月归档:五月 2012

使用ass109.awk分析systemstate

本篇介绍工具ass109.awk使用,大大节约分析systemstate dump文件时间.当然如果要获得详细信息,还是需要人工去读相关进程的dump文件.
模拟会话被hang住

--会话1
SQL> select * from t_xifenfei;

        ID NAME
---------- ----------------------------------------
         1 xifenfei
         2 www.xifenfei

SQL> delete from t_xifenfei where id=1;

1 row deleted.

--会话2
SQL> delete from t_xifenfei where id=1;
--hang住

做systemstate

SQL> oradebug setmypid
Statement processed.
SQL>  oradebug unlimit
Statement processed.
SQL> oradebug dump systemstate 10
Statement processed.
SQL> oradebug tracefile_name
/u01/oracle/diag/rdbms/ora11g/ora11g/trace/ora11g_ora_9976.trc
SQL> exit

使用ass109.awk分析dump文件

[oracle@xifenfei ~]$ awk -f ass109.awk /u01/oracle/diag/rdbms/ora11g/ora11g/trace/ora11g_ora_9976.trc

Starting Systemstate 1
..................................
Ass.Awk Version 1.0.9 - Processing /u01/oracle/diag/rdbms/ora11g/ora11g/trace/ora11g_ora_9976.trc

System 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 'smon timer'         
14: 0: waiting for 'rdbms ipc message'  
15: 0: waiting for 'rdbms ipc message'  
16: 0: waiting for 'rdbms ipc message'  
17:                                     
18:                                     
19: 0: waiting for 'Space Manager: slave idle wait' 
20: 0: waiting for 'SQL*Net message from client' 
21: 0: waiting for 'enq: TX - row lock contention'[Enqueue TX-000A0020-0000024F] 
     Cmd: Delete
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 'Streams AQ: qmn coordinator idle wait' 
27:                                     
28:                                     
30: 0: waiting for 'Streams AQ: qmn slave idle wait' 
31: 0: waiting for 'rdbms ipc message'  
33: 1: waited for 'Streams AQ: waiting for time management or cleanup tasks' 
35: 0: waiting for 'rdbms ipc message'  
41:                                     
44:                                     
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 State
Enqueue TX-000A0020-0000024F    20: 0: waiting for 'SQL*Net message from client'

Object Names
~~~~~~~~~~~~
Enqueue TX-000A0020-0000024F                                                                 

30586 Lines Processed.
--从这里马上就可以知道pid 21 请求Enqueue TX被pid 20阻塞

下载:ass109.awk

发表在 Oracle性能优化 | 标签为 , | 2 条评论

Systemstates分析会话阻塞—锁表

模拟会话被阻塞

--会话1
SQL> select sid from v$mystat where rownum=1;

       SID
----------
        15

SQL> create table t_xifenfei (id number,name varchar2(20));

Table created.

SQL> insert into t_xifenfei values(1,'xifenfei');

1 row created.

SQL> insert into t_xifenfei values(2,'www.xifenfei');

1 row created.

SQL> commit;

Commit complete.

SQL> select * from t_xifenfei;

        ID NAME
---------- ----------------------------------------
         1 xifenfei
         2 www.xifenfei

SQL> delete from t_xifenfei where id=1;

1 row deleted.

--会话2
SQL>  select sid from v$mystat where rownum=1;

       SID
----------
       143

SQL> delete from chf.t_xifenfei where id=1;
--hang住

新打开会话做Systemstates
我们假设不知道会话1和会话2的sid,现在特定的使用Systemstates分析问题,后面给出简单分析方法

SQL> oradebug setmypid
Statement processed.
SQL> oradebug unlimit
Statement processed.
SQL> oradebug dump systemstate 10
Statement processed.
SQL> oradebug dump systemstate 10
Statement processed.
SQL> oradebug tracefile_name
/u01/oracle/diag/rdbms/ora11g/ora11g/trace/ora11g_ora_31027.trc
SQL> exit

阅读trace文件
会话2在这样的情况下hang住,而其他会话正常,第一反应是在lock级别阻塞了,而这个又是DML操作,很自然想到是TX,于是在trace文件中搜索”enq: TX” ,找到对应记录,然后向上找到对应的进程号,开始读相关内容,发现有小信息如下:

PROCESS 20: 
  ----------------------------------------
--客户端信息
    client details:
      O/S info: user: oracle, term: pts/0, ospid: 30622
      machine: xifenfei program: sqlplus@xifenfei (TNS V1-V3)
      application name: SQL*Plus, hash value=3669949024

--进程相关session信息
    (session) sid: 15 ser: 151 trans: 0x343a4c2c, creator: 0x35fe2218
              flags: (0x45) USR/- flags_idl: (0x0) -/-/-/-/-/-
              flags2: (0x40009) -/-/INC
              DID: , short-term DID: 
              txn branch: (nil)
              oct: 0, prv: 0, sql: (nil), psql: 0x2f6e7b68, user: 84/CHF

--被阻塞会话信息
    There are 1 sessions blocked by this session.
    Dumping one waiter:
      inst: 1, sid: 143, ser: 229
      wait event: 'enq: TX - row lock contention'
        p1: 'name|mode'=0x54580006
        p2: 'usn<<16 | slot'=0x40005
        p3: 'sequence'=0x252
      row_wait_obj#: 75928, block#: 171, row#: 0, file# 4
      min_blocked_time: 296 secs, waiter_cache_ver: 7860
    Wait State:
      fixed_waits=0 flags=0x22 boundary=(nil)/-1

--54580006 is split into ASCII 54 + ASCII 58 (TX) + Mode 0006 (X) ...

SQL> select object_type,object_name,owner from dba_objects where object_id=75928;  

OBJECT_TYP OBJECT_NAME          OWNER
---------- -------------------- ----------
TABLE      T_XIFENFEI           CHF

--持有锁的信息
      (enqueue) TX-00040005-00000252	DID: 0001-0014-0000009C
      lv: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  res_flag: 0x6
      mode: X, lock_flag: 0x0, lock: 0x343a4c6c, res: 0x353606a8
      own: 0x355ae5b8, sess: 0x355ae5b8, proc: 0x35fe2218, prv: 0x353606b0
--通过上述信息可以分析出结论:
sqlplus登录的sid=15的会话占用了TX mode=6(mode:x)的锁,阻塞了sid=143会话对chf.t_xifenfei表操作

找出被阻塞进程相关信息(sid 为143的进程),搜索”sid: 143″,阅读相关进程信息

PROCESS 21: 
  ----------------------------------------
--相关session信息
 (session) sid: 143 ser: 229 trans: 0x343915a0, creator: 0x35fe2d3c
              flags: (0x41) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
              flags2: (0x40009) -/-/INC
              DID: , short-term DID: 
              txn branch: (nil)
              oct: 7, prv: 0, sql: 0x2f6cb234, psql: 0x2f6dd5cc, user: 0/SYS

--当前等待信息
 Current Wait Stack:
     0: waiting for 'enq: TX - row lock contention'
        name|mode=0x54580006, usn<<16 | slot=0x40005, sequence=0x252
        wait_id=12 seq_num=13 snap_id=1
        wait times: snap=5 min 1 sec, exc=5 min 1 sec, total=5 min 1 sec
        wait times: max=infinite, heur=5 min 1 sec
        wait counts: calls=101 os=101
        in_wait=1 iflags=0x15a0

--阻塞该会话的session信息
    There is at least one session blocking this session.
      Dumping 1 direct blocker(s):
        inst: 1, sid: 15, ser: 151
      Dumping final blocker:
        inst: 1, sid: 15, ser: 151
    Wait State:
      fixed_waits=0 flags=0x22 boundary=(nil)/-1

--请求锁信息
      SO: 0x352f8fcc, type: 8, owner: 0x35765fe8, flag: INIT/-/-/0x00 if: 0x1 c: 0x1
       proc=0x35fe2d3c, name=enqueue, file=ksq1.h LINE:380, pg=0
      (enqueue) TX-00040005-00000252	DID: 0001-0015-0000003B
      lv: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  res_flag: 0x6
      req: X, lock_flag: 0x10, lock: 0x352f8ff8, res: 0x353606a8
      own: 0x356f49b8, sess: 0x356f49b8, proc: 0x35fe2d3c, prv: 0x353606b8
--通过对被阻塞对象分析,可以得出和阻塞者相同的信息

对该问题的常规分析思路

--查询等待事件
SQL> select event,p1,p2,p3 from v$session where wait_class#<>6;

EVENT                                  P1         P2         P3
------------------------------ ---------- ---------- ----------
SQL*Net message to client      1650815232          1          0
enq: TX - row lock contention  1415053318     262149        594

--查询锁信息(因为通过上面的等待事件分析,TX可能引起会话hang)
SQL> SELECT * FROM v$lock where type in ('TM','TX');

ADDR     KADDR           SID TYPE        ID1        ID2      LMODE    REQUEST      CTIME      BLOCK
-------- -------- ---------- ---- ---------- ---------- ---------- ---------- ---------- ----------
352F8FCC 352F8FF8        143 TX       262149        594          0          6       4181          0
B69CC7A8 B69CC7D8        143 TM        75928          0          3          0       4181          0
B69CC7A8 B69CC7D8         15 TM        75928          0          3          0       4266          0
343A4C2C 343A4C6C         15 TX       262149        594          6          0       4267          1

--通过TM查询出来对应对象
SQL>  select object_type,object_name,owner from dba_objects where object_id=75928; 

OBJECT_TYP OBJECT_NAME          OWNER
---------- -------------------- ----------
TABLE      T_XIFENFEI           CHF

--通过观察v$lock查询结果可以知道:
15会话的TX MODE=6的锁阻塞了143会话想会的的TX MODE=6的锁,从而是的143会话hang住

Systemstates分析参考文档:Understanding and Reading Systemstates或者[ID 423153.1]

发表在 Oracle性能优化 | 一条评论

找出 alter system kill session ‘sid,serial#’ kill 掉的数据库会话对应进程

当我们使用alter system kill session ‘sid,serial#’ 在数据库中kill掉某个会话的时候,如果你观察仔细会发现v$session.paddr发生了改变,从而是的不能直接通过关联v$process.add找出spid,然后进行其他操作.本文提供三种方法找该种情况下spid的方法.
数据库版本

SQL> select * from v$version;

BANNER
-----------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - Production
PL/SQL Release 11.2.0.3.0 - Production
CORE    11.2.0.3.0      Production
TNS for Linux: Version 11.2.0.3.0 - Production
NLSRTL Version 11.2.0.3.0 - Production

会话1

SQL> select sid, SERIAL#,paddr from v$session where 
  2  sid=(select sid from v$mystat where rownum=1);

       SID    SERIAL# PADDR
---------- ---------- --------
       133         53 35FE16F4

会话2

SQL> select sid, SERIAL#,paddr from v$session where 
  2  sid=(select sid from v$mystat where rownum=1);

       SID    SERIAL# PADDR
---------- ---------- --------
       143         21 35FE2D3C

会话3

SQL> alter system kill session '133,53';

System altered.

SQL> alter system kill session '143,21';

System altered.

SQL> select sid, SERIAL#,paddr,status from v$session where sid in(133,143);

       SID    SERIAL# PADDR    STATUS
---------- ---------- -------- ----------------
       133         53 3547A3F4 KILLED
       143         21 3547A3F4 KILLED

证明alter system kill session后,v$session中的paddr发生了改变,这个时候如果需要找出原来的spid,不能使用v$session.paddr和v$process.addr关联获得

找出kill掉的spid方法1

SQL> select spid, program from v$process 
  2      where program!= 'PSEUDO' 
  3      and addr not in (select paddr from v$session)
  4      and addr not in (select paddr from v$bgprocess)
  5      and addr not in (select paddr from v$shared_server);

SPID                                             PROGRAM
------------------------------------------------ ------------------------------
14260                                            oracle@xifenfei (L001)
14256                                            oracle@xifenfei (L000)
15300                                            oracle@xifenfei (TNS V1-V3)
14179                                            oracle@xifenfei (D000)
15318                                            oracle@xifenfei (TNS V1-V3)
14252                                            oracle@xifenfei (N000)


SQL> !ps -ef|grep 15300|grep -v grep
oracle   15300 14052  0 03:22 ?        00:00:00 oracleora11g (DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq)))

SQL> !ps -ef|grep 15318|grep -v grep
oracle   15318 15315  0 03:22 ?        00:00:00 oracleora11g (DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq)))

找出kill 掉的spid 方法2

SQL> SELECT s.username,s.status,
  2  x.ADDR,x.KSLLAPSC,x.KSLLAPSN,x.KSLLASPO,x.KSLLID1R,x.KSLLRTYP,
  3  decode(bitand (x.ksuprflg,2),0,null,1)
  4  FROM x$ksupr x,v$session s
  5  WHERE s.paddr(+)=x.addr
  6  and bitand(ksspaflg,1)!=0;

USERNAME   STATUS           ADDR       KSLLAPSC   KSLLAPSN KSLLASPO                   KSLLID1R KSLL DE
---------- ---------------- -------- ---------- ---------- ------------------------ ---------- ---- --
           ACTIVE           35FD5990          6         26 14121                             0      1
           ACTIVE           35FD6FD8          1         69 14055                             0      1
           ACTIVE           35FD8620          1         69 14055                             0      1
           ACTIVE           35FD9C68          1         69 14055                             0      1
           ACTIVE           35FDB2B0          8         27 15300                             0      1
           ACTIVE           35FDC8F8         12         36 15300                             0      1
           ACTIVE           35FDDF40          1         69 14055                             0      1
           ACTIVE           35FDF588          1         69 14055                             0      1
           ACTIVE           35FE3860          7         26 14236                             0      1
           ACTIVE           35FE4EA8          1         69 14224                             0      1
           ACTIVE           35FE64F0         63          2 14311                           377 EV   1
           ACTIVE           35FEA7C8          3         26 14155                           258 EV   1
           ACTIVE           35FE9180         59          2 14248                           378 EV   1
           ACTIVE           35FE9CA4         12          2 14603                             0      1
           ACTIVE           35FD64B4          1         69 14055                             0      1
           ACTIVE           35FD7AFC          2         27 14055                             0      1
           ACTIVE           35FD9144          2         27 15300                             0      1
           ACTIVE           35FDA78C          3         26 14171                             0      1
           ACTIVE           35FDBDD4         17          2 15255                             0      1
           ACTIVE           35FDD41C         22         26 14155                             0      1
           ACTIVE           35FDEA64         52         26 14155                             0      1
           ACTIVE           35FE4384          1         69 14224                             0      1
           ACTIVE           35FE59CC          1         69 14224                             0      1
           ACTIVE           35FEB2EC          2          2 14248                             0      1
           ACTIVE           35FEC934         11         26 14121                             0      1
SYS        ACTIVE           35FEF5C4          4         16 14117                             0
                            35FE0BD0          1         69 14055                             0
                            35FE865C          1         69 14117                             0
                            35FE7B38          1         69 14117                             0
                            35FE16F4          1         26 14155                             0
                            35FD4E6C          0          0                                   0
                            35FE00AC          2        279 14117                             0
                            35FE2D3C          0          0                                   0
                            35FE7014          2        335 14117                             0
--挑选username和status为null的会话

SQL> select spid,program from v$process where addr in (
  2  '35FE0BD0',
  3  '35FE865C',
  4  '35FE7B38',
  5  '35FE16F4',
  6  '35FD4E6C',
  7  '35FE00AC',
  8  '35FE2D3C',
  9  '35FE7014'
 10  );

SPID                                             PROGRAM
------------------------------------------------ ------------------------------
                                                 PSEUDO
14179                                            oracle@xifenfei (D000)
14183                                            oracle@xifenfei (S000)
15300                                            oracle@xifenfei (TNS V1-V3)
15318                                            oracle@xifenfei (TNS V1-V3)
14252                                            oracle@xifenfei (N000)
14256                                            oracle@xifenfei (L000)
14260                                            oracle@xifenfei (L001)

8 rows selected.
--同样可以发现spid 15300和15318的进程已经在数据库中被kill掉

找出kill掉的spid方法3(11g特有)

SQL> select  spid,program  from v$process where addr in
  2  (select creator_addr from v$session where sid in(133,143));

SPID                                             PROGRAM
------------------------------------------------ ------------------------------
15300                                            oracle@xifenfei (TNS V1-V3)
15318                                            oracle@xifenfei (TNS V1-V3)

找出kill掉的spid方法4(11g特有)

SQL> select * from V$DETACHED_SESSION;

      INDX PG_NAME                                                             SID    SERIAL#        PID
---------- ------------------------------------------------------------ ---------- ---------- ----------
         0 DEFAULT                                                             143         21         21
         1 DEFAULT                                                             133         53         19

SQL> select spid,program from v$process where pid in(21,19);

SPID                                             PROGRAM
------------------------------------------------ ------------------------------
15300                                            oracle@xifenfei (TNS V1-V3)
15318                                            oracle@xifenfei (TNS V1-V3)
发表在 Oracle | 一条评论