{"id":473,"date":"2008-12-10T18:21:31","date_gmt":"2008-12-10T16:21:31","guid":{"rendered":"http:\/\/www.ora-solutions.net\/web\/?p=473"},"modified":"2012-09-22T10:36:33","modified_gmt":"2012-09-22T08:36:33","slug":"system-state-dump-evaluation-with-assawk","status":"publish","type":"post","link":"https:\/\/www.ora-solutions.net\/web\/2008\/12\/10\/system-state-dump-evaluation-with-assawk\/","title":{"rendered":"System State Dump Evaluation with ass.awk"},"content":{"rendered":"<p>I have found out that there is an Oracle Support utility called ass.awk, which can be used to analyze and format a System State dump. It is contained in LTOM, which can be downloaded from MetaLink.<\/p>\n<p>The AWK script is called ass109.awk and can be used in this manner:<\/p>\n<pre lang=\"SQL\">[oracle@ora-vm1 ~]$ awk -f ass109.awk mddb1_diag_12345.trc\r\n\r\nSystem State ASS:\r\nStarting Systemstate 1\r\n..............................................................................\r\n.....\r\nAss.Awk Version 1.0.9 - Processing mddb1_diag_12345.trc\r\nSystem State 1\r\n~~~~~~~~~~~~~~~~\r\n1:\r\n2: waiting for 'pmon timer' wait\r\n3: last wait for 'ksdxexeotherwait'\r\n4: waiting for 'rdbms ipc message' wait\r\n5: waiting for 'rdbms ipc message' wait\r\n6: waiting for 'ges remote message' wait\r\n7: waiting for 'gcs log flush sync' wait\r\n8: waiting for 'gcs log flush sync' wait\r\n9: waiting for 'rdbms ipc message' wait\r\n10: waiting for 'rdbms ipc message' wait\r\n11: waiting for 'enq: CF - contention' [Enqueue CF-00000000-00000000] wait\r\n12: waiting for 'rdbms ipc message' wait\r\n13: waiting for 'buffer busy waits' (2,a9,3b) wait\r\n14: waiting for 'rdbms ipc message' wait\r\n15: waiting for 'rdbms ipc message' wait\r\n16: waiting for 'buffer busy waits' (2,a9,3b) wait\r\n17: waiting for 'rdbms ipc message' wait\r\n18:\r\n19:\r\n20: waiting for 'rdbms ipc message' wait\r\n21: waiting for 'log file sync' wait\r\n22: waiting for 'ASM background timer' wait\r\n23: waiting for 'rdbms ipc message' wait\r\n24: waiting for 'log file sync' wait\r\n25: waiting for 'class slave wait' wait\r\n26: waiting for 'SQL*Net message from client' wait\r\n27: waiting for 'SQL*Net message from client' wait\r\n28: waiting for 'enq: CF - contention' [Enqueue CF-00000000-00000000] wait\r\n29: waiting for 'enq: CF - contention' [Enqueue CF-00000000-00000000] wait\r\n30: waiting for 'Streams AQ: qmn coordinator idle wait' wait\r\n31: waiting for 'SQL*Net message from client' wait\r\n32: waiting for 'SQL*Net message from client' wait\r\nCmd: Select\r\n33: waiting for 'log file sync' wait\r\n34: waiting for 'Streams AQ: qmn slave idle wait' wait\r\n35: for 'Streams AQ: waiting for time management or cleanup tasks' wait\r\n36: waiting for 'log file sync' wait\r\n37: waiting for 'SQL*Net message from client' wait\r\nCmd: Select\r\n38: waiting for 'SQL*Net message from client' wait\r\n39: waiting for 'SQL*Net message from client' wait\r\n40: waiting for 'PX Deq: Execution Msg' wait\r\n41: waiting for 'log file sync' wait\r\n42: waiting for 'log file sync' wait\r\n43: waiting for 'enq: CF - contention' [Enqueue CF-00000000-00000000] wait\r\nCmd: Select\r\n44: waiting for 'SQL*Net message from client' wait\r\n45: waiting for 'SQL*Net message from client' wait\r\n46: waiting for 'SQL*Net message from client' wait\r\n47: waiting for 'SQL*Net message from client' wait\r\n48: waiting for 'SQL*Net message from client' wait\r\n49: waiting for 'log file sync' wait\r\n50: waiting for 'SQL*Net message from client' wait\r\n51: waiting for 'SQL*Net message from client' wait\r\nCmd: Select\r\n52: waiting for 'row cache lock' [Rcache object=0xa5414098,] wait\r\nCmd: Select\r\n53: waiting for 'SQL*Net message from client' wait\r\n54: waiting for 'SQL*Net message from client' wait\r\n55: for 'Streams AQ: waiting for messages in the queue' wait\r\n56: waiting for 'SQL*Net message from client' wait\r\n57: waiting for 'SQL*Net message from client' wait\r\n58: waiting for 'log file sync' wait\r\nCmd: Insert\r\n59: waiting for 'jobq slave wait' wait\r\n60: waiting for 'jobq slave wait' wait\r\n61: waiting for 'SQL*Net message from client' wait\r\n62: waiting for 'SQL*Net message from client' wait\r\n63: waiting for 'SQL*Net message from client' wait\r\n65: waiting for 'SQL*Net message from client' wait\r\nCmd: Select\r\n66: waiting for 'SQL*Net message from client' wait\r\n67: last wait for 'SQL*Net message from client'\r\n68: waiting for 'SQL*Net message from client' wait\r\n69: waiting for 'SQL*Net message from client' wait\r\n70: waiting for 'SQL*Net message from client' wait\r\n71: waiting for 'SQL*Net message from client' wait\r\n72: waiting for 'SQL*Net message from client' wait\r\n73: waiting for 'SQL*Net message from client' wait\r\n74: waiting for 'SQL*Net message from client' wait\r\nCmd: Select\r\n75: waiting for 'SQL*Net message from client' wait\r\nCmd: Select\r\n76: waiting for 'SQL*Net message from client' wait\r\n77: waiting for 'log file sync' wait\r\n78: waiting for 'SQL*Net message from client' wait\r\n80: waiting for 'SQL*Net message from client' wait\r\nCmd: Select\r\n82: waiting for 'SQL*Net message from client' wait\r\n84: waiting for 'log file sync' wait\r\n86: waiting for 'SQL*Net message from client' wait\r\n93: waiting for 'SQL*Net message from client' wait\r\n94: waiting for 'SQL*Net message from client' wait\r\nBlockers\r\n~~~~~~~~\r\nAbove is a list of all the processes. If they are waiting for a resource\r\nthen it will be given in square brackets. Below is a summary of the\r\nwaited upon resources, together with the holder of that resource.\r\nNotes:\r\n~~~~~\r\no A process id of '???' implies that the holder was not found in the\r\nsystemstate.\r\nResource Holder State\r\nEnqueue CF-00000000-00000000 12: waiting for 'rdbms ipc message'\r\nRcache object=0xa5414098, ??? Blocker\r\nObject Names\r\n~~~~~~~~~~~~\r\nEnqueue CF-00000000-00000000\r\nRcache object=0xa5414098,\r\n<\/pre>\n<p>With this information, you can investigate further into the System state dump by looking at rcache object 0xa5414098. The &#8220;State Objects&#8221; are a hierarchical structure. Every state object has an adress &#8220;SO: 0xa6a5955c&#8221; and an owner, which is the parent entry. In this case, you can construct a hierarchical tree of state objects and find dependencies. <\/p>\n<pre lang=\"SQL\"> SO: 0xa6a5995c, type: 2, owner: (nil), flag: INIT\/-\/-\/0x00\r\n (process) Oracle pid=52, calls cur\/top: 0x9d62eb1c\/0x9d5ccfcc, flag: (0) -\r\n\t\t   int error: 0, call error: 0, sess error: 0, txn error 0\r\n (post info) last post received: 0 0 163\r\n\t\t\t last post received-location: kqrbtm\r\n\t\t\t last process to post me: a6a4e1dc 1 6\r\n\t\t\t last post sent: 0 0 24\r\n\t\t\t last post sent-location: ksasnd\r\n\t\t\t last process posted by me: a6a4e1dc 1 6\r\n   (latch info) wait_event=0 bits=0\r\n\tProcess Group: DEFAULT, pseudo proc: 0xa6baf79c\r\n\tO\/S info: user: oracle, term: UNKNOWN, ospid: 29032\r\n    OSD pid info: Unix process pid: 29032, image: oracle@ora-vm1\r\n    Short stack dump: ksdxfstk()+19<-ksdxcb()+1321<-sspuser()+102<-__kernel_vsyscall()+16\r\n\r\n    SO: 0xa4123d20, type: 4, owner: 0xa6a5995c, flag: INIT\/-\/-\/0x00\r\n    (session) sid: 955 trans: (nil), creator: 0xa6a5995c, flag: (41) USR\/- BSY\/-\/-\/-\/-\/-\r\n              DID: 0001-0034-00002227, short-term DID: 0001-0034-00002228\r\n              txn branch: (nil)\r\n              oct: 3, prv: 0, sql: 0x8fee9d44, psql: 0x8fee9f00, user: 23\/DBSNMP\r\n     service name: SYS$USERS\r\n     O\/S info: user: oracle, term: , ospid: 28849, machine: ora-vm1\r\n               program: emagent@ora-vm1(TNS V1-V3)\r\n     application name: emagent@ora-vm1(TNS V1-V3), hash value=2420928497\r\n     waiting for 'row cache lock' blocking sess=0x(nil) seq=127 wait_time=0 seconds since wait started=0\r\n                 cache id=d, mode=0, request=5\r\n     Dumping Session Wait History\r\n      for 'row cache lock' count=1 wait_time=1337230\r\n\t\t         cache id=d, mode=0, request=5\r\n      for 'row cache lock' count=1 wait_time=2930561\r\n                 cache id=d, mode=0, request=5\r\n      for 'row cache lock' count=1 wait_time=2929106\r\n                 cache id=d, mode=0, request=5\r\n      for 'row cache lock' count=1 wait_time=2933326\r\n\r\n      SO: 0x9d5ccfcc, type: 3, owner: 0xa6a5995c, flag: INIT\/-\/-\/0x00\r\n     (call) sess: cur a4123d20, rec a4123d20, usr a4123d20; depth: 0\r\n       ----------------------------------------\r\n       SO: 0x9d51b1a0, type: 3, owner: 0x9d5ccfcc, flag: INIT\/-\/-\/0x00\r\n       (call) sess: cur a4123d20, rec a417f990, usr a4123d20; depth: 1\r\n         ----------------------------------------\r\n         SO: 0x9d69d7f0, type: 3, owner: 0x9d51b1a0, flag: INIT\/-\/-\/0x00\r\n         (call) sess: cur a417f990, rec a417f990, usr a4123d20; depth: 2\r\n         ----------------------------------------\r\n           SO: 0x9d5e547c, type: 3, owner: 0x9d69d7f0, flag: INIT\/-\/-\/0x00\r\n           (call) sess: cur a417f990, rec a417f990, usr a4123d20; depth: 3\r\n           ----------------------------------------\r\n             SO: 0x9d62eb1c, type: 3, owner: 0x9d5e547c, flag: INIT\/-\/-\/0x00\r\n             (call) sess: cur a417f990, rec a417f990, usr a4123d20; depth: 4\r\n             ----------------------------------------\r\n               SO: 0x9fedf748, type: 40, owner: 0x9d62eb1c, flag: INIT\/-\/-\/0x00\r\n               (trans) flg = 0x21, flg2 = 0x80000, prx = 0x0, ros = 2147483647 bsn = 0x395 bndsn = 0x395 spn = 0x395\r\n               efd = 34\r\n               parent xid: 0x0000.000.00000000\r\n               env: (scn: 0x0000.00000000 xid: 0x0000.000.00000000 uba: 0x00000000.0000.00 statement num=0 parent xid: xid:\r\n               0x0000.000.00000000 scn: 0x0000.00000000 0sch: scn: 0x0000.00000000)\r\n               cev: (spc = 0 arsp = 0 ubk tsn: 0 rdba: 0x00000000 useg tsn: 0 rdba: 0x00000000\r\n                     hwm uba: 0x00000000.0000.00 col uba: 0x00000000.0000.00\r\n                     num bl: 0 bk list: 0x0)\r\n                     cr opc: 0x0 spc: 0 uba: 0x00000000.0000.00\r\n               (enqueue) TX-00010011-00D3B4CF DID: 0001-0051-00001323\r\n               lv: 7c ac ad 4d 03 00 00 00 00 00 00 00 00 00 00 00 res_flag: 0x45\r\n               res: 0xa447bb2c, lock_flag: 0x0\r\n               own: 0xa4157e90, sess: 0xa4157e90, prv: 0x9fedf774\r\n               slk: (nil)\r\n                xga: 0x0, heap: UGA\r\n               Trans IMU st: 0 Pool index 65535, Redo pool 0x9fedfb74, Undo pool 0x9fedfbf0\r\n               Redo pool range [0x40ed57e8 0x40ed57e8 0x40ed7fe8]\r\n               Undo pool range [0x40ed2fe8 0x40ed2fe8 0x40ed57e8]\r\n               ----------------------------------------\r\n                  SO: 0x9d42237c, type: 50, owner: 0x9fedf748, flag: INIT\/-\/-\/0x00\r\n                  row cache enqueue: count=1 session=0xa4123d20 object=0xa5414098, request=X\r\n                  savepoint=0x395\r\n                  row cache parent object: address=0xa5414098 cid=13(dc_sequences)\r\n                  hash=9649e7e typ=9 transaction=(nil) flags=00000000\r\n                  own=0xa5414104[0xa5414104,0xa5414104] wat=0xa541410c[0x9d422398,0x9d422398] mode=N\r\n                  status=-\/-\/-\/-\/-\/-\/-\/-\/-\r\n                  request=X release=FALSE flags=2\r\n                  instance lock id=QN 010cdbb3 b3b24847\r\n<\/pre>\n<p>Tanel Poder showed in his seminar to use \"grep -A 3 SO:\" to find all lines containing the State Object Adresses and the following 3 lines to get the tree.<\/p>\n","protected":false},"excerpt":{"rendered":"<p>I have found out that there is an Oracle Support utility called ass.awk, which can be used to analyze and format a System State dump. It is contained in LTOM, which can be downloaded from MetaLink. The AWK script is called ass109.awk and can be used in this manner: [oracle@ora-vm1 ~]$ awk -f ass109.awk mddb1_diag_12345.trc [&hellip;]<\/p>\n","protected":false},"author":2,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"_monsterinsights_skip_tracking":false,"_monsterinsights_sitenote_active":false,"_monsterinsights_sitenote_note":"","_monsterinsights_sitenote_category":0,"footnotes":""},"categories":[13,14,15,19,5,35],"tags":[],"class_list":["post-473","post","type-post","status-publish","format-standard","hentry","category-10g","category-11g","category-9ir2","category-metalink","category-oracle-database","category-real-application-clusters-oracle-database-2"],"aioseo_notices":[],"_links":{"self":[{"href":"https:\/\/www.ora-solutions.net\/web\/wp-json\/wp\/v2\/posts\/473","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/www.ora-solutions.net\/web\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/www.ora-solutions.net\/web\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/www.ora-solutions.net\/web\/wp-json\/wp\/v2\/users\/2"}],"replies":[{"embeddable":true,"href":"https:\/\/www.ora-solutions.net\/web\/wp-json\/wp\/v2\/comments?post=473"}],"version-history":[{"count":10,"href":"https:\/\/www.ora-solutions.net\/web\/wp-json\/wp\/v2\/posts\/473\/revisions"}],"predecessor-version":[{"id":1189,"href":"https:\/\/www.ora-solutions.net\/web\/wp-json\/wp\/v2\/posts\/473\/revisions\/1189"}],"wp:attachment":[{"href":"https:\/\/www.ora-solutions.net\/web\/wp-json\/wp\/v2\/media?parent=473"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/www.ora-solutions.net\/web\/wp-json\/wp\/v2\/categories?post=473"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/www.ora-solutions.net\/web\/wp-json\/wp\/v2\/tags?post=473"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}