RE: No blocking session for wait event: 'Library cache pin'

From: Bobak, Mark <Mark.Bobak_at_proquest.com>
Date: Tue, 2 Aug 2011 16:19:03 -0400
Message-ID: <6AFC12B9BFCDEA45B7274C534738067F751EBA2C_at_AAPQMAILBX02V.proque.st>



Sanjeev,

I think your problem here is misunderstanding your script output. As per Tanel's script, your process was 'ON CPU'. If it's on cpu, it's not waiting, and the wait event indicates that last thing that it waited on, but it has long since moved on.

The key is to consider the value of V$SESSION.STATE, in combination with V$SESSION.EVENT. If STATE column is anything other than 'WAITING', then you are *not* waiting, and are in fact, on the CPU. In this case, if STATE is 'WAITED SHORT TIME', then you waited on the event recorded in EVENT for less than a centisecond. If it's 'WAITED KNOWN TIME', then the time you waited is reflected in WAIT_TIME, and if STATE is 'WAITED UNKNOWN TIME', you need to enable timed_statistics.

So, you're not really stuck on library cache pin wait, at all.

Hope that helps,

-Mark

From: oracle-l-bounce_at_freelists.org [mailto:oracle-l-bounce_at_freelists.org] On Behalf Of Sanjeev M Sent: Tuesday, August 02, 2011 2:32 PM
To: ORACLE-L
Subject: Re: No blocking session for wait event: 'Library cache pin'

Typo corrected in RED below
On Tue, Aug 2, 2011 at 11:19 AM, Sanjeev M <sanjeevorcle_at_gmail.com<mailto:sanjeevorcle_at_gmail.com>> wrote: Environment: 2 node RAC on OEL 5
Grid Home : 11.2.0.2
RDBMS Home: 11.1.0.7.7

On our database, Session was waiting most of the time on 'library cache pin' wait - for a decent amount like a minute or more before toggling to another wait event db file sequential read and back to this wait.

Could it be a bug that the blocker session is not showing up?

select p1raw,p1text,event,sid from v$session where sid=1710;

P1RAW            P1TEXT                                                           EVENT                                                                   SID

---------------- ---------------------------------------------------------------- ---------------------------------------------------------------- ----------
0000000356213B10 handle address library cache pin 1710
select * from x$kglpn where KGLPNHDL='0000000356213B10'; no rows selected <=== Expected to see some info here regading object, lock mode (Either null/shared or exclusive) however no output!!!

Also checked for other handle addresses from gv$session to see if it possibly is having some kind of dependancy:

select inst_id,p1raw,count(1) from gv$session where event='library cache pin' group by inst_id,p1raw;

   INST_ID P1RAW COUNT(1)
---------- ---------------- ----------

         1 000000032FA9B7A0          1
         1 0000000356213B10          1

select * from x$kglpn where KGLPNHDL='000000032FA9B7A0'; no rows selected <=== Expected to see some info here regading object, lock mode (Either null/shared or exclusive) however no output!!! Also tried gv$ges_blocking_enqueue however output does not show anything related to "lib pin -- Nx Gx"

'WAI INST_ID SPID RESOURCE_NAME1
---- ---------- ---------- ------------------------------

Wait          1      10838 [0x75daf18b][0x4c05b769],[NB]
Wait          2      17532 [0x19][0x2],[RS]
Wait          2          0 [0x8c0][0x10000],[BL]
Blkr          1      10132 [0x19][0x2],[RS]
Blkr          2      17508 [0x1][0x0],[PW]

Ran tanel poder's snapper while this was happening and it says session on CPU:

_at_snapper ash=sql_id+event+wait_class+p1+p2+p3 5 1 1710 Sampling SID 1710 with interval 5 seconds, taking 1 snapshots...
-- Session Snapper v3.14 by Tanel Poder _at_ E2SN ( http://tech.e2sn.com<http://tech.e2sn.com/> )


Active% | SQL_ID          | EVENT                     | WAIT_CLASS      | P1               | P2               | P3

--------------------------------------------------------------------------------------------------------------------------------
100% | 10za9fj1va0kd | ON CPU | ON CPU | | |

-- End of ASH snap 1, end=2011-08-02 11:00:58, seconds=5, samples_taken=42

PL/SQL procedure successfully completed.

SQL statement that was being run for this session was:

select msi.inventory_item_id                   from mtl_parameters mp,
                      mtl_system_items msi,
mtl_system_items_interface msii                   where
msii.transaction_id = :transaction_id_bind                    and
msii.set_process_id = :set_id_bind2                    and rownum = 1
                 and msi.organization_id = mp.organization_id
         and  msi.segment1 = msii.segment1
Plan hash value: 904999408
| Id  | Operation                      | Name                          | Rows  | Bytes | Cost (%CPU)| Time     |

----------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | | | 342 (100)| | |* 1 | COUNT STOPKEY | | | | | | | 2 | NESTED LOOPS | | 21 | 882 | 342 (1)| 00:00:05 | | 3 | NESTED LOOPS | | 21 | 798 | 342 (1)| 00:00:05 | | 4 | TABLE ACCESS FULL | MTL_SYSTEM_ITEMS_B | 12245 | 191K| 342 (1)| 00:00:05 | |* 5 | TABLE ACCESS BY INDEX ROWID| MTL_SYSTEM_ITEMS_INTERFACE | 1 | 22 | 0 (0)| | |* 6 | INDEX RANGE SCAN | MTL_SYSTEM_ITEMS_INTERFACE_N6 | 1 | | 0 (0)| | |* 7 | INDEX UNIQUE SCAN | MTL_PARAMETERS_U1 | 1 | 4 | 0 (0)| |
----------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
   1 - filter(ROWNUM=1)
   5 - filter(("MSII"."SET_PROCESS_ID"=:SET_ID_BIND2 AND "MSI"."SEGMENT1"="MSII"."SEGMENT1"))
   6 - access("MSII"."TRANSACTION_ID"=:TRANSACTION_ID_BIND)
   7 - access("MSI"."ORGANIZATION_ID"="MP"."ORGANIZATION_ID")
Any pointers or help much appreciated.

Thanks,
Sanjeev.

--

http://www.freelists.org/webpage/oracle-l Received on Tue Aug 02 2011 - 15:19:03 CDT

Original text of this message