昨天接到研發人員報告，資料庫定時任務未正常執行，導致某些操作失敗。
開始介入處理該事故.
系統環境:
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()執行沒有任何問題。
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。
本文作者:
eygle,Oracle技術關注者,來自中國最大的Oracle技術論壇itpub.
www.eygle.com是作者的個人站點.你可通過Guoqiang.Gai@gmail.com來聯絡作者.歡迎技術探討交流以及連結交換.
原文出處:
http://www.eygle.com/case/Job.Can.Not.Execute.Auto.htm