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

使用ass1045.awk分析library cache lock等待

         最近被个人烦人的问题困扰,下面来看一个使用ass1045.awk分析library cache lock的故障,ASS1045这个版本里面还是新增加了不少的功能,最少我们不需要像原来那么麻烦了。

1ASS1045.AWK格式化systemstate

格式化后的信息如下

[oracle@www.htz.pw sql]$awk -f ass1045.awk  /soft/bnmdb_ora_390.trc

Starting Systemstate 1
..............................................................................
.............................................
Ass.Awk Version 1.0.45
~~~~~~~~~~~~~~~~~~~~~~
Source file : /soft/bnmdb_ora_390.trc

System State 1  (2015-05-07 02:25:36.378)
~~~~~~~~~~~~~~   ~~~~~~~~~~~~~~~~~~~~~~~
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 'DIAG idle wait'       
9: waiting for 'rdbms ipc message'    
10: waiting for 'rdbms ipc message'    
11: waiting for 'rdbms ipc message'    
12: waiting for 'rdbms ipc message'    
13: waiting for 'rdbms ipc message'    
14: waiting for 'rdbms ipc message'    
15: waiting for 'rdbms ipc message'    
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 'rdbms ipc message'    
24:                                    
25:                                    
26: waiting for 'SQL*Net message from client'
27: waiting for 'SQL*Net message from client'
28: waiting for 'Streams AQ: qmn coordinator idle wait'
29: waiting for 'SQL*Net message from client'
30: waiting for 'SQL*Net message from client'
31: waiting for 'SQL*Net message from client'
32: waiting for 'SQL*Net message from client'
33: waiting for 'SQL*Net message from client'
34: waiting for 'SQL*Net message from client'
35: waiting for 'SQL*Net message from client'
36: waiting for 'SQL*Net message from client'
37: waiting for 'SQL*Net message from client'
38: waiting for 'rdbms ipc message'    
39: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
    Final Blocker: inst: 1, sid: 3481, ser: 46803
40: waiting for 'SQL*Net message from client'
41: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
    Final Blocker: inst: 1, sid: 3481, ser: 46803
42:                                    
43: waiting for 'Streams AQ: qmn slave idle wait'
44: waiting for 'SQL*Net message from client'
45: waiting for 'SQL*Net message from client'
46: waiting for 'SQL*Net message from client'
47: waiting for 'SQL*Net message from client'
48: waiting for 'SQL*Net message from client'
49: waiting for 'SQL*Net message from client'
50: waiting for 'SQL*Net message from client'
51:                                    
52: waiting for 'SQL*Net message from client'
53:                                    
54: waiting for 'SQL*Net message from client'
55: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
    Final Blocker: inst: 1, sid: 3481, ser: 46803
56: waiting for 'SQL*Net message from client'
57: waiting for 'SQL*Net message from client'
58:                                    
59: waiting for 'SQL*Net message from client'
60: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
    Final Blocker: inst: 1, sid: 3481, ser: 46803
61: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
    Final Blocker: inst: 1, sid: 3481, ser: 46803
62: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
    Final Blocker: inst: 1, sid: 3481, ser: 46803
63: waiting for 'SQL*Net message from client'
64: waiting for 'SQL*Net message from client'
65: waiting for 'SQL*Net message from client'
66: waiting for 'SQL*Net message from client'
67: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
    Final Blocker: inst: 1, sid: 3481, ser: 46803
68: waiting for 'SQL*Net message from client'
69: waiting for 'SQL*Net message from client'
70: waiting for 'SQL*Net message from client'
71: waiting for 'SQL*Net message from client'
73: waiting for 'Space Manager: slave idle wait'
74: waiting for 'SQL*Net message from client'
75: waiting for 'SQL*Net message from client'
76: waiting for 'SQL*Net message from client'
77: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
    Final Blocker: inst: 1, sid: 3481, ser: 46803
78: waiting for 'SQL*Net message from client'
79: waiting for 'SQL*Net message from client'
80: waiting for 'SQL*Net message from client'
81: waiting for 'SQL*Net message from client'
82: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
    Final Blocker: inst: 1, sid: 3481, ser: 46803
83: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
    Final Blocker: inst: 1, sid: 3481, ser: 46803
84: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
    Final Blocker: inst: 1, sid: 3481, ser: 46803
85: waiting for 'SQL*Net message from client'
86: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
    Final Blocker: inst: 1, sid: 3481, ser: 46803
87: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
    Final Blocker: inst: 1, sid: 3481, ser: 46803
88: waiting for 'SQL*Net message from client'
89: waiting for 'SQL*Net message from client'
90: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
    Final Blocker: inst: 1, sid: 3481, ser: 46803
91: waiting for 'SQL*Net message from client'
92: waiting for 'SQL*Net message from client'
93: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
    Final Blocker: inst: 1, sid: 3481, ser: 46803
94: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
    Final Blocker: inst: 1, sid: 3481, ser: 46803
95: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
    Final Blocker: inst: 1, sid: 3481, ser: 46803
96: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
    Final Blocker: inst: 1, sid: 3481, ser: 46803
97: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
    Final Blocker: inst: 1, sid: 3481, ser: 46803
98: waiting for 'SQL*Net message from client'
99: waiting for 'Space Manager: slave idle wait'
100: waiting for 'db file sequential read' (0x135,0x11989,0x1)
101: waiting for 'SQL*Net message from client'
102: waiting for 'SQL*Net message from client'
103: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
     Final Blocker: inst: 1, sid: 3481, ser: 46803
104: waiting for 'SQL*Net message from client'
105: waiting for 'SQL*Net message from client'
106: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
     Final Blocker: inst: 1, sid: 3481, ser: 46803
108: waiting for 'Space Manager: slave idle wait'
109: waiting for 'Space Manager: slave idle wait'
110:                                    
111: waiting for 'SQL*Net message from client'
112: waiting for 'SQL*Net message from client'
113: waiting for 'db file sequential read' (0xea,0x14c9d,0x1)
118: waiting for 'rdbms ipc message'    
120: waiting for 'Streams AQ: waiting for time management or cleanup tasks'
124: waiting for 'SQL*Net message from client'
125: waiting for 'SQL*Net message from client'
133: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
     Final Blocker: inst: 1, sid: 3481, ser: 46803
140: waiting for 'SQL*Net message from client'
143: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
     Final Blocker: inst: 1, sid: 3481, ser: 46803
149: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
     Final Blocker: inst: 1, sid: 3481, ser: 46803
150: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
     Final Blocker: inst: 1, sid: 3481, ser: 46803
152: waiting for 'SQL*Net message from client'
156: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
     Final Blocker: inst: 1, sid: 3481, ser: 46803
157: waiting for 'library cache lock'   [LOCK: Handle=9abf16648]
     Final Blocker: inst: 1, sid: 3481, ser: 46803
这里我们可以看到阻塞这进程
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://gbr30026.uk.oracle.com:81/Public/TOOLS/Ass.html#enqcnv)

                    Resource Holder State
      LOCK: Handle=9abf16648   113: waiting for 'db file sequential read' (0xea,0x14c9d,0x1)

PID to SID Mapping
~~~~~~~~~~~~~~~~~~
Pid 113 maps to Sid(s): 3481 3485

Object Names
~~~~~~~~~~~~
LOCK: Handle=9abf16648          TABLE(02):HTZ.HTZ_CDHTZ
这里我们看以看到对象的信息

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://gbr30026.uk.oracle.com:81/Public/Utils.html#ass

For additional documentation see
  http://gbr30026.uk.oracle.com:81/Public/TOOLS/Ass.html

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

End of report. 379570 Lines Processed.

通过上面的信息我们得到了阻塞进程与对象。

2,查询阻塞者会话信息

查询会话信息

clip_image001

clip_image002

 ----------------------------------------
    SO: 0x99136ccf8, type: 4, owner: 0x9b0bec3e0, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
     proc=0x9b0bec3e0, name=session, file=ksu.h LINE:12729 ID:, pg=0
    (session) sid: 3481 ser: 46803 trans: 0x0, creator: 0x9b0bec3e0
              flags: (0x10041) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
              flags2: (0x40009) -/-/INC
              DID: , short-term DID:
              txn branch: 0x0                                 执行的SQL信息
              edition#: 100              oct: 3, prv: 0, sql: 0x99b1b1e58, psql: 0x997bd5d90, user: 66/UTOPTEA
    ksuxds FALSE at location: 0
    service name: SYS$USERS
    client details:
      O/S info: user: orabnm, term: UNKNOWN, ospid: 23419
      machine: BAM-DB program: oracle@BAM-DB (J004)
    Current Wait Stack:
     0: waiting for 'db file sequential read'
        file#=0xea, block#=0x14c9d, blocks=0x1
        wait_id=6222760 seq_num=62471 snap_id=1
        wait times: snap=0.006914 sec, exc=0.006914 sec, total=0.006914 sec
        wait times: max=infinite, heur=0.006914 sec
        wait counts: calls=0 os=0
        in_wait=1 iflags=0x5a0

查询SQL信息

clip_image003

clip_image004

 LibraryObjectLock:  Address=9965116c0 Handle=99b1b1e58 Mode=N CanBeBrokenCount=1 Incarnation=1 ExecutionCount=1        

        User=99136ccf8 Session=989381db8 ReferenceCount=1 Flags=CNB/[0001] SavepointNum=554a53d2
      LibraryHandle:  Address=99b1b1e58 Hash=6cdfb52f LockMode=N PinMode=0 LoadLockMode=0 Status=VALD
正在执行的SQL
        ObjectName:  Name=SELECT /* OPT_DYN_SAMP */ /*+ ALL_ROWS IGNORE_WHERE_CLAUSE NO_PARALLEL(SAMPLESUB) opt_param('parallel_execution_enabled', 'false') NO_PARALLEL_INDEX(SAMPLESUB) NO_SQL_TUNE */ NVL(SUM(C1),:"SYS_B_00"), NVL(SUM(C2),:"SYS_B_01"), COUNT(DISTINCT C3), NVL(SUM(CASE WHEN C3 IS NULL THEN :"SYS_B_02" ELSE :"SYS_B_03" END),:"SYS_B_04") FROM (SELECT :"SYS_B_05" AS C1, :"SYS_B_06" AS C2, "PERF"."MO_ID" AS C3 FROM (SELECT /*+ NO_PARALLEL("UTOPTEA"."TF_TT_PERFORMANCE") FULL("UTOPTEA"."TF_TT_PERFORMANCE") NO_PARALLEL_INDE
          FullHashValue=8903ac26967d9972ac7e23566cdfb52f Namespace=SQL AREA(00) Type=CURSOR(00) Identifier=1826600239 OwnerIdn=66
        Statistics:  InvalidationCount=0 ExecutionCount=13 LoadCount=3 ActiveLocks=2 TotalLockCount=12 TotalPinCount=1
        Counters:  BrokenCount=1 RevocablePointer=1 KeepDependency=2 Version=0 BucketInUse=1 HandleInUse=1 HandleReferenceCount=0
        Concurrency:  DependencyMutex=99b1b1f08(0, 41, 0, 0) Mutex=99b1b1f98(0, 2469, 0, 0)
        Flags=RON/PIN/TIM/PN0/DBN/[10012841]
        WaitersLists: 
          Lock=99b1b1ee8[99b1b1ee8,99b1b1ee8]
          Pin=99b1b1ec8[99b1b1ec8,99b1b1ec8]
          LoadLock=99b1b1f40[99b1b1f40,99b1b1f40]
        Timestamp:  Current=05-05-2015 13:01:21
        HandleReference:  Address=99b1b2378 Handle=0 Flags=[00]
        LibraryObject:  Address=943040080 HeapMask=0000-0001-0001-0000 Flags=EXS[0000] Flags2=[0000] PublicFlags=[0000]
          ChildTable:  size='16'
            Child:  id='0' Table=943040f30 Reference=943040968 Handle=99b174bb8
            Child:  id='1' Table=943040f30 Reference=8cd2128b8 Handle=999d06258
        NamespaceDump: 
          Parent Cursor:  sql_id=aszj3atqdzd9g parent=943040120 maxchild=2 plk=y ppn=n
            CursorDiagnosticsNodes:  不共享的原因
              ChildNode:  ChildNumber=0 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_dynamic_sampling= 2

其它的东西就在慢慢查找了。

本文固定链接: http://www.htz.pw/2015/05/08/%e4%bd%bf%e7%94%a8ass1045-awk%e5%88%86%e6%9e%90library-cache-lock%e7%ad%89%e5%be%85.html | 认真就输

该日志由 huangtingzhong 于2015年05月08日发表在 EVENT, systemstate 分类下, 通告目前不可用,你可以至底部留下评论。
原创文章转载请注明: 使用ass1045.awk分析library cache lock等待 | 认真就输
关键字: