某生产系统应用人员反映自己发起的job异常,没有正常运行,导致相关表无数据,自己尝试停止job但未成功,也无法重新发起job。
二, 问题分析
job的登录模式一般为’DBMS_SCHEDULER’,通过PL/SQL工具登录运行如下语句进行查看
select S.STATUS,
S.INST_ID,
S.SID,
S.PADDR,
S.SQL_ID,
S.SQL_EXEC_START,
S.ACTION,
S.LAST_CALL_ET,
S.BLOCKING_INSTANCE,
S.BLOCKING_SESSION,
S.EVENT,
S.WAIT_CLASS
from v$session S
where module = 'DBMS_SCHEDULER';
查询到一个被kill的job,状态为killed,并未释放,通过下面的语句查询到spid后,通过登录后台kill -9 的方式杀掉了系统进程。
Select p.spid from v$session s,v$processes p where p.addr=s.paddr and s.sid=508
之后让应用再次发起job,但job依然无法执行,通过后台发现该job发生了等待事件row cache lock,等待会话为1209,P1值为11,通过下面的语句查看无返回结果,不能定位row cache lock发生在哪里
Select * from v$rowcache where cache#=11;
查询1209会话发现为系统后台进程CJQ0, CJQn和Jnnn均为为oracle作业队列进程,后台进程为什么会锁正常的job呢?
Select * from v$session where sid=1209;
应用人员通过PL/SQL提供的JOB任务发现存在如下异常现象,
(上面的截图缺少了任务CSH_BRANCH_D_1DAY,因为截取的是已经处理后的图像,其实在出现问的时候是有的,只不过忘了截取了)
当前运行很多job,但没有都没有session_id,感觉像是僵尸job,既然无法通过会话杀掉job,
我们尝试通过dbms_scheduler包进行停止,但无法停止,而且依然出现了row cache lock事件,依然被1209后台进程锁住。
Row cache lock无法通过P1定位到具体的锁对象,后台进程为什么会锁住job呢,通过上面的结果初步分析是因为之前有很多僵死的job没有被正常停止,导致再次发起同样的job任务或对该job进行处理就会出现锁的情况,而且是被后台进程CJQn锁住。
SQL>Show parameter processes
通过查看参数job_queue_processes值为1000,aq_tm_processes为10000,并未达到峰值
进一步分析
登录后台通过DEBUG命令收集相关信息分析
用sysdba登录到数据库上:
$sqlplus / as sysdba
或者
$sqlplus -prelim / as sysdba <==当数据库已经很慢或者hang到无法连接
以下为操作截屏,采用的hanganalyze 3,systemstate dump 258级别。
相关说明:
Level 的含义:
1-2:只有hanganalyze输出,不dump任何进程
3:Level2+Dump出在IN_HANG状态的进程
4:Level3+Dump出在等待链里面的blockers(状态为LEAF/LEAF_NW/IGN_DMP)
5:Level4+Dump出所有在等待链中的进程(状态为NLEAF)
Oracle官方建议不要超过level 3,一般level 3也能够解决问题,超过level 3会给系统带来额外负担。
systemstate dump有多个级别:
2: dump (不包括lock element)
10: dump
11: dump + global cache of RAC
256: short stack (函数堆栈)
258: 256+2 -->short stack +dump(不包括lock element)
266: 256+10 -->short stack+ dump
267: 256+11 -->short stack+ dump + global cache of RAC
level 11和 267会 dump global cache, 会生成较大的trace 文件,一般情况下不推荐。
一般情况下,如果进程不是太多,推荐用266,因为这样可以dump出来进程的函数堆栈,可以用来分析进程在执行什么操作。
但是生成short stack比较耗时,如果进程非常多,比如2000个进程,那么可能耗时30分钟以上。这种情况下,可以生成level 10 或者 level 258, level 258 比 level 10会多收集short short stack, 但比level 10少收集一些lock element data.
以下为hanganalyze的截取输出,可以看到主要等待为row cache lock,session id:7/porcess id:128被session id:1209/process id: 49锁住,和上面的分析一致。
Chains most likely to have caused the hang:
[a] Chain 1 Signature: 'rdbms ipc message'<='row cache lock'
Chain 1 Sign