本文共 20662 字，大约阅读时间需要 68 分钟。
为什么要使用hanganalyze Oracle 数据库“真的”hang住了，可以理解为数据库内部发生死锁。因为普通的DML死锁，oracle服务器会自动监测他们的依赖关系，并回滚其中一个操作，终止这种相互等待的局面。而当这种死锁发生在争夺内核级别的资源（比如说是pins或latches）时，Oracle并不能自动的监测并处理这种死锁。 其实很多时候数据库并没有hang住，而只是由于数据库的性能问题，处理的时间比较长而已。 Hanganalyze工具使用内核调用检测会话在等待什么资源，报告出占有者和等待者的相互关系。另外，它还会将一些比较”interesting”的进程状态dump出来，这个取决于我们使用hanganalyze的分析级别。 hanganalyze工具从oracle8i第二版开始提供，到9i增强了诊断RAC环境下的“集群范围”的信息，这意味着它将会报告出整个集群下的所有会话的信息。 目前有三种使用hanganalyze的方法: 一种是会话级别的：SQL>ALTER SESSION SET EVENTS 'immediate trace name HANGANALYZE level一种是实例级别:';
SQL>ORADEBUG hanganalyze一种是集群范围的：
SQL>ORADEBUG setmypidSQL>ORADEBUG setinst allSQL>ORADEBUG -g def hanganalyze
SQL> conn test/testConnected.SQL> create table tb_hang(id int,name varchar2(20));Table created.SQL> insert into tb_hang values(1,'yu');1 row created.SQL> commit;Commit complete.SQL> select userenv('sid') from dual;USERENV('SID')-------------- 1285SQL> update tb_hang set name='shi' where id=1; 1 row updated.这个时候不要提交 SQL> conn test/testConnected.SQL> select userenv('sid') from dual;USERENV('SID')-------------- 1044SQL> update tb_hang set name='shi' where id=1; orcl:/home/oracle@oracle>sqlplus / as sysdbaSQL*Plus: Release 11.2.0.4.0 Production on Thu Feb 8 09:10:51 2018Copyright (c) 1982, 2013, Oracle. All rights reserved.Connected to:Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit ProductionWith the Partitioning, OLAP, Data Mining and Real Application Testing optionsSQL> oradebug hanganalyze 3;Hang Analysis in /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_162680.trcSQL> exit
orcl:/home/oracle@oracle>vi /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_162680.trcTrace file /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_162680.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: oracleRelease: 2.6.32-431.el6.x86_64Version: #1 SMP Fri Nov 22 03:15:09 UTC 2013Machine: x86_64Instance name: orclRedo thread mounted by this instance: 1Oracle process number: 105Unix process pid: 162680, image: oracle@oracle (TNS V1-V3)*** 2018-02-08 09:11:11.573*** SESSION ID:(1248.12215) 2018-02-08 09:11:11.573*** CLIENT ID:() 2018-02-08 09:11:11.573*** SERVICE NAME:(SYS$USERS) 2018-02-08 09:11:11.573*** MODULE NAME:(sqlplus@oracle (TNS V1-V3)) 2018-02-08 09:11:11.573*** ACTION NAME:() 2018-02-08 09:11:11.573 Processing Oradebug command 'hanganalyze 3'*** 2018-02-08 09:11:12.472===============================================================================HANG ANALYSIS: instances (db_name.oracle_sid): orcl.orcl oradebug_node_dump_level: 3 analysis initiated by oradebug os thread scheduling delay history: (sampling every 1.000000 secs) 0.000000 secs at [ 09:11:11 ] NOTE: scheduling delay has not been sampled for 0.557785 secs 0.000000 secs from [ 09:11:07 - 09:11:12 ], 5 sec avg 0.000000 secs from [ 09:10:12 - 09:11:12 ], 1 min avg 0.000000 secs from [ 09:06:13 - 09:11:12 ], 5 min avg vktm time drift history=============================================================================== Chains most likely to have caused the hang: [a] Chain 1 Signature: 'SQL*Net message from client'<='enq: TX - row lock contention' Chain 1 Signature Hash: 0x38c48850 [b] Chain 2 Signature: 'Streams AQ: deallocate messages from Streams Pool' Chain 2 Signature Hash: 0x22faf522 [c] Chain 3 Signature: 'EMON slave idle wait' Chain 3 Signature Hash: 0x9fbbc886 ===============================================================================Non-intersecting chains: -------------------------------------------------------------------------------Chain 1:------------------------------------------------------------------------------- Oracle session identified by: { instance: 1 (orcl.orcl) os id: 162261 process id: 104, oracle@oracle (TNS V1-V3) session id: 1044 session serial #: 22559 } is waiting for 'enq: TX - row lock contention' with wait info: { p1: 'name|mode'=0x54580006 p2: 'usn<<16 | slot'=0x5001b p3: 'sequence'=0x83ba time in wait: 39.344626 sec timeout after: never wait id: 27 blocking: 0 sessions current sql: update tb_hang set name=:"SYS_B_0" where id=:"SYS_B_1" short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10<-skgpwwait()+160<-ksliwat()+2022<-kslwaitctx()+163<-ksqcmi()+2848<-ksqgtlctx()+3501<-ksqgelctx()+557<-ktuGetTxForXid()+131<-ktcwit1()+336<-kdddgb()+8364<-kdusru()+461<-kauupd()+412<-updrow()+2167<-qerupFetch()+832<-updaul()+1321<-updThreePhaseExe()+318<-updexe()+418<-opiexe()+10378<-kpoal8()+2118<-opiodr()+917<-ttcpip()+2183<-opitsk()+1710<-opiino()+969<-opiodr()+917<-opidrv()+570<-sou2o()+103<-opimai_real()+133<-ssthrdmain wait history: * time between current wait and wait #1: 0.007105 sec 1. event: 'SQL*Net message from client' time waited: 24.601697 sec wait id: 26 p1: 'driver id'=0x62657100 p2: '#bytes'=0x1 * time between wait #1 and #2: 0.000001 sec 2. event: 'SQL*Net message to client' time waited: 0.000000 sec wait id: 25 p1: 'driver id'=0x62657100 p2: '#bytes'=0x1 * time between wait #2 and #3: 0.000005 sec 3. event: 'SQL*Net message from client' time waited: 0.000078 sec wait id: 24 p1: 'driver id'=0x62657100 p2: '#bytes'=0x1 } and is blocked by => Oracle session identified by: { instance: 1 (orcl.orcl) os id: 160578 process id: 106, oracle@oracle (TNS V1-V3) session id: 1285 session serial #: 47113 } which is waiting for 'SQL*Net message from client' with wait info: { p1: 'driver id'=0x62657100 p2: '#bytes'=0x1 time in wait: 2 min 22 sec timeout after: never wait id: 62 blocking: 1 session current sql: short stack: ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-read()+14<-ntpfprd()+117<-nsbasic_brc()+376<-nsbrecv()+69<-nioqrc()+495<-opikndf2()+978<-opitsk()+831<-opiino()+969<-opiodr()+917<-opidrv()+570<-sou2o()+103<-opimai_real()+133<-ssthrdmain()+265<-main()+201<-__libc_start_main()+253 wait history: * time between current wait and wait #1: 0.000006 sec 1. event: 'SQL*Net message to client' time waited: 0.000004 sec wait id: 61 p1: 'driver id'=0x62657100 p2: '#bytes'=0x1 * time between wait #1 and #2: 0.143813 sec 2. event: 'SQL*Net message from client' time waited: 25.775520 sec wait id: 60 p1: 'driver id'=0x62657100 p2: '#bytes'=0x1 * time between wait #2 and #3: 0.000003 sec 3. event: 'SQL*Net message to client' time waited: 0.000002 sec wait id: 59 p1: 'driver id'=0x62657100 p2: '#bytes'=0x1 } Chain 1 Signature: 'SQL*Net message from client'<='enq: TX - row lock contention'Chain 1 Signature Hash: 0x38c48850 orcl:/u01/src@oracle>sqlplus -prelim / as sysdbaSQL*Plus: Release 11.2.0.4.0 Production on Thu Feb 8 10:05:56 2018Copyright (c) 1982, 2013, Oracle. All rights reserved.SQL> oradebug setmypidStatement processed.SQL> oradebug unlimitStatement processed.SQL> oradebug dump systemstate 266Statement processed.SQL> oradebug dump systemstate 266Statement processed.SQL> oradebug tracefile_name/u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_192754.trcSQL> exitDisconnected from ORACLE
orcl:/u01/src@oracle>ll ass109.awk -rw-r--r-- 1 root root 34549 2月 8 09:51 ass109.awkorcl:/u01/src@oracle>awk -f ass109.awk /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_192754.trcStarting Systemstate 1....................................................................................................................Starting Systemstate 2..................................................................................................................Ass.Awk Version 1.0.9 - Processing /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_192754.trcSystem State 1~~~~~~~~~~~~~~~~1: 2: 0: waiting for 'pmon timer' 3: 0: waiting for 'rdbms ipc message' 4: 0: waiting for 'VKTM Logical Idle Wait' 5: 0: waiting for 'rdbms ipc message' 6: 0: waiting for 'DIAG idle wait' 7: 0: waiting for 'rdbms ipc message' 8: 0: waiting for 'DIAG idle wait' 9: 0: waiting for 'rdbms ipc message' 10: 0: waiting for 'rdbms ipc message' 11: 0: waiting for 'rdbms ipc message' 12: 0: waiting for 'rdbms ipc message' 13: 0: waiting for 'rdbms ipc message' 14: 0: waiting for 'rdbms ipc message' 15: 0: waiting for 'rdbms ipc message' 16: 0: waiting for 'rdbms ipc message' 17: 0: waiting for 'rdbms ipc message' 18: 0: waiting for 'rdbms ipc message' 19: 0: waiting for 'rdbms ipc message' 20: 0: waiting for 'rdbms ipc message' 21: 0: waiting for 'rdbms ipc message' 22: 0: waiting for 'rdbms ipc message' 23: 0: waiting for 'rdbms ipc message' 24: 0: waiting for 'rdbms ipc message' 25: 0: waiting for 'rdbms ipc message' 26: 0: waiting for 'rdbms ipc message' 27: 0: waiting for 'rdbms ipc message' 28: 29: 0: waiting for 'rdbms ipc message' 30: 0: waiting for 'rdbms ipc message' 31: 0: waiting for 'rdbms ipc message' 32: 33: 34: 35: 36: 37: 38: 39: 40: 41: 42: 43: 44: 45: 46: 47: 48: 49: 50: 51: 52: 53: 54: 55: 56: 57: 58: 59: 60: 61: 62: 63: 64: 65: 0: waiting for 'SQL*Net message from client' 66: 0: waiting for 'rdbms ipc message' 67: 0: waiting for 'rdbms ipc message' 68: 0: waiting for 'rdbms ipc message' 69: 0: waiting for 'rdbms ipc message' 70: 0: waiting for 'rdbms ipc message' 71: 0: waiting for 'VKRM Idle' 72: 0: waiting for 'Streams AQ: qmn coordinator idle wait' 73: 0: waiting for 'Streams AQ: emn coordinator idle wait' 74: 0: waiting for 'SQL*Net message from client' 75: 0: waiting for 'SQL*Net message from client' 76: 0: waiting for 'SQL*Net message from client' 77: 0: waiting for 'SQL*Net message from client' 78: 9: waited for 'Streams AQ: waiting for time management or cleanup tasks' 79: 0: waiting for 'SQL*Net message from client' 80: 0: waiting for 'SQL*Net message from client' 81: 0: waiting for 'SQL*Net message from client' 82: 0: waiting for 'SQL*Net message from client' 83: 0: waiting for 'SQL*Net message from client' 84: 0: waiting for 'SQL*Net message from client' 85: 0: waiting for 'SQL*Net message from client' 86: 0: waiting for 'SQL*Net message from client' 87: 0: waiting for 'PL/SQL lock timer' 88: 0: waiting for 'EMON slave idle wait' 89: 0: waiting for 'EMON slave idle wait' 90: 0: waiting for 'EMON slave idle wait' 91: 0: waiting for 'EMON slave idle wait' 92: 0: waiting for 'EMON slave idle wait' 93: 0: waiting for 'SQL*Net message from client' 94: 0: waiting for 'SQL*Net message from client' 95: 0: waiting for 'rdbms ipc message' 96: 0: waiting for 'SQL*Net message from client' 97: 0: waiting for 'SQL*Net message from client' 98: 0: waiting for 'SQL*Net message from client' 99: 0: waiting for 'SQL*Net message from client' 100:0: waiting for 'SQL*Net message from client' 101:0: waiting for 'SQL*Net message from client' 102:0: waiting for 'SQL*Net message from client' 103:0: waiting for 'Space Manager: slave idle wait' 104:0: waiting for 'enq: TX - row lock contention'[Enqueue TX-0005001B-000083BA] //--可见104进程即V$PROCESS的PID，为上述的会话2正在等待TX锁105:0: waiting for 'SQL*Net message from client' 106:0: waiting for 'SQL*Net message from client' 107:0: waiting for 'SQL*Net message from client' 108:0: waiting for 'SQL*Net message from client' 109:0: waiting for 'SQL*Net message from client' 110:0: waiting for 'SQL*Net message from client' 111:0: waiting for 'SQL*Net message from client' 112: 113:0: waiting for 'Streams AQ: qmn slave idle wait' 114: 121:0: waiting for 'rdbms ipc message' 134:0: waiting for 'Streams AQ: deallocate messages from Streams Pool' Blockers~~~~~~~~ Above is a list of all the processes. If they are waiting for a resource then it will be given in square brackets. Below is a summary of the waited upon resources, together with the holder of that resource. Notes: ~~~~~ o A process id of '???' implies that the holder was not found in the systemstate. Resource Holder StateEnqueue TX-0005001B-000083BA 106: 0: waiting for 'SQL*Net message from client'Object Names~~~~~~~~~~~~Enqueue TX-0005001B-000083BA System State 2~~~~~~~~~~~~~~~~1: 2: 0: waiting for 'pmon timer' 3: 0: waiting for 'rdbms ipc message' 4: 0: waiting for 'VKTM Logical Idle Wait' 5: 0: waiting for 'rdbms ipc message' 6: 0: waiting for 'DIAG idle wait' 7: 0: waiting for 'rdbms ipc message' 8: 0: waiting for 'DIAG idle wait' 9: 0: waiting for 'rdbms ipc message' 10: 0: waiting for 'rdbms ipc message' 11: 0: waiting for 'rdbms ipc message' 12: 0: waiting for 'rdbms ipc message' 13: 0: waiting for 'rdbms ipc message' 14: 0: waiting for 'rdbms ipc message' 15: 0: waiting for 'rdbms ipc message' 16: 0: waiting for 'rdbms ipc message' 17: 0: waiting for 'rdbms ipc message' 18: 0: waiting for 'rdbms ipc message' 19: 0: waiting for 'rdbms ipc message' 20: 0: waiting for 'rdbms ipc message' 21: 0: waiting for 'rdbms ipc message' 22: 0: waiting for 'rdbms ipc message' 23: 0: waiting for 'rdbms ipc message' 24: 0: waiting for 'rdbms ipc message' 25: 0: waiting for 'rdbms ipc message' 26: 0: waiting for 'rdbms ipc message' 27: 0: waiting for 'rdbms ipc message' 28: 0: waiting for 'smon timer' 29: 0: waiting for 'rdbms ipc message' 30: 0: waiting for 'rdbms ipc message' 31: 0: waiting for 'rdbms ipc message' 32: 33: 34: 35: 36: 37: 38: 39: 40: 41: 42: 43: 44: 45: 46: 47: 48: 49: 50: 51: 52: 53: 54: 55: 56: 57: 58: 59: 60: 61: 62: 63: 64: 65: 0: waiting for 'SQL*Net message from client' 66: 0: waiting for 'rdbms ipc message' 67: 0: waiting for 'rdbms ipc message' 68: 0: waiting for 'rdbms ipc message' 69: 0: waiting for 'rdbms ipc message' 70: 0: waiting for 'rdbms ipc message' 71: 0: waiting for 'VKRM Idle' 72: 0: waiting for 'Streams AQ: qmn coordinator idle wait' 73: 0: waiting for 'Streams AQ: emn coordinator idle wait' 74: 0: waiting for 'SQL*Net message from client' 75: 0: waiting for 'SQL*Net message from client' 76: 0: waiting for 'SQL*Net message from client' 77: 0: waiting for 'SQL*Net message from client' 78: 9: waited for 'Streams AQ: waiting for time management or cleanup tasks' 79: 0: waiting for 'SQL*Net message from client' 80: 0: waiting for 'SQL*Net message from client' 81: 0: waiting for 'SQL*Net message from client' 82: 0: waiting for 'SQL*Net message from client' 83: 0: waiting for 'SQL*Net message from client' 84: 0: waiting for 'SQL*Net message from client' 85: 0: waiting for 'SQL*Net message from client' 86: 0: waiting for 'SQL*Net message from client' 87: 0: waiting for 'PL/SQL lock timer' 88: 0: waiting for 'EMON slave idle wait' 89: 0: waiting for 'EMON slave idle wait' 90: 0: waiting for 'EMON slave idle wait' 91: 0: waiting for 'EMON slave idle wait' 92: 0: waiting for 'EMON slave idle wait' 93: 0: waiting for 'SQL*Net message from client' 94: 0: waiting for 'SQL*Net message from client' 95: 0: waiting for 'rdbms ipc message' 96: 0: waiting for 'SQL*Net message from client' 97: 0: waiting for 'SQL*Net message from client' 98: 0: waiting for 'SQL*Net message from client' 99: 0: waiting for 'SQL*Net message from client' 100:0: waiting for 'SQL*Net message from client' 101:0: waiting for 'SQL*Net message from client' 102:0: waiting for 'SQL*Net message from client' 103:0: waiting for 'Space Manager: slave idle wait' 104:0: waiting for 'enq: TX - row lock contention'[Enqueue TX-0005001B-000083BA] 105:0: waiting for 'SQL*Net message from client' 106:0: waiting for 'SQL*Net message from client' 107:0: waiting for 'SQL*Net message from client' 108:0: waiting for 'SQL*Net message from client' 109:0: waiting for 'SQL*Net message from client' 110:0: waiting for 'SQL*Net message from client' 111:0: waiting for 'SQL*Net message from client' 113:0: waiting for 'Streams AQ: qmn slave idle wait' 121:0: waiting for 'rdbms ipc message' 134:0: waiting for 'Streams AQ: deallocate messages from Streams Pool' Blockers~~~~~~~~ Above is a list of all the processes. If they are waiting for a resource then it will be given in square brackets. Below is a summary of the waited upon resources, together with the holder of that resource. Notes: ~~~~~ o A process id of '???' implies that the holder was not found in the systemstate. Resource Holder StateEnqueue TX-0005001B-000083BA 106: 0: waiting for 'SQL*Net message from client'Object Names~~~~~~~~~~~~Enqueue TX-0005001B-000083BA 150787 Lines Processed.
转载地址：http://jdhji.baihongyu.com/