客户反馈执行select job,what from dba_jobs时session Hang住,等待事件为enq: TX contention。
现象:
因为没在现场,所以我要求客户执行如下SQL:
a).生成10046trace:
SQL> connect username/password
SQL> alter session set tracefile_identifier='10046trace';
SQL> alter session set timed_statistics = true;
SQL> alter session set statistics_level=all;
SQL> alter session set max_dump_file_size = unlimited;
SQL> alter session set events '10046 trace name context forever, level 12';
SQL> select job,what from dba_jobs;
b). 另开一个session,生成hanganalyze trace:
SQL>oradebug setmypid
SQL>oradebug unlimit;
SQL>oradebug dump hanganalyze 3
Wait for 30 seconds
SQL>oradebug dump hanganalyze 3
Wait for 30 seconds
SQL>oradebug dump hanganalyze 3
SQL> oradebug tracefile_name
c). 开一个新的会话,生成systemstate
SQL>oradebug setmypid
SQL>oradebug unlimit
SQL>oradebug dump systemstate 10
Wait for 30 seconds
SQL>oradebug dump systemstate 10
SQL>oradebug tracefile_name
10046:
PARSING IN CURSOR #1 len=29 dep=0 uid=0 oct=3 lid=0 tim=137502489 hv=2963431435 ad='3816f698'
select job,what from dba_jobs
END OF STMT
PARSE #1:c=93750,e=144411,p=17,cr=321,cu=0,mis=1,r=0,dep=0,og=1,tim=137502487
BINDS #1:
EXEC #1:c=0,e=29,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=137502778
WAIT #1: nam='SQL*Net message to client' ela= 2 driver id=1111838976 #bytes=1 p3=0 obj#=-1 tim=137502803
WAIT #1: nam='db file sequential read' ela= 1630 file#=1 block#=1657 blocks=1 obj#=237 tim=137504471
WAIT #1: nam='enq: TX - contention' ela= 995528 name|mode=1415053316 usn<<16 | slot=1179661 sequence=7710334 obj#=237 tim=138500082
WAIT #1: nam='enq: TX - contention' ela= 1999676 name|mode=1415053316 usn<<16 | slot=1179661 sequence=7710334 obj#=237 tim=140499853
WAIT #1: nam='enq: TX - contention' ela= 2999565 name|mode=1415053316 usn<<16 | slot=1179661 sequence=7710334 obj#=237 tim=143499520
WAIT #1: nam='enq: TX - contention' ela= 999803 name|mode=1415053316 usn<<16 | slot=1179661 sequence=7710334 obj#=237 tim=144499411
*** 2013-06-18 10:30:13.329
<...snipped...>
*** 2013-06-18 10:37:06.329
WAIT #1: nam='enq: TX - contention' ela= 2999585 name|mode=1415053316 usn<<16 | slot=1179661 sequence=7710334 obj#=237 tim=560453211
WAIT #1: nam='enq: TX - contention' ela= 2999571 name|mode=1415053316 usn<<16 | slot=1179661 sequence=7710334 obj#=237 tim=563452876
WAIT #1: nam='enq: TX - contention' ela= 2999586 name|mode=1415053316 usn<<16 | slot=1179661 sequence=7710334 obj#=237 tim=566452539
hanganalyze trace:
*** 2013-06-18 10:30:43.407
HANG ANALYSIS:
==============
Open chains found:
Chain 1 :
<0/78/65191/0x5c041478/4368/SQL*Net message from dblink>
-- <0/139/51158/0x5c06a920/12992/enq: TX - contention>
Other chains found:
<...snipped...>
Chain 7 :
<0/172/23264/0x5c034068/15528/enq: TX - contention> <-- 发现DB中还存在其他的chain
systemstate(ass09.awk解释后的):
System State 1 (2013-06-18 10:32:11.485)
~~~~~~~~~~~~~~ ~~~~~~~~~~~~~~~~~~~~~~~
<...snipped...>
18: waiting for 'rdbms ipc message' seq=7781
20: waiting for 'enq: TX - contention' [Enq TX-0012000D-0075A67E] seq=41370 <--1.大量session在等待'enq: TX - contention([Enq TX-0012000D-0075A67E])'
<...snipped...>
136:waiting for 'enq: TX - contention' [Enq TX-0012000D-0075A67E] seq=19
Cmd: Select
<...snipped...>
180:waiting for 'enq: TX - contention' [Enq TX-0012000D-0075A67E] seq=17
Cmd: Select
<...snipped...>
206:waiting for 'enq: TX - contention' [Enq TX-0012000D-0075A67E] seq=38
Cmd: Select
<...snipped...>
232:waiting for 'db file sequential read' (e,1863d4,1) seq=17277
Cmd: Select
<...snipped...>
246:waiting for 'enq: TX - contention' [Enq TX-0012000D-0075A67E] seq=28
Cmd: Select
<...snipped...>
258:waiting for 'SQL*Net message from dblink' seq=1947 <--3.session258在等待SQL*Net message from dblink
<...snipped...>
362:waiting for 'enq: TX - contention' [Enq TX-0012000D-0075A67E] seq=48
Cmd: Select
Resource Holder State
Enq TX-0012000D-0075A67E 258: waiting for 'SQL*Net message from dblink' <--2.[Enq TX-0012000D-0075A67E]的Holder为session 258
systemstate(raw):
PROCESS 258:
----------------------------------------
SO: 000000025C041478, type: 2, owner: 0000000000000000, flag: INIT/-/-/0x00
(process) Oracle pid=258, calls cur/top: 000000025F930F60/000000025F97FF88, flag: (0) -
int error: 0, call error: 0, sess error: 0, txn error 0
(po