session 1:SQL> select sid from v$mystat where rownum=1; SID---------- 41SQL> create or replace procedure pining is begin null; end; /Procedure createdSQL>SQL> create or replace procedure calling is begin pining; dbms_lock.sleep(200); end; /SQL>SQL> call calling();..............................................
session 2:SQL> select sid from v$mystat where rownum=1; SID---------- 37SQL> alter procedure pining compile; hang........... session 3:SQL> select sid from v$mystat where rownum=1; SID---------- 38SQL> drop procedure pining; HANG...........................................
session 4:SQL> select sid, event,wait_class, seconds_in_wait from v$session_wait w where w.WAIT_CLASS <> 'Idle'; SID EVENT WAIT_CLASS SECONDS_IN_WAIT---------- ---------------------------------------------------------------- ---------------------------------------------------------------- --------------- 1 SQL*Net message to client Network 0 37 library cache pin Concurrency 44 38 library cache lock Concurrency 33SQL> SQL> oradebug setmypidStatement processed.SQL> oradebug hanganalyze 3;Hang Analysis in /u01/app/oracle/diag/rdbms/dbdb/DBdb/trace/DBdb_ora_27483.trcSQL> oradebug close_trace;Statement processed.--查看trace文件:[oracle@wang ~]$ more /u01/app/oracle/diag/rdbms/dbdb/DBdb/trace/DBdb_ora_27483.trcTrace file /u01/app/oracle/diag/rdbms/dbdb/DBdb/trace/DBdb_ora_27483.trcOracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit ProductionWith the Partitioning, OLAP, Data Mining and Real Application Testing optionsORACLE_HOME = /u01/app/oracle/product/11.2.0/db_1System name: LinuxNode name: wangRelease: 3.10.0-327.el7.x86_64Version: #1 SMP Thu Oct 29 17:29:29 EDT 2015Machine: x86_64Instance name: DBdbRedo thread mounted by this instance: 1Oracle process number: 32Unix process pid: 27483, image: oracle@wang (TNS V1-V3)*** 2017-12-11 11:02:22.201*** SESSION ID:(1.201) 2017-12-11 11:02:22.201*** CLIENT ID:() 2017-12-11 11:02:22.201*** SERVICE NAME:(SYS$USERS) 2017-12-11 11:02:22.201*** MODULE NAME:(sqlplus@wang (TNS V1-V3)) 2017-12-11 11:02:22.201*** ACTION NAME:() 2017-12-11 11:02:22.201 Processing Oradebug command 'setmypid'*** 2017-12-11 11:02:22.201Oradebug command 'setmypid' console output:*** 2017-12-11 11:02:30.699Processing Oradebug command 'hanganalyze 3'*** 2017-12-11 11:02:30.701===============================================================================HANG ANALYSIS: instances (db_name.oracle_sid): dbdb.dbdb oradebug_node_dump_level: 3 analysis initiated by oradebug os thread scheduling delay history: (sampling every 1.000000 secs) 0.000000 secs at [ 11:02:29 ] NOTE: scheduling delay has not been sampled for 0.879666 secs 0.000000 secs from [ 11:02:25 - 11:02:30 ], 5 sec avg 0.000000 secs from [ 11:01:31 - 11:02:30 ], 1 min avg 0.000000 secs from [ 10:57:31 - 11:02:30 ], 5 min avg vktm time drift history=============================================================================== Chains most likely to have caused the hang: ===============================================================================No chains found.===============================================================================Extra information that will be dumped at higher levels: State of ALL nodes([nodenum]/cnode/sid/sess_srno/session/ospid/state/[adjlist]):*** 2017-12-11 11:02:30.770===============================================================================END OF HANG ANALYSIS===============================================================================*** 2017-12-11 11:02:30.770===============================================================================HANG ANALYSIS DUMPS: oradebug_node_dump_level: 3=============================================================================== State of LOCAL nodes([nodenum]/cnode/sid/sess_srno/session/ospid/state/[adjlist]): No processes qualify for dumping. ===============================================================================HANG ANALYSIS DUMPS: END===============================================================================*** 2017-12-11 11:02:30.771Oradebug command 'hanganalyze 3' console output:Hang Analysis in /u01/app/oracle/diag/rdbms/dbdb/DBdb/trace/DBdb_ora_27483.trc*** 2017-12-11 11:03:41.097Processing Oradebug command 'close_trace'Oradebug command 'close_trace' console output:Processing Oradebug command 'setmypid'Oradebug command 'setmypid' console output:Processing Oradebug command 'hanganalyze 3'===============================================================================HANG ANALYSIS: instances (db_name.oracle_sid): dbdb.dbdb oradebug_node_dump_level: 3 analysis initiated by oradebug os thread scheduling delay history: (sampling every 1.000000 secs) 0.000000 secs at [ 11:05:35 ] NOTE: scheduling delay has not been sampled for 0.908940 secs 0.000000 secs from [ 11:05:31 - 11:05:36 ], 5 sec avg 0.000000 secs from [ 11:04:37 - 11:05:36 ], 1 min avg 0.000001 secs from [ 11:00:37 - 11:05:36 ], 5 min avg vktm time drift history=============================================================================== Chains most likely to have caused the hang: [a] Chain 1 Signature: 'PL/SQL lock timer'<='library cache pin'<='library cache lock' Chain 1 Signature Hash: 0x38f0a7dd ===============================================================================Non-intersecting chains: -------------------------------------------------------------------------------Chain 1:------------------------------------------------------------------------------- Oracle session identified by: { instance: 1 (dbdb.dbdb) os id: 27238 process id: 31, oracle@wang (TNS V1-V3) session id: 38 session serial #: 75 } is waiting for 'library cache lock' with wait info: { p1: 'handle address'=0x72046288 p2: 'lock address'=0x721d7690 p3: '100*mode+namespace'=0x1618500010003 time in wait: 9.863328 sec timeout after: 14 min 50 sec wait id: 26 blocking: 0 sessions current sql: short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+160<-ksliwat()+2022<-kslwaitctx()+163<-ksfwaitctx()+14<-kglLockWait()+870<-kgllkal()+1166<-kglLock()+1308<-kglget()+343<-kkdllk0()+423<-kkdlGetCodeObject()+307<-kkpdrp()+246<-opiexe()+18161<-opiosq0()+3932<-kpooprx()+274<-kpoal8()+842<-opiodr()+917<-ttcpip()+2183<-opitsk()+1710<-opiino()+969<-opiodr()+917<-opidrv()+570<-sou2o()+103<-opimai_real()+133<-ssthrdmain()+265<-main()+201<-__libc_start_main()+245 wait history: * time between current wait and wait #1: 0.001590 sec 1. event: 'SQL*Net message from client' time waited: 3 min 25 sec wait id: 25 p1: 'driver id'=0x62657100 p2: '#bytes'=0x1 * time between wait #1 and #2: 0.000005 sec 2. event: 'SQL*Net message to client' time waited: 0.000002 sec wait id: 24 p1: 'driver id'=0x62657100 p2: '#bytes'=0x1 * time between wait #2 and #3: 0.000085 sec 3. event: 'log file sync' time waited: 0.011217 sec wait id: 23 p1: 'buffer#'=0x4e2 p2: 'sync scn'=0x53ae65 } and is blocked by => Oracle session identified by: { instance: 1 (dbdb.dbdb) os id: 26883 process id: 34, oracle@wang (TNS V1-V3) session id: 37 session serial #: 121 } which is waiting for 'library cache pin' with wait info: { p1: 'handle address'=0x72046288 p2: 'pin address'=0x720c2960 p3: '100*mode+namespace'=0x1618500010003 time in wait: 10.974797 sec timeout after: 14 min 49 sec wait id: 11802 blocking: 1 session current sql: alter procedure pining compile short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+160<-ksliwat()+2022<-kslwaitctx()+163<-ksfwaitctx()+14<-kglpnal()+1991<-kglpin()+1373<-kkdllk0()+927<-kkdlGetCodeObject()+307<-kkpalt()+353<-opiexe()+18119<-opiosq0()+3932<-kpooprx()+274<-kpoal8()+842<-opiodr()+917<-ttcpip()+2183<-opitsk()+1710<-opiino()+969<-opiodr()+917<-opidrv()+570<-sou2o()+103<-opimai_real()+133<-ssthrdmain()+265<-main()+201<-__libc_start_main()+245 wait history: * time between current wait and wait #1: 0.001621 sec 1. event: 'SQL*Net message from client' time waited: 3 min 24 sec wait id: 11801 p1: 'driver id'=0x62657100 p2: '#bytes'=0x1 * time between wait #1 and #2: 0.000006 sec 2. event: 'SQL*Net message to client' time waited: 0.000002 sec wait id: 11800 p1: 'driver id'=0x62657100 p2: '#bytes'=0x1 * time between wait #2 and #3: 0.000396 sec 3. event: 'log file sync' time waited: 0.084778 sec wait id: 11799 p1: 'buffer#'=0x4bf p2: 'sync scn'=0x53ae54 } and is blocked by => Oracle session identified by: { instance: 1 (dbdb.dbdb) os id: 27149 process id: 19, oracle@wang (TNS V1-V3) session id: 41 session serial #: 59 } which is waiting for 'PL/SQL lock timer' with wait info: { p1: 'duration'=0x0 time in wait: 11.653800 sec timeout after: 3 min 8 sec wait id: 11681 blocking: 2 sessions current sql: call calling() short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+160<-ksliwat()+2022<-kslwaitctx()+163<-psdwat()+169<-pevm_icd_call_common()+897<-pfrinstr_ICAL()+169<-pfrrun_no_tool()+63<-pfrrun()+627<-plsql_run()+649<-peidxr_run()+263<-peidxexe()+79<-kkxdexe()+340<-kkxmpexe()+241<-kgmexwi()+605<-kgmexec()+2193<-evapls()+813<-evaopn2()+808<-kkxmexcs()+133<-opiexe()+20880<-kpoal8()+2118<-opiodr()+917<-ttcpip()+2183<-opitsk()+1710<-opiino()+969<-opiodr()+917<-opidrv()+570<-sou wait history: * time between current wait and wait #1: 0.002402 sec 1. event: 'SQL*Net message from client' time waited: 48.869463 sec wait id: 11680 p1: 'driver id'=0x62657100 p2: '#bytes'=0x1 * time between wait #1 and #2: 0.000008 sec 2. event: 'SQL*Net message to client' time waited: 0.000001 sec wait id: 11679 p1: 'driver id'=0x62657100 p2: '#bytes'=0x1 * time between wait #2 and #3: 0.000079 sec 3. event: 'log file sync' time waited: 0.001921 sec wait id: 11678 p1: 'buffer#'=0x83a p2: 'sync scn'=0x53b046 } Chain 1 Signature: 'PL/SQL lock timer'<='library cache pin'<='library cache lock'Chain 1 Signature Hash: 0x38f0a7dd------------------------------------------------------------------------------- ===============================================================================Extra information that will be dumped at higher levels:[level 4] : 1 node dumps -- [LEAF] [LEAF_NW] [level 5] : 2 node dumps -- [NO_WAIT] [INVOL_WT] [SINGLE_NODE] [NLEAF] [SINGLE_NODE_NW] State of ALL nodes([nodenum]/cnode/sid/sess_srno/session/ospid/state/[adjlist]):[36]/1/37/121/0x90e7b740/26883/NLEAF/[40][37]/1/38/75/0x90e78660/27238/NLEAF/[36][40]/1/41/59/0x90e6f3c0/27149/LEAF/
NLEAF –》该状态的session通常被认为 “stuck” session。即其他session所需要的资源正被其holding。
[36]对应的sid:37,被[40]对应的sid:41所阻塞。
[37]对应的sid:38,被[36]对应的sid:37所阻塞。
===============================================================================END OF HANG ANALYSIS===============================================================================Oradebug command 'hanganalyze 3' console output:Hang Analysis in /u01/app/oracle/diag/rdbms/dbdb/DBdb/trace/DBdb_ora_27483.trcProcessing Oradebug command 'close_trace'Oradebug command 'close_trace' console output:[oracle@wang ~]$
新闻名称：11G数据库之librarycachelock及librarycachepin模拟结合hanganalyze定位
分享地址：
http://cdxtjz.cn/article/johsps.html
