当前位置: 首页 > systemstate > 正文

systemstate分析row cache lock

下面是一次测试row cache locksystemstate分析方法,平台为11.2.04

欢迎大家加入ORACLE超级群:17115662 免费解决各种ORACLE问题,以后BLOG将迁移到http://www.htz.pw

 

1,使用ass来格式化systemstate

[oracle@11rac1 sql]$ awk -f ass1039.awk /u01/app/oracle/diag/rdbms/power/power1/trace/power1_ora_14290.trc

 

Starting Systemstate 1

………………………………………………

Ass.Awk Version 1.0.39

~~~~~~~~~~~~~~~~~~~~~~

Source file : /u01/app/oracle/diag/rdbms/power/power1/trace/power1_ora_14290.trc

 

System State 1  (2014-07-16 15:14:42.518)

~~~~~~~~~~~~~~   ~~~~~~~~~~~~~~~~~~~~~~~

1:                                      [DEAD]

2:  waiting for ‘pmon timer’           

3:  waiting for ‘rdbms ipc message’    

4:  waiting for ‘VKTM Logical Idle Wait’

5:  waiting for ‘rdbms ipc message’    

6:  waiting for ‘DIAG idle wait’       

7:  waiting for ‘rdbms ipc message’    

8:  waiting for ‘PING’                 

9:  waiting for ‘rdbms ipc message’    

10: waiting for ‘DIAG idle wait’       

11: waiting for ‘rdbms ipc message’    

12: waiting for ‘ges remote message’   

13: waiting for ‘gcs remote message’   

14: waiting for ‘rdbms ipc message’    

15: waiting for ‘GCR sleep’            

16: waiting for ‘rdbms ipc message’    

17: waiting for ‘rdbms ipc message’    

18: waiting for ‘rdbms ipc message’    

19: waiting for ‘rdbms ipc message’    

20: waiting for ‘smon timer’           

21: waiting for ‘rdbms ipc message’    

22: waiting for ‘rdbms ipc message’    

23: waiting for ‘ASM background timer’ 

24: waiting for ‘rdbms ipc message’    

25: waiting for ‘rdbms ipc message’    

26:                                    

27: waiting for ‘wait for unread message on broadcast channel’

28:                                    

29: waiting for ‘rdbms ipc message’    

30: waiting for ‘rdbms ipc message’    

31: waiting for ‘rdbms ipc message’    

32: waiting for ‘SQL*Net message from client’

33: waiting for ‘Space Manager: slave idle wait’

34: waiting for ‘rdbms ipc message’    

35: waiting for ‘rdbms ipc message’    

36: waiting for ‘rdbms ipc message’    

37: waiting for ‘rdbms ipc message’    

38: waiting for ‘SQL*Net message from client’

39: waiting for ‘rdbms ipc message’    

40: waiting for ‘Space Manager: slave idle wait’

41: waiting for ‘wait for unread message on broadcast channel’

42: waiting for ‘Streams AQ: qmn coordinator idle wait’

43: waiting for ‘SQL*Net message from client’

     Cmd: PL/SQL Execute

44: waiting for ‘SQL*Net message from client’

45: waiting for ‘Streams AQ: qmn slave idle wait’

46: waiting for ‘Streams AQ: waiting for time management or cleanup tasks’

47: waiting for ‘SQL*Net message from client’

     Cmd: Select

48: waiting for ‘rdbms ipc message’    

49: waiting for ‘enq: TX – row lock contention'[Enq TX-00010008-00000629]

     Cmd: Select

50: waiting for ‘row cache lock’       [Rcache object=0x8f0a1990,]

     Cmd: Select

51: waiting for ‘SQL*Net message from client’

52:                                    

53:                                    

58: waiting for ‘class slave wait’     

 

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. (The holder may have released the resource before we

           dumped the state object tree of the blocking process).

         o Lines with ‘Enqueue conversion’ below can be ignored *unless*

           other sessions are waiting on that resource too. For more, see

           http://dlsunuk11.uk.oracle.com/Public/TOOLS/Ass.html#enqcnv)

 

                    Resource Holder State

    Enq TX-00010008-00000629    47: waiting for ‘SQL*Net message from client’

   Rcache object=0x8f0a1990,    49: 49: is waiting for 47:

 

Object Names

~~~~~~~~~~~~

Enq TX-00010008-00000629                                     

Rcache object=0x8f0a1990,       cid=13(dc_sequences)         

 

Summary of Wait Events Seen (count>10)

~~~~~~~~~~~~~~~~~~~~~~~~~~~

  No wait events seen more than 10 times

 

                   ——————ooOoo——————

For the LATEST version of this utility see

  http://dlsunuk11.uk.oracle.com/Public/Utils.html#ass

 

For additional documentation see

  http://dlsunuk11.uk.oracle.com/Public/TOOLS/Ass.html

 

Suggested improvements, bugs etc. should be sent to kevin.p.quinn@oracle.com

 

End of report. 60404 Lines Processed.

 

 

 

[oracle@11rac2 sql]$ awk -f ass1039.awk /u01/app/oracle/diag/rdbms/power/power2/trace/power2_ora_9758.trc

 

Starting Systemstate 1

……………………………………………

Ass.Awk Version 1.0.39

~~~~~~~~~~~~~~~~~~~~~~

Source file : /u01/app/oracle/diag/rdbms/power/power2/trace/power2_ora_9758.trc

 

System State 1  (2014-07-16 15:15:33.423)

~~~~~~~~~~~~~~   ~~~~~~~~~~~~~~~~~~~~~~~

1:                                      [DEAD]

2:  waiting for ‘pmon timer’           

3:  waiting for ‘rdbms ipc message’    

4:  waiting for ‘VKTM Logical Idle Wait’

5:  waiting for ‘rdbms ipc message’    

6:  waiting for ‘DIAG idle wait’       

7:  waiting for ‘rdbms ipc message’    

8:  waiting for ‘PING’                 

9:  waiting for ‘rdbms ipc message’    

10: waiting for ‘DIAG idle wait’       

11: waiting for ‘rdbms ipc message’    

12: waiting for ‘ges remote message’   

13: waiting for ‘gcs remote message’   

14: waiting for ‘rdbms ipc message’    

15: waiting for ‘GCR sleep’            

16: waiting for ‘rdbms ipc message’    

17: waiting for ‘rdbms ipc message’    

18: waiting for ‘rdbms ipc message’    

19: waiting for ‘rdbms ipc message’    

20: waiting for ‘smon timer’           

21: waiting for ‘rdbms ipc message’    

22: waiting for ‘rdbms ipc message’    

23: waiting for ‘ASM background timer’ 

24: waiting for ‘rdbms ipc message’    

25: waiting for ‘rdbms ipc message’    

26: waiting for ‘wait for unread message on broadcast channel’

27:                                    

28:                                    

29: waiting for ‘rdbms ipc message’    

30: waiting for ‘rdbms ipc message’    

31: waiting for ‘rdbms ipc message’    

32: waiting for ‘SQL*Net message from client’

33: waiting for ‘Space Manager: slave idle wait’

34: waiting for ‘class slave wait’     

35: waiting for ‘rdbms ipc message’    

36: waiting for ‘rdbms ipc message’    

37: waiting for ‘rdbms ipc message’    

38: waiting for ‘rdbms ipc message’    

39: waiting for ‘rdbms ipc message’    

40: waiting for ‘wait for unread message on broadcast channel’

41: waiting for ‘class slave wait’     

42: waiting for ‘Streams AQ: qmn coordinator idle wait’

43:                                    

44: waiting for ‘SQL*Net message from client’

45: waiting for ‘Streams AQ: qmn slave idle wait’

46: waiting for ‘row cache lock’       [Rcache object=0x8e9a5120,]

     Cmd: Select

47:                                    

48: waiting for ‘rdbms ipc message’    

49: waiting for ‘Space Manager: slave idle wait’

50: waiting for ‘Space Manager: slave idle wait’

51:                                    

 

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. (The holder may have released the resource before we

           dumped the state object tree of the blocking process).

         o Lines with ‘Enqueue conversion’ below can be ignored *unless*

           other sessions are waiting on that resource too. For more, see

           http://dlsunuk11.uk.oracle.com/Public/TOOLS/Ass.html#enqcnv)

 

                    Resource Holder State

   Rcache object=0x8e9a5120,    ??? Blocker

 

Object Names

~~~~~~~~~~~~

Rcache object=0x8e9a5120,       cid=13(dc_sequences)         

 

Summary of Wait Events Seen (count>10)

~~~~~~~~~~~~~~~~~~~~~~~~~~~

  No wait events seen more than 10 times

 

                   ——————ooOoo——————

For the LATEST version of this utility see

  http://dlsunuk11.uk.oracle.com/Public/Utils.html#ass

 

For additional documentation see

  http://dlsunuk11.uk.oracle.com/Public/TOOLS/Ass.html

 

Suggested improvements, bugs etc. should be sent to kevin.p.quinn@oracle.com

 

End of report. 43873 Lines Processed.

   Rcache object=0x8e9a5120,    ??? Blocker这里节点2没有发现阻塞者,说明阻塞者不在2节点,在1节点

2,找到row cache locksession

row cache lock等待事件来搜索会话的等待情况,如果没有使用ass格式化的情况下,一般我们都是这样来和

    —————————————-

    SO: 0x9b513658, type: 4, owner: 0x9ce441f0, flag: INIT/-/-/0x00 if: 0x3 c: 0x3

     proc=0x9ce441f0, name=session, file=ksu.h LINE:12624, pg=0

    (session) sid: 52 ser: 15 trans: 0x9515a1f0, creator: 0x9ce441f0

              flags: (0x41) USR/- flags_idl: (0x1) BSY/-/-/-/-/-

              flags2: (0x40009) -/-/INC

              DID: , short-term DID:

              txn branch: (nil)

              oct: 3, prv: 0, sql: 0x8e954a20, psql: 0x8f50cfd0, user: 0/SYS

    ksuxds FALSE at location: 0

    service name: SYS$USERS

    client details:

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

      machine: 11rac2 program: sqlplus@11rac2 (TNS V1-V3)

      application name: sqlplus@11rac2 (TNS V1-V3), hash value=3270042948

    Current Wait Stack:

     0: waiting for ‘row cache lock’

        cache id=0xd, mode=0x0, request=0x5

        wait_id=6656 seq_num=6657 snap_id=1

        wait times: snap=0.001217 sec, exc=0.001217 sec, total=0.001217 sec

        wait times: max=3.000000 sec, heur=3 min 6 sec

        wait counts: calls=1 os=1

        in_wait=1 iflags=0x5a2

找到row cache enqueue的信息,

这里我们可以看到最终的BLOCKERinst:1,sid:793

这里需要记录一下行号

row cache enqueue*request来搜索,找到离刚开始最近的一行记录

37769         row cache enqueue: count=1 session=0x9b513658 object=0x8e9a5120, request=X

其实我们还可以下面的方式来搜索

type: 75, owner: 0x9515a1f0来搜索,因为我们知道,row cache enqueuetype75,并且owner是属于processsessionowner是一致的。

其中还可以以row cache enqueue*session*9b513658来搜索

        SO: 0x8e990c40, type: 75, owner: 0x9515a1f0, flag: INIT/-/-/0x00 if: 0x1 c: 0x1

         proc=0x9ce441f0, name=row cache enqueues, file=kqr.h LINE:2064, pg=0

        row cache enqueue: count=1 session=0x9b513658 object=0x8e9a5120, request=X

        savepoint=0x46

        row cache parent object: address=0x8e9a5120 cid=13(dc_sequences)

        hash=152264bc typ=11 transaction=(nil) flags=00000000

        own=0x8e9a51e8[0x8e9a51e8,0x8e9a51e8] wat=0x8e9a51f8[0x8e990ce8,0x8e990ce8] mode=N

        status=-/-/-/-/-/-/-/-/-

        request=X release=FALSE flags=a

        instance lock=QN 152264bc 374026d7

        data=

        00012a05 00000000 00000000 00000000 00000000 00000000 00000000 00000000

        00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000

        00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000

        00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000

        00000000 00000000 00000000 00000000 00000000 152264bc 8e9a5120 00000000

        947397a8 00000000 947397a8 00000000 00000005 00000000 26784f80 00007f3c

        00000000 00000000 00000000 00000000 8e9a5120 00000000 8e9a52f0 00000000

        8e9a52f0 00000000 8e9a5318 00000000 0000000a 152264bc 374026d7 00000000

        00000101 00000000 0000011d 00000000 99dd8510 00000000 9ce336f0 00000000

        8f4eb538 00000000 98c04f78 00000000 00000000 00000000 00000000 00000000

        00000000 00000000 00000000 00000000 00000000 00000000 99f79978 00000000

        00000001 0000009a 00050001 08910321 8e9a5388 00000000 8e9a5388 00000000

        0730efec 00000000 26784fa0 00007f3c 99f799d0 00000000 99f799d0 00000000

        00000000 00000000 00000000 00000000 00000000 00000000 99dd8510 00000000

        98c05018 00000000 8f4eb5d8 00000000 9b554ec8 00000000 00000000 00000002

        8e9a53f8 00000000 8e9a53f8 00000000 00000000 00000000 00000000 00000000

        8e9a5418 00000000 8e9a5418 00000000 8e9a5428 00000000 8e9a5428 00000000

        99dca9b8 00000000 99dca9b8 00000000 00000000 00004fe7 26784f88 00007f3c

        00000000 00000000 00000000 00000000 8e9a5468 00000000 8e9a5468 00000000

        00000000 00000000 00000000 00000000 feb172d0 00007fff 10600160 09000200

        00000000 00000000 06c25c14 00000000 26784fa0 00007f3c 00000000 00000000

        f251fa11 00000002 00000000 00000000 8e9a51e8 00000000

kssdmh:  so 0x8e990c40 (type 75, "row cache enqueues") may not have children

红色的部分就是row cache enqueue的信息

instance lock=QN 152264bc 374026d7这里是全局锁的信息,如果在本地没有找到阻塞者的时候,我们就要以这个在其它的节点找到。

3,搜索阻塞者

row cache enqueue*object*8e9a5120来搜索

2节点没有搜索到阻塞者,回到1节点的trace文件搜索

那么我们只能以instance lock=QN 152264bc 374026d7来搜索

这里可以得到下面的2行,分别进入相应的行,找到MODE

54281         instance lock=QN 152264bc 374026d7

54922         instance lock=QN 152264bc 374026d7

得到moderow cache enqueue的信息

        —————————————-

        SO: 0x8e5c2150, type: 75, owner: 0x951b5128, flag: INIT/-/-/0x00 if: 0x1 c: 0x1

         proc=0x9cde1780, name=row cache enqueues, file=kqr.h LINE:2064, pg=0

        row cache enqueue: count=1 session=0x9b4728e8 object=0x8f0a1990, mode=X

        savepoint=0x29

        row cache parent object: address=0x8f0a1990 cid=13(dc_sequences)

        hash=152264bc typ=11 transaction=0x951b5128 flags=0000012a

        own=0x8f0a1a58[0x8e5c21f8,0x8e5c21f8] wat=0x8f0a1a68[0x8e5d5e58,0x8e5d5e58] mode=X

        status=VALID/UPDATE/-/-/IO/-/-/-/-

        request=N release=TRUE flags=8

        instance lock=QN 152264bc 374026d7

        data=

        00012a05 0002000c 000f0002 00020001 000002c1 00000000 00000000 00000000

        02c10000 00000000 00000000 00000000 00000000 646464ce 64646464 64646464

        00646464 00800000 00000000 00000000 00000000 00000000 000003c1 00000000

        00000000 00000000 2d2d0000 2d2d2d2d 2d2d2d2d 2d2d2d2d 2d2d2d2d 2d2d2d2d

        2d2d2d2d 2d2d2d2d 2d2d2d2d 2d2d2d2d 00000000 152264bc 8f0a1990 00000000

        947397a8 00000000 947397a8 00000000 00000000 00000000 2d95f900 00007f5f

        00000001 00000000 00000000 00000000 8f0a1990 00000000 8f0a1b60 00000000

        8f0a1b60 00000000 8f0a1b88 00000000 00000008 152264bc 374026d7 00000000

        00000101 00000000 0000011d 00000000 99cd8068 00000000 9cdcda70 00000000

        8e4f6420 00000000 8e5b8288 00000000 00000000 00000000 00000000 00000000

        00000000 00000000 00000000 00000000 00000000 00000000 999b9938 00000000

        00000001 00095556 00050520 08910321 8f0a1bf8 00000000 8f0a1bf8 00000000

        00000000 00000000 2d95f920 00007f5f 999b9980 00000000 999b9980 00000000

        06c25c14 00000000 00000000 00000000 2d95f920 00007f5f 99cd8068 00000000

        8e5b8328 00000000 8e4f64c0 00000000 9c337718 00000000 00000000 00000002

        8f0a1c68 00000000 8f0a1c68 00000000 00000000 00000000 00000000 00000000

        8f0a1c88 00000000 8f0a1c88 00000000 8f0a1c98 00000000 8f0a1c98 00000000

        8f0a1ca8 00000000 8f0a1ca8 00000000 00000000 00000000 2d95f908 00007f5f

        00000000 00000000 00000000 00000000 8f0a1cd8 00000000 8f0a1cd8 00000000

        00000000 00000000 00000000 00000000 5e2f04e8 00007fff 10600160 00000100

        03000001 00000000 00000000 00000000 00000000 00000000 00000000 00000000

        00000000 00000001 00000108 00000000 8f0a1a58 00000000

kssdmh:  so 0x8e5c2150 (type 75, "row cache enqueues") may not have children

9b4728e8*type: 4来搜索会话的信息,可以看到会话正在等待TX的等待事件

    —————————————-

    SO: 0x9b4728e8, type: 4, owner: 0x9cde1780, flag: INIT/-/-/0x00 if: 0x3 c: 0x3

     proc=0x9cde1780, name=session, file=ksu.h LINE:12624, pg=0

    (session) sid: 795 ser: 15 trans: 0x951b5128, creator: 0x9cde1780

              flags: (0x41) USR/- flags_idl: (0x1) BSY/-/-/-/-/-

              flags2: (0x9) -/-/INC

              DID: , short-term DID:

              txn branch: (nil)

              oct: 3, prv: 0, sql: 0x8e4f5860, psql: 0x8f112090, user: 0/SYS

    ksuxds FALSE at location: 0

    service name: SYS$USERS

    client details:

      O/S info: user: oracle, term: pts/1, ospid: 6441

      machine: 11rac1 program: sqlplus@11rac1 (TNS V1-V3)

      application name: sqlplus@11rac1 (TNS V1-V3), hash value=985707405

    Current Wait Stack:

     0: waiting for ‘enq: TX – row lock contention

关于enq的等待,见enqueue

本文固定链接: http://www.htz.pw/2014/07/16/systemstate%e5%88%86%e6%9e%90row-cache-lock.html | 认真就输

该日志由 huangtingzhong 于2014年07月16日发表在 systemstate 分类下, 你可以发表评论,并在保留原文地址及作者的情况下引用到你的网站或博客。
原创文章转载请注明: systemstate分析row cache lock | 认真就输
关键字: , ,