oracle oradebug analyze 的日常使用详解数据库

oracle oradebug analyze 是dba分析问题的必备技能，建议dba们空闲的时候可以多做做实验，熟能生巧。

数据库版本

$sqlplus system/oracleoracle 
 
SQL*Plus: Release 12.2.0.1.0 Production on Fri Apr 27 17:35:11 2018 
 
Copyright (c) 1982, 2016, Oracle.  All rights reserved. 
 
 
Connected to: 
Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production 
 
SQL> 
SQL> set lines 200;  
SQL> set pages 200; 
SQL>  
SQL> select * from v$version; 
 
BANNER                                           CON_ID 
-------------------------------------------------------------------------------- ---------- 
Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production          0 
PL/SQL Release 12.2.0.1.0 - Production                            0 
CORE    12.2.0.1.0  Production                                0 
TNS for Linux: Version 12.2.0.1.0 - Production                        0 
NLSRTL Version 12.2.0.1.0 - Production                            0 
 
SQL> 

创建测试表，插入测试数据

SQL> create table tmp_peiyb_20180427 ( a varchar2(100),b varchar2(100)); 
 
Table created. 
 
SQL> insert into tmp_peiyb_20180427(a,b) values('aa','bb'); 
 
1 row created. 
 
SQL> commit; 
 
Commit complete. 
 
SQL>  
SQL> 

session 1 更新，不commit

SQL> update tmp_peiyb_20180427 set b='cc' where a='aa'; 
 
1 row updated. 
 
SQL> 

session 2 更新，会处于wait状态

SQL> update tmp_peiyb_20180427 set b='cc' where a='aa'; 

session 3 使用sys执行 debug analyze

SQL> oradebug setmypid; 
Statement processed. 
SQL> oradebug unlimit; 
Statement processed. 
SQL> oradebug hanganalyze 3;   
Hang Analysis in /u01/app/oracle/diag/rdbms/rac0/rac01/trace/rac01_ora_32339.trc 
SQL>  
SQL> oradebug TRACEFILE_NAME; 
/u01/app/oracle/diag/rdbms/rac0/rac01/trace/rac01_ora_32339.trc 
SQL>  
SQL>  
SQL>  
SQL>  
SQL>  
SQL> oradebug hanganalyze 3; 
Hang Analysis in /u01/app/oracle/diag/rdbms/rac0/rac01/trace/rac01_ora_32339.trc 
SQL> oradebug TRACEFILE_NAME; 
/u01/app/oracle/diag/rdbms/rac0/rac01/trace/rac01_ora_32339.trc 
SQL> oradebug CLOSE_TRACE; 
Statement processed. 
SQL> exit;

分析 trace 文件
这里截取了部分内容说明下：

基本信息

Trace file /u01/app/oracle/diag/rdbms/rac0/rac01/trace/rac01_ora_32339.trc 
Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production 
Build label:    RDBMS_12.2.0.1.0_LINUX.X64_170125 
ORACLE_HOME:    /u01/app/oracle/product/12.2.0/db_1 
System name:    Linux 
Node name:  nodea 
Release:    3.10.0-693.el7.x86_64 
Version:    #1 SMP Tue Aug 22 21:09:27 UTC 2017 
Machine:    x86_64 
Instance name: rac01 
Redo thread mounted by this instance: 1 
Oracle process number: 51 
Unix process pid: 32339, image: [email protected] (TNS V1-V3)

问题的简单描述

=============================================================================== 
 
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: 'REPL Capture/Apply: RAC AQ qmn coordinator' 
     Chain 2 Signature Hash: 0x38f1e28b

chain 1 详细描述

------------------------------------------------------------------------------- 
Chain 1: 
------------------------------------------------------------------------------- 
Oracle session identified by: 
{ 
instance: 1 (rac0.rac01) 
os id: 23580 
process id: 74, [email protected] (TNS V1-V3) 
session id: 97 
session serial #: 46397 
pdb id: 1 (CDB$ROOT) 
} 
is waiting for 'enq: TX - row lock contention' with wait info: 
{ 
p1: 'name|mode'=0x54580006 
p2: 'usn<<16 | slot'=0x10011 
p3: 'sequence'=0x2f1 
px1: 'pdb uid'=0x1 
px2: 'master hint'=0x2 
time in wait: 2 min 47 sec 
timeout after: never 
wait id: 67 
blocking: 0 sessions 
current sql: update tmp_peiyb_20180427 set b='cc' where a='aa' 
short stack: ksedsts()+346<-ksdxfstk()+71<-ksdxcb()+912<-sspuser()+217<-__sighandler()<-semtimedop()+10<-skgpwwait()+200<-ksliwat()+2292<-kslwaitctx()+197<-kjusuc()+9058<-ksipgetctxia()+5359<-ksqcmi()+27067<-ksqgtlctx()+4872<-ksqgelctx()+771<-ktuGetTxForXid()+241<-ktcwit1()+378<-kdddgb()+6484<-kdusru()+552<-updrowFastPath()+1229<-qerupFetch()+899<-updaul()+1399<-updThreePhaseExe()+325<-updexe()+435<-opiexe()+10959<-kpoal8()+2679<-opiodr()+1229<-ttcpip()+1257<-opitsk()+1940<-opiino()+941<-opiodr()+1229<-opidrv()+1021<-sou2o()+1 
wait history: 
* time between current wait and wait #1: 0.000582 sec 
1.       event: 'SQL*Net message from client' 
time waited: 1 min 57 sec 
wait id: 66               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: 65               p1: 'driver id'=0x62657100 
p2: '#bytes'=0x1 
* time between wait #2 and #3: 0.000025 sec 
3.       event: 'SQL*Net message from client' 
time waited: 0.000145 sec 
wait id: 64               p1: 'driver id'=0x62657100 
p2: '#bytes'=0x1 
} 
and is blocked by 
=> Oracle session identified by: 
{ 
instance: 1 (rac0.rac01) 
os id: 24434 
process id: 78, [email protected] (TNS V1-V3) 
session id: 49 
session serial #: 18438 
pdb id: 1 (CDB$ROOT) 
} 
which is waiting for 'SQL*Net message from client' with wait info: 
{ 
p1: 'driver id'=0x62657100 
p2: '#bytes'=0x1 
time in wait: 3 min 24 sec 
timeout after: never 
wait id: 91 
blocking: 1 session 
current sql: <none> 
short stack: ksedsts()+346<-ksdxfstk()+71<-ksdxcb()+912<-sspuser()+217<-__sighandler()<-read()+14<-ntpfprd()+141<-nsbasic_brc()+432<-nioqrc()+6340<-opikndf2()+1071<-opitsk()+890<-opiino()+941<-opiodr()+1229<-opidrv()+1021<-sou2o()+145<-opimai_real()+455<-ssthrdmain()+417<-main()+262<-__libc_start_main()+245 
wait history: 
* time between current wait and wait #1: 0.000007 sec 
1.       event: 'SQL*Net message to client' 
time waited: 0.000001 sec 
wait id: 90               p1: 'driver id'=0x62657100 
p2: '#bytes'=0x1 
* time between wait #1 and #2: 0.014772 sec 
2.       event: 'PGA memory operation' 
time waited: 0.000016 sec 
wait id: 89               p1: ''=0x10000 
p2: ''=0x1 
* time between wait #2 and #3: 0.004890 sec 
3.       event: 'PGA memory operation' 
time waited: 0.000012 sec 
wait id: 88               p1: ''=0x10000 
p2: ''=0x1 
} 
Chain 1 Signature: 'SQL*Net message from client'<='enq: TX - row lock contention' 
Chain 1 Signature Hash: 0x38c48850

chain 2 详细描述

------------------------------------------------------------------------------- 
Chain 2: 
------------------------------------------------------------------------------- 
Oracle session identified by: 
{ 
instance: 1 (rac0.rac01) 
os id: 7836 
process id: 72, [email protected] (QM05) 
session id: 76 
session serial #: 56663 
pdb id: 1 (CDB$ROOT) 
} 
is waiting for 'REPL Capture/Apply: RAC AQ qmn coordinator' with wait info: 
{ 
p1: '1=>MASTER 2=>SLAVE'=0x1 
time in wait: 0.047702 sec (last interval) 
time in wait: 6.579727 sec (total) 
heur. time in wait: 31 min 6 sec 
timeout after: 53.420273 sec 
wait id: 18507 
blocking: 0 sessions 
current sql: <none> 
short stack: ksedsts()+346<-ksdxfstk()+71<-ksdxcb()+912<-sspuser()+217<-__sighandler()<-__poll()+16<-ipcgxp_selectex()+409<-ipclw_wait()+1045<-ksxpwait_ipclw()+3844<-ksxpwait_int()+22103<-ksxpwait()+845<-ksliwat()+10910<-kslwaitctx()+197<-knlpwaitandrmsg()+867<-knlpipcmaster()+1064<-kwsbgMsProc()+301<-kwsbgcbkms()+31<-ksvrdp_int()+2010<-opirip()+602<-opidrv()+602<-sou2o()+145<-opimai_real()+202<-ssthrdmain()+417<-main()+262<-__libc_start_main()+245 
wait history: 
* time between current wait and wait #1: 0.000000 sec 
1.       event: 'AQ: RAC AQ Network' 
time waited: 0.000009 sec 
wait id: 18573            
* time between wait #1 and #2: 0.000000 sec 
2.       event: 'REPL Capture/Apply: RAC AQ qmn coordinator' 
time waited: 0.100131 sec (last interval) 
time waited: 6.532016 sec (total) 
wait id: 18507            p1: '1=>MASTER 2=>SLAVE'=0x1 
* time between wait #2 and #3: 0.000000 sec 
3.       event: 'AQ: RAC AQ Network' 
time waited: 0.000005 sec 
wait id: 18572            
} 
Chain 2 Signature: 'REPL Capture/Apply: RAC AQ qmn coordinator' 
Chain 2 Signature Hash: 0x38f1e28b 
-------------------------------------------------------------------------------

注意观察一些关键字， session id、is blocked by、is waiting for

session 3 在rac的环境下

SQL>  
SQL> oradebug setmypid; 
Statement processed. 
SQL> oradebug unlimit; 
Statement processed. 
SQL> oradebug setinst all; 
Statement processed. 
SQL>  
SQL> oradebug -g def hanganalyze 3; 
Hang Analysis in /u01/app/oracle/diag/rdbms/rac0/rac01/trace/rac01_diag_4140.trc 
SQL>  
SQL> oradebug -g all hanganalyze 3; 
Hang Analysis in /u01/app/oracle/diag/rdbms/rac0/rac01/trace/rac01_diag_4140.trc 
SQL>  
SQL> oradebug CLOSE_TRACE; 
Statement processed.

oradebug hanganalyze level

一般情况下，level 3 在一般情况下足够，另外几个level的说明如下：

10   Dump all processes (IGN state) 
5    Level 4 + Dump all processes involved in wait chains (NLEAF state) 
4    Level 3 + Dump leaf nodes (blockers) in wait chains (LEAF,LEAF_NW,IGN_DMP state) 
3    Level 2 + Dump only processes thought to be in a hang (IN_HANG state) 
1-2  Only HANGANALYZE output, no process dump at all

无法登录数据库，需要添加 -prelim 参数

sqlplus -prelim / as sysdba;