遭遇cursor:pin x等待事件却无法找到blocker的会话

bj-jn

环境描述：DB:10.2.0.4.0 /OS:AIX 5.3 (64bit)

问题描述：
1.会话A执行如下命令被挂起
SQL> exec dbms_shared_pool.purge('07000008B4C75210,2298158739','C',1);

2.登陆会话B查看v$session相关信息
SQL> select sid,blocking_session,event,p1,p2raw from v$session where event='cursor: pin X';

       SID BLOCKING_SESSION EVENT                             P1 P2RAW
---------- ---------------- ------------------------- ---------- ----------------
      2016                  cursor: pin X             2298158739 0000000000000001

当前被阻塞会话id为2016,通过blocking_session字段和p2raw字段都无法判断blocker会话id。

3.对当前实例做systemstate level 266，从trace文件中观察到如下信息：
PROCESS 42:
  ----------------------------------------
  SO: 700000a0c3d2748, type: 2, owner: 0, flag: INIT/-/-/0x00
  (process) Oracle pid=42, calls cur/top: 7000009c1f4bb98/7000009c1f4bb98, flag: (0) -
            int error: 0, call error: 0, sess error: 0, txn error 0
。。。。。。
。。。。。。
    (session) sid: 2016 trans: 0, creator: 700000a0c3d2748, flag: (100041) USR/- BSY/-/-/-/-/-
              DID: 0001-002A-00000792, short-term DID: 0000-0000-00000000
              txn branch: 0
              oct: 47, prv: 0, sql: 7000008d486cf10, psql: 7000009d0360ae0, user: 0/SYS
。。。。。。
。。。。。。
   waiting for 'cursor: pin X' blocking sess=0x0 seq=13163 wait_time=0 seconds since wait started=0
                idn=88fb1e93, value=1, where|sleeps=e000432d5
从标红信息确实看到了被阻塞会话的相关信息，到此我还是不知道如何能够查找到blocker会话的sid。
希望各位给予指点，万分感谢！
附件为完整的systemstate

warmbreeze

被阻塞session准备以excl方式持有这个cursor
Mutex 7000008b4736020(0, 1) idn 88fb1e93 oper GET_EXCL

而PROCESS 29:
正以shared方式持有此cursor
Mutex 7000008b4736020(0, 1) idn 88fb1e93 oper SHRD

bj-jn

warmbreeze 发表于 2013-4-10 12:13
被阻塞session准备以excl方式持有这个cursor
Mutex 7000008b4736020(0, 1) idn 88fb1e93 oper GET_EXCL

谢谢这位哥们！

Maclean Liu(刘相兵

[oracle@vrh8 ~]$ awk -f ass1033.awk  systemstate.txt

Starting Systemstate 1
.......................................
Ass.Awk Version 1.0.33
~~~~~~~~~~~~~~~~~~~~~~
Source file : systemstate.txt

System State 1  (2013-04-09 21:00:03.452)
~~~~~~~~~~~~~~   ~~~~~~~~~~~~~~~~~~~~~~~
1:                                      [DEAD]
2:  waiting for 'pmon timer'            seq=21645
3:  waiting for 'rdbms ipc message'     seq=36789
4:  waiting for 'rdbms ipc message'     seq=19
5:  waiting for 'rdbms ipc message'     seq=36156
6:  waiting for 'rdbms ipc message'     seq=59533
7:  waiting for 'rdbms ipc message'     seq=13749
8:  waiting for 'rdbms ipc message'     seq=20685
9:  waiting for 'rdbms ipc message'     seq=48539
10: waiting for 'rdbms ipc message'     seq=32585
11: waiting for 'rdbms ipc message'     seq=1059
12: waiting for 'rdbms ipc message'     seq=58711
13: waiting for 'rdbms ipc message'     seq=24089
14: waiting for 'rdbms ipc message'     seq=47243
15: last wait for 'smon timer'         
16: waiting for 'rdbms ipc message'     seq=1762
17: waiting for 'rdbms ipc message'     seq=50056
18: waiting for 'rdbms ipc message'     seq=63956
19: waiting for 'rdbms ipc message'     seq=19
20: last wait for 'db file sequential read' (2a,1422eb,1)
     Cmd: Insert
21: waiting for 'Streams AQ: waiting for time management or cleanup tasks' seq=260
22: waiting for 'Streams AQ: qmn coordinator idle wait' seq=480
23: waiting for 'db file sequential read' (3d,3152db,1) seq=1312
     Cmd: Update
24: waiting for 'SQL*Net message from client' seq=182
25: waiting for 'SQL*Net message from client' seq=64
26: waiting for 'SQL*Net message from client' seq=21469
27: waiting for 'SQL*Net message from client' seq=25062
28: waiting for 'SQL*Net message from client' seq=252
29: waiting for 'db file sequential read' (47,339e6,1) seq=60148
     Cmd: Insert
30: waiting for 'SQL*Net message from client' seq=10
31: waiting for 'SQL*Net message from client' seq=170
32: waiting for 'SQL*Net message from client' seq=1619
33: waiting for 'Streams AQ: qmn slave idle wait' seq=64
34: waiting for 'SQL*Net message from client' seq=12
35: waiting for 'SQL*Net message from client' seq=2761
36: last wait for 'ksdxexeotherwait'   
40: waiting for 'SQL*Net message from client' seq=153
42: waiting for 'cursor: pin X'        [Mutex 88fb1e93] seq=13163
     Cmd: PL/SQL Execute
44: waiting for 'SQL*Net message from client' seq=7578

Blockers


                    Resource Holder State
              Mutex 88fb1e93    ??? Blocker



No blockers seen.

Object Names
~~~~~~~~~~~~
Mutex 88fb1e93                                                

Summary of Wait Events Seen (count>10)
~~~~~~~~~~~~~~~~~~~~~~~~~~~
    16 : 'rdbms ipc message'
    12 : 'SQL*Net message from client'

Maclean Liu(刘相兵

Mutex 88fb1e93    ??? Blocker

      KGX Atomic Operation Log 7000007a4c28310
       Mutex 7000008b4736020(0, 1) idn 88fb1e93 oper GET_EXCL
       Cursor Pin uid 2016 efd 0 whr 14 slp 7785
       opr=3 pso=700000898104d18 flg=0
       pcs=7000008b4736020 nxt=7000008b4735ad0 flg=18 cld=0 hd=7000008b47a53f8 par=7000008b476cbb0
       ct=9 hsh=0 unp=0 unn=0 hvl=b476cea0 nhv=0 ses=0
       hep=7000008b47360a0 flg=80 ld=1 ob=700000824463668 ptr=7000008b4199d80 fex=7000008b4199090
      ----------------------------------------
      SO: 7000006bc0eec98, type: 53, owner: 7000009c1f4bb98, flag: INIT/-/-/0x00
      LIBRARY OBJECT LOCK: lock=7000006bc0eec98 handle=7000008b4c75210 mode=N
      call pin=0 session pin=0 hpc=0000 hlc=0000
      htl=7000006bc0eed18[70000089f11b590,700000898104d98] htb=70000089f11b590 ssga=70000089f11ab48
      user=700000a0b5d0748 session=700000a0b5d0748 count=1 flags=[0000] savepoint=0xad7
      LIBRARY OBJECT HANDLE: handle=7000008b4c75210 mtx=7000008b4c75340(2) cdp=1
      name=
INSERT INTO BUSINESS_TARGETS (COMCODE, DEPTNO, BUSINESS_TYPE, CUSTOM, CHANNEL, RISKCODE, KINDCODE, CAR_TYPE, YEAR, MONTH, TARGET_TYPE, AMOUNT) SELECT COMCODE, COMCODE,
'' BUSINESS_TYPE, '' CUSTOM, C.BUSINESSNATURE CHANNEL, C.RISKCODE, NVL(A.ARTICLECODE, '02'), '999999' CAR_TYPE, :B5 YEAR, :B4 MONTH, 'е¥¼þÊý' TARGET_TYPE, SUM(1) AMOU
NT FROM PRPCMAINORIGIN C, (SELECT * FROM PRPCITEMKINDORIGIN H LEFT JOIN PRPDKINDARTICLE G ON (H.RISKCODE = G.RISKCODE AND H.KINDCODE = G.KINDCODE) WHERE H.RISKCODE LIKE
'05%' A
      hash=6e031a7ec0e7eec037f459cd88fb1e93 timestamp=04-08-2013 15:05:55
      namespace=CRSR flags=RON/KGHP/TIM/PN0/KST/DBN/MTX/[100100d0]
      kkkk-dddd-llll=0000-0001-0001 lock=N pin=0 latch#=8 hpc=fff4 hlc=fff4
      lwt=7000008b4c752b8[7000008b4c752b8,7000008b4c752b8] ltm=7000008b4c752c8[7000008b4c752c8,7000008b4c752c8]
      pwt=7000008b4c75280[7000008b4c75280,7000008b4c75280] ptm=7000008b4c75290[7000008b4c75290,7000008b4c75290]
      ref=7000008b4c752e8[7000008b4c752e8,7000008b4c752e8] lnd=7000008b4c75300[7000009f7e9d678,7000009c41d4f78]
        LIBRARY OBJECT: object=7000008b476ca98
        type=CRSR flags=EXS[0001] pflags=[0000] status=VALD load=0


      KGX Atomic Operation Log 700000824452808
       Mutex 7000008b4736020(0, 1) idn 88fb1e93 oper SHRD
       Cursor Pin uid 2018 efd 0 whr 1 slp 0
       opr=4 pso=7000009f5135b48 flg=0
       pcs=7000008b4736020 nxt=7000008b4735ad0 flg=18 cld=0 hd=7000008b47a53f8 par=7000008b476cbb0
       ct=9 hsh=0 unp=0 unn=0 hvl=b476cea0 nhv=0 ses=0
       hep=7000008b47360a0 flg=80 ld=1 ob=700000824463668 ptr=7000008b4199d80 fex=7000008b4199090



       Mutex 7000008b4736020(0, 1) idn 88fb1e93 oper SHRD
              Mutex 7000008b4736020(0, 1) idn 88fb1e93 oper GET_EXCL


Mutex 7000008b4736020(0, 1) idn 88fb1e93 oper SHRD 的session  sqlplus@DB01_manage (TNS V1-V3)  sid: 2018正在执行该INSERT语句，该语句用到了绑定变量


    SO: 700000a095c9940, type: 4, owner: 700000a0b3c1500, flag: INIT/-/-/0x00
    (session) sid: 2018 trans: 700000a05bc18e8, creator: 700000a0b3c1500, flag: (41) USR/- BSY/-/-/-/-/-
              DID: 0001-001D-00001A25, short-term DID: 0000-0000-00000000
              txn branch: 0
              oct: 2, prv: 0, sql: 7000008b4c75210, psql: 7000008b448f428, user: 254/<none>
    service name: SYS$USERS
    O/S info: user: ora, term: pts/3, ospid: 4055330, machine: DB01_manage
              program: sqlplus@DB01_manage (TNS V1-V3)
    application name: sqlplus@DB01_manage (TNS V1-V3), hash value=3504064190
    waiting for 'db file sequential read' blocking sess=0x0 seq=60148 wait_time=0 seconds since wait started=0
                file#=47, block#=339e6, blocks=1
    Dumping Session Wait History
     for 'db file sequential read' count=1 wait_time=105082
                file#=46, block#=34241, blocks=1
     for 'db file sequential read' count=1 wait_time=4813
                file#=46, block#=3424c, blocks=1
     for 'db file sequential read' count=1 wait_time=7209


      SO: 7000009ed0ce938, type: 53, owner: 700000a095c9940, flag: INIT/-/-/0x00
      LIBRARY OBJECT LOCK: lock=7000009ed0ce938 handle=7000008b4c75210 mode=N
      call pin=0 session pin=0 hpc=0000 hlc=0000
      htl=7000009ed0ce9b8[70000089f118248,7000009f5135bc8] htb=70000089f118248 ssga=70000089f117800
      user=700000a095c9940 session=700000a095c9940 count=1 flags=[0000] savepoint=0x51641086
      LIBRARY OBJECT HANDLE: handle=7000008b4c75210 mtx=7000008b4c75340(2) cdp=1
      name=
INSERT INTO BUSINESS_TARGETS (COMCODE, DEPTNO, BUSINESS_TYPE, CUSTOM, CHANNEL, RISKCODE, KINDCODE, CAR_TYPE, YEAR, MONTH, TARGET_TYPE, AMOUNT) SELECT COMCODE, COMCODE,
'' BUSINESS_TYPE, '' CUSTOM, C.BUSINESSNATURE CHANNEL, C.RISKCODE, NVL(A.ARTICLECODE, '02'), '999999' CAR_TYPE, :B5 YEAR, :B4 MONTH, 'е¥¼þÊý' TARGET_TYPE, SUM(1) AMOU
NT FROM PRPCMAINORIGIN C, (SELECT * FROM PRPCITEMKINDORIGIN H LEFT JOIN PRPDKINDARTICLE G ON (H.RISKCODE = G.RISKCODE AND H.KINDCODE = G.KINDCODE) WHERE H.RISKCODE LIKE
'05%' A




被block的session 等待 cursor: pin X 正在执行的是

BEGIN dbms_shared_pool.purge('07000008B4C75210,2298158739','C',1); END;

07000008b4c75210 正对应于 前面的INSERT SQL语句：

      SO: 7000006bc0eec98, type: 53, owner: 7000009c1f4bb98, flag: INIT/-/-/0x00
      LIBRARY OBJECT LOCK: lock=7000006bc0eec98 handle=7000008b4c75210 mode=N
      call pin=0 session pin=0 hpc=0000 hlc=0000
      htl=7000006bc0eed18[70000089f11b590,700000898104d98] htb=70000089f11b590 ssga=70000089f11ab48
      user=700000a0b5d0748 session=700000a0b5d0748 count=1 flags=[0000] savepoint=0xad7
      LIBRARY OBJECT HANDLE: handle=7000008b4c75210 mtx=7000008b4c75340(2) cdp=1
      name=
INSERT INTO BUSINESS_TARGETS (COMCODE, DEPTNO, BUSINESS_TYPE, CUSTOM, CHANNEL, RISKCODE, KINDCODE, CAR_TYPE, YEAR, MONTH, TARGET_TYPE, AMOUNT) SELECT COMCODE, COMCODE,
'' BUSINESS_TYPE, '' CUSTOM, C.BUSINESSNATURE CHANNEL, C.RISKCODE, NVL(A.ARTICLECODE, '02'), '999999' CAR_TYPE, :B5 YEAR, :B4 MONTH, 'е¥¼þÊý' TARGET_TYPE, SUM(1) AMOU
NT FROM PRPCMAINORIGIN C, (SELECT * FROM PRPCITEMKINDORIGIN H LEFT JOIN PRPDKINDARTICLE G ON (H.RISKCODE = G.RISKCODE AND H.KINDCODE = G.KINDCODE) WHERE H.RISKCODE LIKE
'05%' A
      hash=6e031a7ec0e7ee



   SO: 700000a0b5d0748, type: 4, owner: 700000a0c3d2748, flag: INIT/-/-/0x00
    (session) sid: 2016 trans: 0, creator: 700000a0c3d2748, flag: (100041) USR/- BSY/-/-/-/-/-
              DID: 0001-002A-00000792, short-term DID: 0000-0000-00000000
              txn branch: 0
              oct: 47, prv: 0, sql: 7000008d486cf10, psql: 7000009d0360ae0, user: 0/SYS
    service name: SYS$USERS
    O/S info: user: ora, term: pts/7, ospid: 2811306, machine: DB01_manage
              program: sqlplus@DB01_manage (TNS V1-V3)
    application name: sqlplus@DB01_manage (TNS V1-V3), hash value=3504064190
    waiting for 'cursor: pin X' blocking sess=0x0 seq=13163 wait_time=0 seconds since wait started=0
                idn=88fb1e93, value=1, where|sleeps=e000432d5
    Dumping Session Wait History
     for 'cursor: pin X' count=1 wait_time=69980
                idn=88fb1e93, value=1, where|sleeps=e000432d4
     for 'cursor: pin X' count=1 wait_time=9775
                idn=88fb1e93, value=1, where|sleeps=e000432d3
     for 'cursor: pin X' count=1 wait_time=9774
                idn=88fb1e93, value=1, where|sleeps=e000432d2
     for 'cursor: pin X' count=1 wait_time=9774


      SO: 7000006290f8f38, type: 53, owner: 700000a0b5d0748, flag: INIT/-/-/0x00
      LIBRARY OBJECT LOCK: lock=7000006290f8f38 handle=7000008d486cf10 mode=N
      call pin=0 session pin=0 hpc=0000 hlc=0000
      htl=7000006290f8fb8[70000089f11b200,700000629133d38] htb=70000089f11b200 ssga=70000089f11ab48
      user=700000a0b5d0748 session=700000a0b5d0748 count=1 flags=[0000] savepoint=0x51641087
      LIBRARY OBJECT HANDLE: handle=7000008d486cf10 mtx=7000008d486d040(1) cdp=1
      name=BEGIN dbms_shared_pool.purge('07000008B4C75210,2298158739','C',1); END;
      hash=cc5a32e71af8e9d6b84bb0e747a0805a timestamp=04-09-2013 13:29:19
      namespace=CRSR flags=RON/KGHP/TIM/PN0/MED/KST/DBN/MTX/[500100d0]
      kkkk-dddd-llll=0000-0001-0001 lock=N pin=0 latch#=35 hpc=0002 hlc=0002
      lwt=7000008d486cfb8[7000008d486cfb8,7000008d486cfb8] ltm=7000008d486cfc8[7000008d486cfc8,7000008d486cfc8]
      pwt=7000008d486cf80[7000008d486cf80,7000008d486cf80] ptm=7000008d486cf90[7000008d486cf90,7000008d486cf90]
      ref=7000008d486cfe8[7000008d486cfe8,7000008d486cfe8] lnd=7000008d486d000[7000008d486d000,7000008d486d000]
        LIBRARY OBJECT: object=7000008cd68e3b0

Maclean Liu(刘相兵

总结：

sqlplus@DB01_manage (TNS V1-V3) 登陆的 session 2016 视图执行
BEGIN dbms_shared_pool.purge('07000008B4C75210,2298158739','C',1); END;


但是其所要 purge的游标 一直被 sqlplus@DB01_manage (TNS V1-V3)  sid: 2018 执行 ，导致出现'cursor: pin X' 等待

bj-jn

Maclean Liu(刘相兵 发表于 2013-4-10 15:16
总结：

sqlplus@DB01_manage (TNS V1-V3) 登陆的 session 2016 视图执行

感谢刘大的回复，学习了！

F.k-Tao

刘大  ass1033.awk 能提供吗？

F.k-Tao

不知道这个脚本在metalink里面能找到不？

Maclean Liu(刘相兵

F.k-Tao 发表于 2013-4-12 15:13
不知道这个脚本在metalink里面能找到不？

不能