Oracle诊断案例-Job任务停止执行[最终版]

Oracle诊断案例-Job任务停止执行

Last Updated: Friday, 2004-11-26 9:48 Eygle

昨天接到研发人员报告,数据库定时任务未正常执行,导致某些操作失败。

开始介入处理该事故.

系统环境:

SunOS DB 5.8 Generic_108528-21 sun4u sparc SUNW,Ultra-4

Oracle9i Enterprise Edition Release 9.2.0.3.0 - Production

1.首先介入检查数据库任务

$ sqlplus "/ as sysdba"

SQL*Plus: Release 9.2.0.3.0 - Production on Wed Nov 17 20:23:53 2004

Copyright (c) 1982, 2002, Oracle Corporation. All rights reserved.

Connected to:

Oracle9i Enterprise Edition Release 9.2.0.3.0 - Production

With the Partitioning, OLAP and Oracle Data Mining options

JServer Release 9.2.0.3.0 - Production

SQL> select job,last_date,last_sec,next_date,next_sec,broken,failures from dba_jobs;

JOB LAST_DATE LAST_SEC NEXT_DATE NEXT_SEC B FAILURES INTERVAL

---------- --------- ---------------- --------- ---------------- - ---------- ----------------------------

31 16-NOV-04 01:00:02 17-NOV-04 01:00:00 N 0 trunc(sysdate+1)+1/24

27 16-NOV-04 00:00:04 17-NOV-04 00:00:00 N 0 TRUNC(SYSDATE) + 1

35 16-NOV-04 01:00:02 17-NOV-04 01:00:00 N 0 trunc(sysdate+1)+1/24

29 16-NOV-04 00:00:04 17-NOV-04 00:00:00 N 0 TRUNC(SYSDATE) + 1

30 01-NOV-04 06:00:01 01-DEC-04 06:00:00 N 0 trunc(add_months(sysdate,1),'MM')+6/24

65 16-NOV-04 04:00:03 17-NOV-04 04:00:00 N 0 trunc(sysdate+1)+4/24

46 16-NOV-04 02:14:27 17-NOV-04 02:14:27 N 0 sysdate+1

66 16-NOV-04 03:00:02 17-NOV-04 18:14:49 N 0 trunc(sysdate+1)+3/24

8 rows selected.

发现JOB任务是都没有正常执行,最早一个应该在17-NOV-04 01:00:00执行。但是没有执行。

2.建立测试JOB

create or replace PROCEDURE pining

IS

BEGIN

NULL;

END;

/

variable jobno number;

variable instno number;

begin

select instance_number into :instno from v$instance;

dbms_job.submit(:jobno, 'pining;', trunc(sysdate+1/288,'MI'), 'trunc(SYSDATE+1/288,''MI'')', TRUE, :instno);

end;

/

发现同样的,不执行。

但是通过dbms_job.run(<job>)执行没有任何问题。

3.进行恢复尝试

怀疑是CJQ0进程失效,首先设置JOB_QUEUE_PROCESSES为0,Oracle会杀掉CJQ0及相应job进程

SQL> ALTER SYSTEM SET JOB_QUEUE_PROCESSES = 0;

等2~3分钟,重新设置

SQL> ALTER SYSTEM SET JOB_QUEUE_PROCESSES = 5;

此时PMON会重起CJQ0进程

在警报日志中可以看到以下信息:

Thu Nov 18 11:59:50 2004

ALTER SYSTEM SET job_queue_processes=0 SCOPE=MEMORY;

Thu Nov 18 12:01:30 2004

ALTER SYSTEM SET job_queue_processes=10 SCOPE=MEMORY;

Thu Nov 18 12:01:30 2004

Restarting dead background process CJQ0

CJQ0 started with pid=8

但是Job仍然不执行,而且在再次修改的时候,CJQ0直接死掉了。

Thu Nov 18 13:52:05 2004

ALTER SYSTEM SET job_queue_processes=0 SCOPE=MEMORY;

Thu Nov 18 14:09:30 2004

ALTER SYSTEM SET job_queue_processes=10 SCOPE=MEMORY;

Thu Nov 18 14:10:27 2004

ALTER SYSTEM SET job_queue_processes=0 SCOPE=MEMORY;

Thu Nov 18 14:10:42 2004

ALTER SYSTEM SET job_queue_processes=10 SCOPE=MEMORY;

Thu Nov 18 14:31:07 2004

ALTER SYSTEM SET job_queue_processes=0 SCOPE=MEMORY;

Thu Nov 18 14:40:14 2004

ALTER SYSTEM SET job_queue_processes=10 SCOPE=MEMORY;

Thu Nov 18 14:40:28 2004

ALTER SYSTEM SET job_queue_processes=0 SCOPE=MEMORY;

Thu Nov 18 14:40:33 2004

ALTER SYSTEM SET job_queue_processes=1 SCOPE=MEMORY;

Thu Nov 18 14:40:40 2004

ALTER SYSTEM SET job_queue_processes=10 SCOPE=MEMORY;

Thu Nov 18 15:00:42 2004

ALTER SYSTEM SET job_queue_processes=0 SCOPE=MEMORY;

Thu Nov 18 15:01:36 2004

ALTER SYSTEM SET job_queue_processes=15 SCOPE=MEMORY;

4.尝试重起数据库

这个必须在晚上进行

PMON started with pid=2

DBW0 started with pid=3

LGWR started with pid=4

CKPT started with pid=5

SMON started with pid=6

RECO started with pid=7

CJQ0 started with pid=8

QMN0 started with pid=9

....

CJQ0正常启动,但是Job仍然不执行。

5.没办法了...

继续研究...居然发现Oralce有这样一个bug

1. Clear description of the problem encountered:

slgcsf() / slgcs() on Solaris will stop incrementing after

497 days 2 hrs 28 mins (approx) machine uptime.

2. Pertinent configuration information

No special configuration other than long machine uptime. .

3. Indication of the frequency and predictability of the problem

100% but only after 497 days.

4. Sequence of events leading to the problem

If the gethrtime() OS call returns a value > 42949672950000000

nanoseconds then slgcs() stays at 0xffffffff. This can

cause some problems in parts of the code which rely on

slgcs() to keep moving.

eg: In kkjssrh() does "now = slgcs(&se)" and compares that

to a previous timestamp. After 497 days uptime slgcs()

keeps returning 0xffffffff so "now - kkjlsrt" will

always return 0. .

5. Technical impact on the customer. Include persistent after effects.

In this case DBMS JOBS stopped running after 497 days uptime.

Other symptoms could occur in various places in the code.

好么,原来是计时器溢出了,一检查我的主机:

bash-2.03$ uptime

10:00pm up 500 day(s), 14:57, 1 user, load average: 1.31, 1.09, 1.08

bash-2.03$ date

Fri Nov 19 22:00:14 CST 2004

刚好到事发时是497天多一点.ft.

6.安排重起主机系统..

这个问题够郁闷的,NND,谁曾想Oracle这都成...

Oracle最后声称:

fix made it into 9.2.0.6 patchset

在Solaris上的9206尚未发布...晕.

好了,就当是个经历吧,如果有问题非常不可思议的话,那么大胆怀疑Oracle吧,是Bug,可能就是Bug。

重起以后问题解决,状态如下:

$ sqlplus "/ as sysdba"

SQL*Plus: Release 9.2.0.3.0 - Production on Fri Nov 26 09:21:21 2004

Copyright (c) 1982, 2002, Oracle Corporation. All rights reserved.

Connected to:

Oracle9i Enterprise Edition Release 9.2.0.3.0 - Production

With the Partitioning, OLAP and Oracle Data Mining options

JServer Release 9.2.0.3.0 - Production

SQL> select job,last_date,last_sec,next_date,next_sec from user_jobs;

       JOB LAST_DATE LAST_SEC         NEXT_DATE NEXT_SEC
---------- --------- ---------------- --------- ----------------
        70 26-NOV-04 09:21:04         26-NOV-04 09:26:00


SQL> /

       JOB LAST_DATE LAST_SEC         NEXT_DATE NEXT_SEC
---------- --------- ---------------- --------- ----------------
        70 26-NOV-04 09:26:01         26-NOV-04 09:31:00

SQL> 
SQL> select * from v$timer;

     HSECS
----------
   3388153

SQL> select * from v$timer;

     HSECS
----------
   3388319

SQL>                         

7.FAQ

一些朋友在Pub上问的问题

Q:对于不同平台,是否存在同样的问题?

A:对于不同平台,存在同样的问题

因为Oracle使用了标准C函数gethrtime

参考:

http://www.eygle.com/unix/Man.Page.Of.gethrtime.htm

使用了该函数的代码都会存在问题.

在Metalink Note:3427424.8 文档中,Oracle定义的平台影响为:Generic (all / most platforms affected)

Q.计数器溢出,看了看job 中基本都是1天左右执行一次,如果设置 3 天执行一次的 job , 是否出问题的uptime 应该是 497*3 之后呢 ?

A:不会

Oracle内部通过计时器来增进相对时间.

由于Oracle内部hrtime_t使用了32位计数

那么最大值也就是0xffffffff

0xffffffff = 4294967295

slgcs()是10亿分之一秒,溢出在42949672950000000这个点上.

注意,这里0xffffffff,达到这个值时,本来是无符号整型,现在变成了-1,那么这个值递增时,+1 = 0了。

时间就此停住了。

我写了一小段代码来验证这个内容,参考:

[oracle@jumper oracle]$ cat unsign.c
#include 
int main(void){
unsigned int num = 0xffffffff;

printf("num is %d bits long/n", sizeof(num) * 8);
printf("num = 0x%x/n", num);
printf("num + 1 = 0x%x/n", num + 1);

return 0;
}

[oracle@jumper oracle]$ gcc -o unsign.sh unsign.c
[oracle@jumper oracle]$ ./unsign.sh
num is 32 bits long
num = 0xffffffff
num + 1 = 0x0
[oracle@jumper oracle]$
 

Q:内部时钟之一应该就是这个吧: v$timer 精确到1/100 秒的数据

没错!

注意前面说的:

4. Sequence of events leading to the problem

If the gethrtime() OS call returns a value > 42949672950000000

nanoseconds then slgcs() stays at 0xffffffff. This can

cause some problems in parts of the code which rely on

slgcs() to keep moving.

也就是说如果gethrtime() 操作系统调用返回值大于42949672950000000(单位10亿分之一秒)

也就是说Oracle将得到一个cs值为4294967295的时间值

而4294967295值就是0xffffffff

所以当时v$timer的计时也就是:

 SQL> select * from v$timer;

     HSECS
----------
4294967295

SQL> /                   

     HSECS
----------
4294967295

SQL> /

     HSECS
----------
4294967295

SQL>                        
                      
 

本文作者:

eygle,Oracle技术关注者,来自中国最大的Oracle技术论坛itpub.

www.eygle.com是作者的个人站点.你可通过Guoqiang.Gai@gmail.com来联系作者.欢迎技术探讨交流以及链接交换.

原文出处:

http://www.eygle.com/case/Job.Can.Not.Execute.Auto.htm

本文参与腾讯云自媒体分享计划,欢迎正在阅读的你也加入,一起分享。

发表于

我来说两句

0 条评论
登录 后参与评论

相关文章

来自专栏龙首琴剑庐

mybaits3整合spring总结

1、maven定义properties: <org.springframework.version>4.3.1.RELEASE</org.springframe...

37870
来自专栏杨建荣的学习笔记

awr性能问题排查第一篇(r3笔记第42天)

对于awr,里面涵盖的内容比较杂,有时候看报告的时候总是不知道该怎么下手。时间长了,可能会有一些阅读习惯或者心得。今天在看大师chris lawson的一篇博文...

30140
来自专栏杨建荣的学习笔记

一个MySQL死锁问题的复现

很久之前有一个同事问我一个关于死锁的问题,一直在拖这个事情,总算找了空来看看。 这个环境的事务隔离级别是RR,仔细看了下问题描述和背景,发现还真不是一...

45890
来自专栏杨建荣的学习笔记

ORA-00439的解决(笔记93天)

今天用gc配置了stream后,重启数据库后发现有以下的问题 SQL> startup ORA-00439: feature not enabled: Real...

376100
来自专栏杨建荣的学习笔记

探究AWR 第一篇

statspack相比awr算是比较通用,而且免费,可以在标准版,企业版中使用,awr是新企业版本中才有的,算是statspack的一个升级版,而且代码不公开。...

36570
来自专栏杨建荣的学习笔记

关于db link权限分配的苦旅(一) (r7笔记第42天)

昨天接到一个开发的需求,内容看起来非常简单。 申请数据库192.168.1.118:1522:TEST下用户APP_TE_FLOW_128赋予对表testore...

34760
来自专栏Jerry的SAP技术分享

ABAP OPEN SQL里OPEN CURSOR和SELECT的比较

After the OPEN CURSOR statement, the database cursor is positioned in front of t...

39290
来自专栏杨建荣的学习笔记

只言片语分析datapump的工作原理(r2第18天)

datapump是从oracle 10g推出的新的数据导入导出工具,可以说是exp/imp的加强版,主要的亮点在于服务端,结合了direct+parallel,...

25130
来自专栏杨建荣的学习笔记

一条sql语句“导致”的数据库宕机问题及分析 (38天)

最近测试环境需要做一些变更,把测试环境切分成两套环境,存储空间也需要压缩压缩和整理。 unix组的人已经开始做空间划分了,然后我们需要在此基础上重建一套环境。 ...

36540
来自专栏乐沙弥的世界

Linux 5 下安装MySQL 5.6(RPM方式)

    MySQL在很多领域被广泛使用,尤其是很多互联网企业,诸如腾讯,阿里等等。本文主要介绍在Linux 5下通过rpm方式来安装Mysql,这是比较简单的一...

15110

扫码关注云+社区

领取腾讯云代金券