oradebug分析oracle hang

sqlplus -prelim /nolog
connect / as sysdba

oradebug setmypid
oradebug hanganalyze 3

oradebug unlimit;
oradebug dump systemstate 10

ORADEBUG TRACEFILE_NAME

 

 

轉：

sql*plus命令oradebug
sql*plus命令oradebug對於診斷效能和hang住問題非常有用。在其他方面，它也可以用來檢查RAC的inter-instance communication
是否使用了正確的IP地址。
1、ORADEBUG介紹
oradebug起著debug和trace的目的。需要以sysdba連線到資料庫。它可以用於：
A、enable SQL trace in your own server process or a foreign server process
B、figure out which trace file a process is writing to
C、dump internal ORACLE structures for diagnosing database hangs or memory corruptions
D、dump information from data file headers or undo segments headers
E、determine which shared memory segments and semaphores a DBMS instance uses
F、find out which interconnect address and protocol RAC instances use
G、modify data structures in the SGA
In all likelihood, the last item will be relevant only to Oracle Support personnel.
2、oradebug的工作流程
使用oradebug時，工作流程如下：
1. Start SQL*Plus and connect as SYSDBA.
2. Attach to a process of an ORACLE instance.
3. Issue one or more ORADEBUG commands.
4. Examine screen output or trace files.
5. Detach from the process (occurs automatically when exiting from SQL*Plus or attaching to
another process).
3、ORADEBUG Command Reference
SQL> oradebug help
ORADEBUG HELP command displays a single line help text on a command. Yet, this is no more
detailed than what ORADEBUG HELP provides.
4、Attaching to a Process
在執行任何oradebug命令之前，必須先Attaching to a target process。The
following three options exist:
A、Attaching to your own server process—the process serving your SQL*Plus session.
B、Attaching to a foreign server process by ORACLE process identifier.
C、Attaching to a foreign process by operating system process identifier.
Attaching to a process that belongs to a RAC instance on another node in the same cluster
is not implemented.
Command Purpose
ORADEBUG SETMYPID Attach to your own server process
ORADEBUG SETORAPID pid Attach to a foreign process, where pid equals V$PROCESS.PID
ORADEBUG SETOSPID spid Attach to a foreign process, where spid equals V$PROCESS.SPID
5、SETMYPID
In case you wanted to run a few SQL or PL/SQL statements in your own session to record
performance metrics and execution plans, you would use ORADEBUG SETMYPID.
SQL> ORADEBUG SETMYPID
Statement processed.
SQL> ORADEBUG UNLIMIT
Statement processed.
SQL> ORADEBUG EVENT 10046 TRACE NAME CONTEXT FOREVER, LEVEL 8
Statement processed.
SQL> SELECT ... /* run whatever statements you want to trace */
SQL> ORADEBUG TRACEFILE_NAME
/opt/oracle/obase/admin/TEN/udump/ten1_ora_24953.trc
SQL> ORADEBUG EVENT 10046 TRACE NAME CONTEXT OFF
Statement processed.
6、SETOSPID
A scenario for SETOSPID is when you see an ORACLE process that consumes a lot of CPU with a
tool such as top (any UNIX platform), prstat (Solaris), glance (HP-UX), or nmon (AIX). You would
then attach to the process and enable SQL trace with event 10046 at level 8 or 12.
7、SETORAPID
SQL> SELECT pid, spid
FROM v$process p, v$session s
WHERE s.sid=151 and s.paddr=p.addr;
PID SPID
---------- ------
19 15365
SQL> ORADEBUG SETORAPID 19
Unix process pid: 15365, image: oracle@dbserver1.oradbpro.com (TNS V1-V3)
When trace data collection is complete, switch off extended SQL trace with ORADEBUG EVENT
10046 TRACE NAME CONTEXT OFF.
8、ORADEBUG IPC
ORADEBUG IPC may be used to find out which UNIX shared memory segment(s) an ORACLE
instance uses. On platforms where ORACLE instances use semaphores for synchronization,（On AIX the postwait kernel extension is used instead of semaphores.）
information on semaphores is also included. RAC instances write information on the interconnect
IP address and protocol to the trace file. This is particularly useful to verify the interconnect
addresses in Oracle9i, since releases prior to Oracle10g do not write this information to the
alert log.
On UNIX systems, each shared memory segment and semaphore set has a unique identifier.
These identifiers are listed by the command ipcs. Use ipcs -mb to list shared memory segments
along with the owner and size.
The following section shows how to dump IPC information. The trace file is from a RAC
instance. Thus it contains not only shared memory identifiers, but also information on the
cluster interconnect, which is marked by the string “SSKGXPT” in both Oracle9i and Oracle10g.
$ sqlplus "/ as sysdba"
Connected to:
Oracle9i Enterprise Edition Release 9.2.0.8.0 - 64bit Production
With the Real Application Clusters option
SQL> ORADEBUG SETMYPID
Statement processed.
SQL> ORADEBUG IPC
Information written to trace file.
SQL> ORADEBUG TRACEFILE_NAME
/var/opt/oracle/udump/fhs91_ora_1065152.trc
The following trace file excerpts include the relevant sections. Note how the shared memory
identifier 7 matches the output of the command ipcs depicted earlier.
Shared Memory:
ID KEY
7 0xc3f37a04
The following trace file section indicates that the IP address 172.16.0.1 is used as the RAC
interconnect address. The interconnect protocol is UDP (user datagram protocol).
SSKGXPT 0x1028d484 flags SSKGXPT_READPENDING active network 0
info for network 0
socket no 8 IP 172.16.0.1 UDP 52608
ORADEBUG may also be used with ASM instances. Following is an example that illustrates the
use of semaphores by an ASM instance:
$ env ORACLE_SID=+ASM1 sqlplus / as sysdba
SQL> ORADEBUG SETMYPID
Statement processed.
SQL> ORADEBUG IPC
Information written to trace file.
SQL> ORADEBUG TRACEFILE_NAME
/opt/oracle/obase/admin/+ASM/udump/+asm1_ora_19685.trc
SQL> !grep -A 1 "Semaphore List" /opt/oracle/obase/admin/+ASM/udump/+asm1_ora_19685.
trc
Semaphore List=
884736
$ ipcs -s
------ Semaphore Arrays --------
key semid owner perms nsems
0x2c13c9dc 884736 oracle 640 44
0xcbcd5e70 1146881 oracle 640 154
The smaller semaphore set with identifier 884736 was used by an ASM instance, whereas
the larger set with 154 semaphores was used by an RDBMS instance.（The number of semaphores allocated depends on the initialization parameter PROCESSES, which had
the values 40 and 150 in the ASM and RDBMS instances, respectively.）
In a situation where one out of several instances on a system has failed without cleaning
up shared memory and/or semaphores, ORADEBUG IPC is the ideal tool to gather the information
required to perform. cleanup with the command ipcrm. The UNIX IPC identifiers reproduced in
bold in the preceding examples may be used to remove shared memory segments and semaphore
sets with ipcrm. IPC identifiers are not reused when an ORACLE instance is shut down
and restarted. When resources on a machine are scarce, it may happen that an ORACLE instance
cannot be started due to resources allocated to stale shared memory segments or semaphore
sets left behind by a crashed instance. Under these circumstances, the removal of both types of
IPC structures with ipcrm is the solution.
9、ORADEBUG SHORT_STACK
A program call stack represents how routines in a program call each other. If a program hangs,
the program call stack shows in which routine it hangs. These are the two ways of obtaining a
program call stack with ORADEBUG:
A、The ERRORSTACK diagnostic dump
B、The SHORT_STACK command
The ERRORSTACK dump results in a large trace file. The command SHORT_STACK is well suited
to quickly determine which routine is currently executed by a server process. The output of this
command is sent to a terminal window and not to a trace file. It is available in Oracle10g and
subsequent releases. Following is an example:
SQL> ORADEBUG SETOSPID 14807
Oracle pid: 34, Unix process pid: 14807, image: oracleDZAV024@l012r065
SQL> ORADEBUG SHORT_STACK
The current routine is at the top of the output. Of course, dumping the call stack affects the
call stack itself. Presumably ksdxcb is a debug callback function for performing a stack dump. I
assume that the routine kdsgrp was executed when the command SHORT_STACK was received by
the attached process. The names of the routines may be used as search keywords on the Metalink
support platform.
10、Diagnostic Dumps
Oracle9i Release 2 supports 85 different diagnostic dumps, Oracle10g supports 146, and Oracle11g
165. Due to the large amount of dumps, it’s impossible to cover more than a few. To list the
dump names, run ORADEBUG DUMPLIST.
A、CONTROLF
This option is for dumping the control file(s) at different levels of detail. Here’s an example of a
level 1 dump:
Received ORADEBUG command 'DUMP CONTROLF 1' from process Windows thread id: 3580,
image:
DUMP OF CONTROL FILES, Seq # 545 = 0x221
V10 STYLE. FILE HEADER:
Compatibility Vsn = 169869568=0xa200100
Db ID=1156831202=0x44f3d7e2, Db Name='ORCL'
Activation ID=0=0x0
Control Seq=545=0x221, File size=430=0x1ae
File Number=0, Blksiz=16384, File Type=1 CONTROL
B、EVENTS
The EVENTS dump is not a true diagnostic dump. It merely writes the enabled events to a trace
file. If you are uncertain which events are active in a session, process, or instance, this is the
correct way to find out. Here is an example:
SQL> ALTER SESSION SET EVENTS '10046 trace name context forever, level 8';
Session altered.
SQL> ALTER SESSION SET EVENTS '4031 trace name heapdump level 3';
Session altered.
SQL> ORADEBUG SETMYPID
Statement processed.
SQL> ORADEBUG DUMP EVENTS 1
Statement processed.
SQL> ORADEBUG TRACEFILE_NAME
/opt/oracle/obase/admin/TEN/udump/ten1_ora_20206.trc
ORADEBUG DUMP EVENTS Levels and Scope
Level Event Scope Command Used
1 Session ALTER SESSION, DBMS_SYSTEM.SET_EV
2 Process ORADEBUG EVENT
4 Instance ALTER SYSTEM
C、ERRORSTACK
ERRORSTACK Trace File Contents
Trace File Sections Level 1 Level 2 Level 3
Current SQL statement yes yes yes
Call stack trace yes yes yes
Process state (includes session wait history) no yes yes
Enabled events at session and instance level no no yes
Cursor dump no no yes
Following is an example of an ERRORSTACK dump:
SQL> ORADEBUG SETOSPID 6524
Oracle pid: 16, Unix process pid: 6524, image: oracleTEN1@dbserver1.oradbpro.com
SQL> ORADEBUG DUMP ERRORSTACK 1
Statement processed.
SQL> ORADEBUG TRACEFILE_NAME
/opt/oracle/obase/admin/TEN/udump/ten1_ora_6524.trc
SQL> !less /opt/oracle/obase/admin/TEN/udump/ten1_ora_6524.trc
Received ORADEBUG command 'DUMP ERRORSTACK 1' from process Unix process pid: 6518,
image:
*** 2007-09-09 12:36:02.525
ksedmp: internal or fatal error
Current SQL statement for this session:
SELECT sys_context('userenv', 'sessionid'),sys_context('userenv', 'client_identifier
'),sys_context('userenv', 'client_info'),sys_context('userenv', 'host'), /* correspo
nds to v$session.machine */sys_context('userenv', 'os_user'), /* corresponds to v$se
ssion.osuser */ sys_context('userenv', 'terminal')FROM dual
----- Call Stack Trace -----
calling call entry argument values in hex
location type point (? means dubious value)
-------------------- -------- -------------------- ----------------------------
ksedst()+27 call ksedst1() 1 ? 1 ?
ksedmp()+557 call ksedst() 1 ? 2A120F04 ? 76010B ?
2A11FC8E ? 0 ? BFFFB638 ?
ksdxfdmp()+1382 call 0C94496E 1 ? 83CD95B ? C816D60 ?
BFFFB7DC ? 83E55FD ?
2EAF9940 ?
ksdxcb()+1321 call 00000000 BFFFBAE8 ? 11 ? 3 ?
BFFFBA48 ? BFFFBA98 ?
sspuser()+102 call 00000000 1 ? 2000 ? 0 ? 0 ? 0 ? 0 ?
0071A7A0 signal 00000000 C ? BFFFBF70 ? BFFFBFF0 ?
nttrd()+155 call snttread() D ? C86BEC6 ? 810 ? 0 ?
…
At the time when the stack was dumped, the server process was waiting for a network
packet from the client in the routine nttrd. The wait event SQL*Net message from client in
V$SESSION confirms this.
SQL> SELECT p.spid, s.event, s.state
FROM v$session s, v$process p
WHERE s.username='NDEBES'
AND s.paddr=p.addr;
SPID EVENT STATE
------------ --------------------------- -------
6524 SQL*Net message from client WAITING
The routine nttrd waited for the UNIX system call read to return. Using the system call
tracing utility strace reveals that the read system call was done against file descriptor 13, which
represents a socket connection between the traced dedicated server process and the client.
$ strace -p 6524
Process 6524 attached - interrupt to quit
read(13,
Process 6524 detached
$ ls -l /proc/6524/fd/13
lrwx------ 1 oracle oinstall 64 Sep 9 13:08 /proc/6524/fd/13 -> socket:[4514905]
D、HANGANALYZE
The command HANGANALYZE performs a hang analysis dump. Such dumps are taken to diagnose
database hanging issues. Please refer to the very extensive Metalink note 61552.1 for more
information on this topic. Following is an example of a level 1 hang analysis dump. The scenario
was as follows:
1. Session 141 (V$SESSION.SID=141) executed LOCK TABLE IN EXCLUSIVE MODE on a table.
2. Session 147 tried to insert into the same table.
3. The INSERT statement executed by session 147 had to wait for session 141 to release the
table lock.
The resulting hang analysis dump is shown next. Chains list waiting sessions. Chains that
contain more than a single session indicate that the session at the head of the chain (on the left)
is blocking other sessions in the same chain.
==============
HANG ANALYSIS:
==============
Open chains found:
Chain 1 : :
<0/141/47/3580/No Wait> -- <0/147/518/6064/enq: TM - contention>
Other chains found:
Chain 2 : :
<0/145/117/5244/jobq slave wait>
Chain 3 : :
<0/150/38/440/Streams AQ: qmn slave idle wait>
Chain 4 : :
<0/152/1/5440/Streams AQ: waiting for time man>
Chain 5 : :
<0/154/1/4584/Streams AQ: qmn coordinator idle>
Extra information that will be dumped at higher levels:
[level 4] : 1 node dumps -- [REMOTE_WT] [LEAF] [LEAF_NW]
[level 5] : 4 node dumps -- [SINGLE_NODE] [SINGLE_NODE_NW] [IGN_DMP]
[level 6] : 1 node dumps -- [NLEAF]
[level 10] : 11 node dumps -- [IGN]
E、MODIFIED_PARAMETERS
This dump records any initialization parameters that were modified with ALTER SESSION or
ALTER SYSTEM in a trace file. Level 1 is sufficient. Higher levels do not produce more detailed
output. In the following example, the initialization parameters PGA_AGGREGATE_TARGET and
SKIP_UNUSABLE_INDEXES are modified. Thus, these parameters and their new values appear in
the MODIFIED_PARAMETERS dump.
SQL> ALTER SYSTEM SET pga_aggregate_target=512m;
System altered.
SQL> ALTER SESSION SET skip_unusable_indexes=true;
System altered.
SQL> ORADEBUG DUMP MODIFIED_PARAMETERS 1
Statement processed.
The trace file contains an entry for each modified parameter.
Received ORADEBUG command 'DUMP MODIFIED_PARAMETERS 1' from process Windows thread
id: 3580, image:
DYNAMICALLY MODIFIED PARAMETERS:
pga_aggregate_target = 536870912
skip_unusable_indexes = TRUE
F、PROCSTAT and Process-Level Operating System Statistics
Process-level operating system statistics may be dumped to a trace file with the command
ORADEBUG PROCSTAT. CPU usage is reported at a more granular level than by the statistic “CPU
used by this session” in V$SESSTAT. Here is an example:
SQL> ORADEBUG PROCSTAT
SQL> ORADEBUG TRACEFILE_NAME
/opt/oracle/obase/admin/TEN/udump/ten1_ora_8739.trc
SQL> !cat /opt/oracle/obase/admin/TEN/udump/ten1_ora_8739.trc
----- Dump of Process Statistics -----
User time used = 500
System time used = 1750
…
Page reclaims = 66357
Page faults = 1
…
Voluntary context switches = 2775
Involuntary context switches = 65892