Frequent generate a lot of cdmp* directories contain *bucket trace in bdump(二 ) root cause
之前记录过Frequent generate a lot of cdmp* directories contain *bucket trace in bdump , 当时根据现象与该bug 很相似,该bug解决的只是不生成cdump还是会生成trace 文件,所以要分析生成trace的根本原因。之前数据库在诊断问题时也启用过相关trace event(见下面) , 但是instance memroy 级别实例重启后不再生效, 在第一篇时我写使用oradebug列出过当时启用的event trace, 这里简单的记录
首先还是看db alert log
Wed Jun 01 22:00:12 2016 Global Enqueue Services Deadlock detected. More info in file /oracle/app/oracle/diag/rdbms/anbob/anbob1/trace/anbob1_ora_11255.trc. Wed Jun 01 22:00:12 2016 Dumping diagnostic data in directory=[cdmp_20160601220012], requested by (instance=1, osid=11255), summary=[abnormal process termination]. Wed Jun 01 22:01:01 2016 Global Enqueue Services Deadlock detected. More info in file /oracle/app/oracle/diag/rdbms/anbob/anbob1/trace/anbob1_ora_25999.trc. Wed Jun 01 22:01:01 2016 Dumping diagnostic data in directory=[cdmp_20160601220101], requested by (instance=1, osid=25999), summary=[abnormal process termination]. Wed Jun 01 22:02:01 2016 Global Enqueue Services Deadlock detected. More info in file /oracle/app/oracle/diag/rdbms/anbob/anbob1/trace/anbob1_ora_29423.trc. Wed Jun 01 22:02:01 2016 Dumping diagnostic data in directory=[cdmp_20160601220201], requested by (instance=1, osid=29423), summary=[abnormal process termination]. Wed Jun 01 22:03:00 2016 Global Enqueue Services Deadlock detected. More info in file /oracle/app/oracle/diag/rdbms/anbob/anbob1/trace/anbob1_ora_3100.trc.
cdmp 是有实例发生了GES deadlock 后请求生成的,看具体的trace
Trace file /oracle/app/oracle/diag/rdbms/anbob/anbob1/trace/anbob1_ora_11255.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
With the Partitioning, Real Application Clusters, OLAP, Data Mining
and Real Application Testing options
ORACLE_HOME = /oracle/app/oracle/product/11.2.0.3/dbhome_1
System name: HP-UX
Node name: qdyyc1
Release: B.11.31
Version: U
Machine: ia64
Instance name: anbob1
Redo thread mounted by this instance: 1
Oracle process number: 3219
Unix process pid: 11255, image: oracle@qdyyc1 (TNS V1-V3)
*** 2016-06-01 22:00:12.225
*** SESSION ID:(1195.8589) 2016-06-01 22:00:12.225
*** CLIENT ID:() 2016-06-01 22:00:12.225
*** SERVICE NAME:(SYS$USERS) 2016-06-01 22:00:12.225
*** MODULE NAME:(replx@qdyyc1 (TNS V1-V3)) 2016-06-01 22:00:12.225
*** ACTION NAME:() 2016-06-01 22:00:12.225
Single resource deadlock: blocked by granted enqueue, f 0 <<<<<<<<<<<<<<< Single resource deadlock.
Granted global enqueue c0000015f9b20778
----------enqueue c0000015f9b20778------------------------
lock version : 1066119
Owner inst : 1
grant_level : KJUSEREX <<<<<<<<<<< already has exclusive lock.
req_level : KJUSEREX <<<<<<<<<<<
bast_level : KJUSERNL
notify_func : 0000000000000000
resp : c000001617da1f08
procp : c000001636096a48
pid : 11255
proc version : 3438
oprocp : 0000000000000000
opid : 11255
group lock owner : c000001603746b60
possible pid : 11255
xid : 10C9-0C93-0021E8C9
dd_time : 0.0 secs
dd_count : 0
timeout : 0.0 secs
On_timer_q? : N
On_dd_q? : N
lock_state : GRANTED
ast_flag : 0x0
Open Options : KJUSERDEADLOCK
Convert options : KJUSERNOQUEUE KJUSERNODEADLOCKWAIT
History : 0x14951495
Msg_Seq : 0x0
res_seq : 80
valblk : 0x00000000000000000000000000000000 .
user session for deadlock lock 0xc0000015f9b20778
sid: 1195 ser: 8589 audsid: 596318785 user: 1149/COMMON <<<<<<<<<<<<<<< session info
flags: (0x41) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
flags2: (0x40009) -/-/INC
pid: 3219 O/S info: user: replx35, term: UNKNOWN, ospid: 11255
image: oracle@qdyyc1 (TNS V1-V3)
client details:
O/S info: user: replx35, term: , ospid: 11226
machine: qdyyc1 program: replx@qdyyc1 (TNS V1-V3)
application name: replx@qdyyc1 (TNS V1-V3), hash value=2173374484
current SQL:
UPDATE COMMON.SA_SHM_REFRESH_INFO SET MODIFYTIME=SYSDATE WHERE TABLE_NAME='PARAMETER_VALUE' <<<<<<<<<<<<<<<<<
Requesting global enqueue c0000015f9b20948
----------enqueue c0000015f9b20948------------------------
lock version : 628411
Owner inst : 1
grant_level : KJUSERNL
req_level : KJUSEREX <<<<<<<<<<<< Also request exclusive mode lock.
bast_level : KJUSERNL
notify_func : 0000000000000000
resp : c000001617da1f08
procp : c000001636096a48
pid : 11255
proc version : 3438
oprocp : 0000000000000000
opid : 11255
group lock owner : c000001603746b60
possible pid : 11255
xid : 10C9-0C93-0021E8C9
dd_time : 0.0 secs
dd_count : 0
timeout : 0.0 secs
On_timer_q? : N
On_dd_q? : N
lock_state : OPENING CONVERTING
ast_flag : 0x0
Open Options : KJUSERDEADLOCK
Convert options : KJUSERGETVALUE
History : 0x51495149
Msg_Seq : 0x0
res_seq : 80
valblk : 0x00000000000000000000000000000000 .
user session for deadlock lock 0xc0000015f9b20948
sid: 1195 ser: 8589 audsid: 596318785 user: 1149/COMMON
flags: (0x41) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
flags2: (0x40009) -/-/INC
pid: 3219 O/S info: user: replx35, term: UNKNOWN, ospid: 11255
image: oracle@qdyyc1 (TNS V1-V3)
client details:
O/S info: user: replx35, term: , ospid: 11226
machine: qdyyc1 program: replx@qdyyc1 (TNS V1-V3)
application name: replx@qdyyc1 (TNS V1-V3), hash value=2173374484
current SQL:
UPDATE COMMON.SA_SHM_REFRESH_INFO SET MODIFYTIME=SYSDATE WHERE TABLE_NAME='PARAMETER_VALUE'
----------resource c000001617da1f08----------------------
resname : [0x2700009][0x125d3],[TX][ext 0x2,0x0] <<<<<<<<<<<<<<<< TX lock
hash mask : x3
Local inst : 1
dir_inst : 1
master_inst : 1
hv idx : 59
hv last r.inc : 0
current inc : 4
hv status : 0
hv master : 0
open options : dd
grant_bits : KJUSERNL KJUSEREX
grant mode : KJUSERNL KJUSERCR KJUSERCW KJUSERPR KJUSERPW KJUSEREX
count : 1 0 0 0 0 1
val_state : KJUSERVS_NOVALUE
valblk : 0x9ffffffffffe84500129000000000000 .P)
access_inst : 1
vbreq_state : 0
state : x0
resp : c000001617da1f08
On Scan_q? : N
Total accesses: 545
Imm. accesses: 452
Granted_locks : 2
Cvting_locks : 0
value_block: 9f ff ff ff ff fe 84 50 01 29 00 00 00 00 00 00
GRANTED_Q :
lp c0000015f9b20778 gl KJUSEREX rp c000001617da1f08 [0x2700009][0x125d3],[TX][ext 0x2,0x0]
master 1 gl owner c000001603746b60 possible pid 11255 xid 10C9-0C93-0021E8C9 bast 0 rseq 80 mseq 0 history 0x14951495
open opt KJUSERDEADLOCK
CONVERT_Q:
-------------------------------------------------------------------------------
Trace Bucket Dump Begin: default bucket for process 3219 (osid: 11255)
TIME(*=approx):SEQ:COMPONENT:FILE@LINE:FUNCTION:SECT/DUMP: [EVENT#:PID:SID] DATA
是一种Single resource deadlock类型的GES lock, 现在从MOS中Troubleshooting “Global Enqueue Services Deadlock detected” (文档 ID 1443482.1)分析,有记录诊断方向
4. Single resource deadlock for TX , TM or IV
trace shows:
Single resource deadlock: blocking enqueue which blocks itself, f 1
Granted global enqueue 0xd078cec0
…
resname :[0x2001f][0x1a96c3],[TX]
or
resname :[0x00001432][0x0],[TM]
or
resname : [0xbb7cc5db][0x82d0d4b5],[IV]a. For single resource deadlock on TX enqueue, often it is caused by using autonomous transaction in stored procedure or PL/SQL. It is a known issue that the use of autonomous transactions is vulnerable to deadlocks. Please check out Oracle® Database Concepts Overview of Autonomous Transactions for detail explanation. Since AUTONOMOUS transaction has been used in the stored procedure, the system would consider any DML statement under this transaction as a separate one (commit/rollback won’t affect the parent), and this would cause conflict if the same row is involved in the parent transaction (INSERT, UPDATE or DELETE), and hence deadlock is reported rightly. Usually the SQL involved in the deadlock is called from a stored procedure or PL/SQL with the following line:
PRAGMA AUTONOMOUS_TRANSACTION;
To avoid such deadlock, please remove the autonomous transaction in the application code.
lock mode: #define KJUSERNL 0 /* no permissions */ (Null) #define KJUSERCR 1 /* concurrent read */ (Row-S (SS)) #define KJUSERCW 2 /* concurrent write */ (Row-X (SX)) #define KJUSERPR 3 /* protected read */ (Share) #define KJUSERPW 4 /* protected write */ (S/Row-X (SSX)) #define KJUSEREX 5 /* exclusive access */ (Exclusive)
解决方法:
从dba_source or dba_triggers 中找出有AUTONOMOUS_TRANSACTION 关键字的对象,确实存在一个自制事务TRIGGER,中包含上面trace文件中的SQL语句,确认没有必要后去掉了自制事务行,问题得以解决,TOM 也提到过自制事务对deadlock的影响,个人觉得目前除了insert 操作日志外没有想到其它合理的应用场景。
对不起,这篇文章暂时关闭评论。