利用hanganalyz/systemstate dump诊断数据库hang

最新推荐文章于 2024-01-15 13:40:26 发布

congdiku5262

最新推荐文章于 2024-01-15 13:40:26 发布

阅读量202

点赞数

诊断数据库是否hang

一般采用两个命令：hanganalyze/dump systemstate，其中systemstate级别大于256时会对每个进程进行dump，当数据库进程太多时会比较消耗资源，尤其在非solaris/linux平台

Hanganalyze

HANGANALYZE uses internal kernel calls to determine if a session is waiting for a resource, and reports the relationships between blockers and waiters. In addition, it determines which processes are "interesting" to be dumped, and may perform. automatic PROCESSSTATE dumps and ERRORSTACKS on those processes, based on the level used while executing the HANGANALYZE.

The "HANGANALYZE" command has been available since Oracle Release 8.1.6. In Oracle9i it was enhanced to provide "cluster wide" information in Real Application Cluster (RAC) environments on a single shot. The meaning of this is that it will generate information for all the sessions in the cluster regardless of the instance that issued the command.

HANGANALYZE syntax:

3 Syntax Examples:

ALTER SESSION SET EVENTS 'immediate trace name HANGANALYZE level ';

ORADEBUG hanganalyze

ORADEBUG -g def hanganalyze (Cluster wide syntax)

The sets the amount of additional information that will be extracted from the processes found by HANGANALYZE (ERROSTACK dump) based on the "STATE" of the node.

The levels are defined as follows:

Dump all processes (IGN state)

Level 4 + Dump all processes involved in wait chains (NLEAF state)

Level 3 + Dump leaf nodes (blockers) in wait chains (LEAF,LEAF_NW,IGN_DMP state)

Level 2 + Dump only processes thought to be in a hang (IN_HANG state)

1-2

Only HANGANALYZE output, no process dump at all

It is advisable not to use levels higher than 3 due to the potentially large number of trace files that may be produced (and could overwhelm the I/O subsystem). Since HANGANALYZE will be mostly used to diagnose "true" hangs, a level 3 will dump the processes that are involved in the hang condition - this usually involves fewer than 4 processes.

NOTE: In some cases hanganalyze could appear to be hung. Hanganalyze will only return when all processes are dumped. To verify that hanganalyze is working on non-clustered environments, monitor the size of the trace files in the user_dump_destination. If the trace files are growing in size, hanganalyze is not hung. To verify that hanganalyze is working on clustered environments, monitor the size of the "diag" trace file in the background_dump_destination.

Systemstate

A system state is a set of process states for all processes on the instance when the dump is taken. A system state dump is useful in determining the interaction between processes. A systemstate dump will report on resources that are being held by each process.

SYSTEMSTATE syntax:

3 Syntax Examples:

ALTER SESSION SET EVENTS 'immediate trace name SYSTEMSTATE level ';

ORADEBUG dump systemstate

ORADEBUG -g all dump systemstate (Cluster wide syntax)

The sets the amount of additional information that will be extracted from the processes found by SYSTEMSTATE dump based on the "STATE" of the node.

The levels are defined as follows:

Very basic process information only

process + session state objects

Most common level - includes state object trees for all processes

Level + 256

Adding 256 to the level will try to dump short stack info for each process.

*** IMPORTANT ***
Dumping short stacks in the systemstate dump is an enhancement that has been included in patchsets 9.2.0.6 and 10.1.0.4. It is also included in base release 10.2.0.1.

Short stacks are produced reasonably quickly on Solaris and Linux but on other platforms including short stacks in dumps can take a very long time. Hence it is advisable to test if the overhead is acceptable before using this option.

Typical levels are 266 (Solaris or Linux) and 10 (other platforms)

操作步骤

非RAC系统

The ideal manner to collect the hanganalyze and systemstate dumps is to collect 2 sets. However, it is best to have the 2 hanganalyzes in one trace file and the 2 systemstate dumps is 2 separate trace files. In order to do this, you will need 3 separate sqlplus sessions. We will identify these as SQL1, SQL2, and SQL3.

export ORACLE_SID=PROD ## Replace PROD with the SID you want to trace
Using SQL*Plus connect as SYSDBA using the following command:

sqlplus -prelim / as sysdba

Do this 3 times in 3 separate windows, creating 3 sqlplus sessions (SQL1, SQL2, and SQL3)

In SQL1 execute the following:

SQL1> oradebug setmypid
SQL1> oradebug unlimit
SQL1> oradebug hanganalyze 3

In SQL2 execute the following:

SQL2> oradebug setmypid
SQL2> oradebug unlimit
SQL2> oradebug dump systemstate 266

Wait at least 2 minutes to give time to identify process state changes.
In SQL1 execute the following:

SQL1> oradebug hanganalyze 3

In SQL3 execute the following:

SQL3> oradebug setmypid
SQL3> oradebug unlimit
SQL3> oradebug dump systemstate 266

NOTE:

Systemstate level 258 and 266 are only available in patchsets 9.2.0.6, 10.1.0.4 and base release 10.2.0.1 and higher. If you are not on one of these releases, use level 10 in place of the level suggested above. If you are using systemstate level 266 and it is taking much longer than expected to generate the dump file, then end this systemstate dump and try level 258.

RAC系统

The trace files will be written to the "diag" background process trace file in the background_dump_destination on each node.

Identify the SID you want to trace

export ORACLE_SID=PROD

Replace PROD with the SID you want to trace

Using SQL*Plus connect as "/ AS SYSDBA" using the following command:

sqlplus -prelim / as sysdba

Execute the following:

SQL> oradebug setmypid
SQL> oradebug unlimit
SQL> oradebug -g all hanganalyze 3
SQL> oradebug -g all dump systemstate 266

Wait at least 2 minutes to give time to identify process state changes.
Execute the following:

SQL> oradebug -g all hanganalyze 3
SQL> oradebug -g all dump systemstate 266

Verify that the the "diag" background process trace file has been updated in the background_dump_destination on each node. Examine each "diag" file to ensure that it contains 2 hanganalyze dumps and a systemstate dump.

检测数据库是否 hang

所谓的hang是指oracle内部死锁。当DML发生内部死锁时，oracle可以自动处理；当内核级资源(latch/pin)死锁时，通常oracle就会挂在那里

Hanganaylze报告

当CYCLE出现时，意味着数据库真的遭遇死锁了

Cycle 1 : :

<17/472/0x80057dd8/6674/library cache lock>

-- <13/7/0x800580f4/6676/library cache lock>

-- <21/204/0x8005a644/5813/library cache lock>

f your hanganalyze output has a "CYCLE" section, the database is in a hang state.

Note down the SID and OSPID for the blocker and waiter sessions to use in the Determine a Cause>Data Collection and Determine a Cause>Analysis steps. Go to the next step to collect additional data.

Open Chain

the "OPEN CHAIN" section reports sessions involved in a wait chain. A wait chain means that one session is blocking one or more other sessions. Open chains represents "stuck" or "locked" sessions

Hanganalyze #1

Open chains found:

Chain 1 : :

<16/44773/0x265f15c/1948/SQL*Net message from client>

-- <12/5/0x265fad4/2112/enqueue>

-- <13/14/0x265fdfc/2076/enqueue>

Chain 2 : :

<19/3/0x2660124/2392/No Wait>

Hanganalyze #2

Open chains found:

Chain 1 : :

<16/44773/0x265f15c/1948/SQL*Net message from client>

-- <12/5/0x265fad4/2112/enqueue>

-- <13/14/0x265fdfc/2076/enqueue>

Chain 2 : :

<19/3/0x2660124/2392/No Wait>

Hanganalyze #3

Open chains found:

Chain 1 : :

<16/44773/0x265f15c/1948/SQL*Net message from client>

-- <12/5/0x265fad4/2112/enqueue>

-- <13/14/0x265fdfc/2076/enqueue>

-- <19/3/0x2660124/2392/enqueue>

通过对比三次报告，判断会话是否阻塞时间过长，在上面例子中，需要对blocker和第一个waiter会话做errorstack；

若一个进程阻塞了10个或更多sesson，通常Open Chain之前会有Found信息，若一个blocker出现多次，则需要收集errorstack

Found 34 objects waiting for ospid/wait_event>

<131/754/0x9fc1e8/576293/No Wait>

Found 17 objects waiting for ospid/wait_event>

<245/2343/0xa19f48/575938/latch free>

Found 24 objects waiting for ospid/wait_event>

<144/2183/0xa0c9b8/575457/latch free>

Dump errorstack

SQL> oradebug setospid
SQL> oradebug unlimit
SQL> oradebug dump errorstack 3

若没有满足以上条件的输出结果，那么数据库应该是性能慢而非hang

查看errorstack报告

包含call stack和process state两部分，其中process state又有一系列的SO(state object)组成，大致分为process/session/library object lock

1 process

(process)

shows that the state object is of type process

ospid: 25765

shows that the ospid is equal to 25765

SO: 0x3661bd0c, type: 2, owner: (nil), flag: INIT/-/-/0x00

(process) Oracle pid=16, calls cur/top: 0x3672bb94/0x3672bb94, flag: (0) -

int error: 0, call error: 0, sess error: 0, txn error 0

(post info) last post received: 0 0 0

last post received-location: No post

last process to post me: none

last post sent: 0 0 0

last post sent-location: No post

last process posted by me: none

(latch info) wait_event=0 bits=0

Process Group: DEFAULT, pseudo proc: 0x3664d528

O/S info: user: oracle, term: pts/0, ospid: 25765

OSD pid info: Unix process pid: 25765, image: username@machine.name.com (TNS V1-V3)

(process)

shows that the state object is of type process

ospid: 25765

shows that the ospid is equal to 25765

2 session

SO: 0x366dd1b4, type: 4, owner: 0x3661bd0c, flag: INIT/-/-/0x00

(session) sid: 118 trans: 0x354e1fb0, creator: 0x3661bd0c, flag: (41) USR/- BSY/-/-/-/-/-

DID: 0001-0010-000010E9, short-term DID: 0000-0000-00000000

txn branch: (nil)

oct: 26, prv: 0, sql: 0x3076f3f8, psql: 0x32a2c520, user: 54/SCOTT

O/S info: user: oracle, term: pts/0, ospid: 25764, machine: machine.name.com

program: sqlplus@machine.name.com (TNS V1-V3)

application name: SQL*Plus, hash value=3669949024

waiting for 'enq: TM - contention' blocking sess=0x0x366c7f14 seq=39 wait_time=0 seconds since wait started=11900

name|mode=544d0006, object #=c7cc, table/partition=0

(session)

shows that the state object is of type process

sid: 118

shows that the sid for this session is 118. This is used to ensure that you are looking at the correct session.

sql: 0x3076f3f8

shows that the address of the SQL for this session is 3076f3f8. This will be used to find the Active SQL in the next step.

waiting for 'enq: TM - contention'

shows that the wait event for this session is enq: TM - contention. This will be used when determining the type of lock associated with the hang or lock situation that you are troubleshooting.

name|mode=544d0006

shows the value for P1 if the wait event is an enqueue. P1 is a hexadecimal value that represents the lock type and lock mode (lmode). See MetaLink Note 34566.1 for details on obtaining the lock type and lock mode from P1. MetaLink Note 29787.1 provides details on the lock types and lock modes.

3 library object lock

通过session信息里的sql address搜查，可以找到相应的library object lock(搜索时去掉0x前缀)

SO: 0x2f041b48, type: 53, owner: 0x366dd1b4, flag: INIT/-/-/0x00

LIBRARY OBJECT LOCK: lock=2f041b48 handle=3076f3f8 mode=N

call pin=(nil) session pin=(nil) hpc=0000 hlc=0000

htl=0x2f041b94[0x30c3e358,0x324497a4] htb=0x30c3e358 ssga=0x30c3de24

user=366dd1b4 session=366dd1b4 count=1 flags=[0000] savepoint=0x460964fc

LIBRARY OBJECT HANDLE: handle=3076f3f8 mtx=0x3076f4ac(1) cdp=1

name=lock table emp in exclusive mode

hash=01e8abf8cabca30a0249f91737e32c8f timestamp=03-27-2007 14:39:28

namespace=CRSR flags=RON/KGHP/TIM/PN0/SML/KST/DBN/MTX/[120100d0]

kkkk-dddd-llll=0000-0001-0001 lock=N pin=0 latch#=1 hpc=0002 hlc=0002

lwt=0x3076f454[0x3076f454,0x3076f454] ltm=0x3076f45c[0x3076f45c,0x3076f45c]

pwt=0x3076f438[0x3076f438,0x3076f438] ptm=0x3076f440[0x3076f440,0x3076f440]

ref=0x3076f474[0x3076f474,0x3076f474] lnd=0x3076f480[0x3076f480,0x3076f480]

LIBRARY OBJECT LOCK

shows that the state object is of type Library Object Lock

LIBRARY OBJECT HANDLE: handle=3076f3f8

shows that the Library Object Handle address is 3076f3f8. This address is the same as the SQL address found in the "session" state object. This is use to verify that this is the state object containing the active SQL.

name=lock table emp in exclusive mode

show that the active SQL is "lock table emp in exclusive mode".

Callstack

可以将显示的function在MOS作为关键字搜索，一般来说需要忽略kse/ksd打头的

As a general rule, ignore the functions beginning with 'kse' and 'ksd'. Start by using the first 5 functions following the 'kse' and 'ksd' functions. You may need to try several combinations of search criteria before finding any previously identified issues that match the issue you are attempting to troubleshoot.

对该案例可以尝试ntprd nsprecv nsrdr nsdo nsbrecv enq: TM conection关键字搜索

----- 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 ? 8409404 ? AC007B ? 18 ?

C0246C4 ? 6 ?

ksdxfdmp()+1382 call 0C969FDE 3 ? 1 ? BBA5021 ? 6F64736E ?

312B2928 ? 373134 ?

ksdxcb()+1321 call 00000000 BFFFC3B0 ? 11 ? 3 ?

BFFFC310 ? BFFFC360 ?