使用ass1045.awk分析library cache lock等待
May082015
最近被个人烦人的问题困扰,下面来看一个使用ass1045.awk分析library cache lock的故障,ASS在1045这个版本里面还是新增加了不少的功能,最少我们不需要像原来那么麻烦了。
1,ASS1045.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,查询阻塞者会话信息 |
查询会话信息
---------------------------------------- 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信息
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/?p=970 | 认真就输
非常感谢博主的分享,不知博主可以共享一下ass1045.awk脚本,499582627@qq.com,谢谢