SQL> create or replace procedure pining is begin null; end; / Procedure created SQL> SQL> create or replace procedure calling is begin pining; dbms_lock.sleep(200); end; / SQL> SQL> call calling();
..............................................
SQL> SQL> oradebug setmypid Statement processed. SQL> oradebug hanganalyze 3; Hang Analysis in /u01/app/oracle/diag/rdbms/dbdb/DBdb/trace/DBdb_ora_27483.trc SQL> oradebug close_trace; Statement processed.
--查看trace文件: [oracle@wang ~]$ more /u01/app/oracle/diag/rdbms/dbdb/DBdb/trace/DBdb_ora_27483.trc Trace file /u01/app/oracle/diag/rdbms/dbdb/DBdb/trace/DBdb_ora_27483.trc Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production With the Partitioning, OLAP, Data Mining and Real Application Testing options ORACLE_HOME = /u01/app/oracle/product/11.2.0/db_1 System name: Linux Node name: wang Release: 3.10.0-327.el7.x86_64 Version: #1 SMP Thu Oct 29 17:29:29 EDT 2015 Machine: x86_64 Instance name: DBdb Redo thread mounted by this instance: 1 Oracle process number: 32 Unix process pid: 27483, image: oracle@wang (TNS V1-V3)
*** 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.771 Oradebug 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.097 Processing 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()+16 3<-ksfwaitctx()+14<-kglLockWait()+870<-kgllkal()+1166<-kglLock()+1308<-kglget()+343<-kkdllk0()+423<-kkdlGetCodeObject()+307<-kkpdrp()+246<-opiexe()+18161<-opiosq0()+39 32<-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()+16 3<-ksfwaitctx()+14<-kglpnal()+1991<-kglpin()+1373<-kkdllk0()+927<-kkdlGetCodeObject()+307<-kkpalt()+353<-opiexe()+18119<-opiosq0()+3932<-kpooprx()+274<-kpoal8()+842<-o piodr()+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()+16 3<-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<-k kxmpexe()+241<-kgmexwi()+605<-kgmexec()+2193<-evapls()+813<-evaopn2()+808<-kkxmexcs()+133<-opiexe()+20880<-kpoal8()+2118<-opiodr()+917<-ttcpip()+2183<-opitsk()+1710<-o piino()+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/
