Library cache dump and cursors

Test Environment:
Oracle : 11.2.0.3 / RHEL : 6.3 x86_64

sqlplus /nolog
conn caoff/caoff
drop table TEST_NOT_EXIST purge;
drop table TEST_EXIST purge;
create table TEST_EXIST as select * from dba_objects where rownum<=10;

alter system flush shared_pool;

— table TEST_NOT_EXIST does not exist

select count(*) from TEST_NOT_EXIST;

— table TEST_EXIST exists

select count(*) from TEST_EXIST;

conn / as sysdba

— identify parent cursor and child cursor content for a the above SQL

set lines 200 pages 200
col kglnaobj for a40
col KGLNAOWN for a8
select ADDR,
KGLHDADR,
KGLHDPAR,
KGLNAOWN,
KGLNAOBJ,
KGLOBHD0,
KGLOBHD6
from x$kglob
where kglnaobj like '%select count(*) from T_%'
and kglnaobj not like '%x$kglob%'
order by kglnaobj,KGLHDADR;

There is one parent cursor with one valid child cursor and one parent cursor with one invalid child cursor (the child cursor 0000000077459530 does not exist in x$kglcursor_child).

----
ADDR KGLHDADR KGLHDPAR KGLNAOWN KGLNAOBJ KGLOBHD0 KGLOBHD6
---------------- ---------------- ---------------- -------- ---------------------------------------- ---------------- ----------------
00007F4C5EDA2FA0 0000000090BD6970 0000000090BD6CE0 select count(*) from TEST_EXIST 0000000090BD68B8 0000000092472AB0
00007F4C5EDA40E8 0000000090BD6CE0 0000000090BD6CE0 select count(*) from TEST_EXIST 000000008AE28F38 00
00007F4C5EDA2FA0 000000008AE28FF0 000000008AE29450 select count(*) from TEST_NOT_EXIST 00 00
00007F4C5EDA40E8 000000008AE29450 000000008AE29450 select count(*) from TEST_NOT_EXIST 000000008AE29398 00

— dump library cache level 4: include dump of object structures ( heap 0)

alter session set tracefile_identifier = after_executed_by_caoff;
alter session set events 'immediate trace name library_cache level 4';
Bucket: #=62562 Mutex=0x98469780(0, 120, 0, 6)
 LibraryHandle: Address=0x90bd6ce0 Hash=7b6cf462 LockMode=0 PinMode=0 LoadLockMode=0 Status=VALD
 ObjectName: Name=select count(*) from TEST_EXIST
 FullHashValue=424ef4685aa15d90c4b35d197b6cf462 Namespace=SQL AREA(00) Type=CURSOR(00) Identifier=2070738018 OwnerIdn=66
 Statistics: InvalidationCount=0 ExecutionCount=1 LoadCount=2 ActiveLocks=0 TotalLockCount=1 TotalPinCount=1
 Counters: BrokenCount=1 RevocablePointer=1 KeepDependency=1 BucketInUse=0 HandleInUse=0 HandleReferenceCount=0
 Concurrency: DependencyMutex=0x90bd6d90(0, 1, 0, 0) Mutex=0x90bd6e10(134, 36, 0, 6)
 Flags=RON/PIN/TIM/PN0/DBN/[10012841]
 WaitersLists:
 Lock=0x90bd6d70[0x90bd6d70,0x90bd6d70]
 Pin=0x90bd6d50[0x90bd6d50,0x90bd6d50]
 LoadLock=0x90bd6dc8[0x90bd6dc8,0x90bd6dc8]
 Timestamp: Current=10-18-2016 11:08:14
 HandleReference: Address=0x90bd6e98 Handle=(nil) Flags=[00]
 LibraryObject: Address=0x924723f0 HeapMask=0000-0001-0001-0000 Flags=EXS[0000] Flags2=[0000] PublicFlags=[0000]
 ChildTable: size='16'
 Child: id='0' Table=0x924732a0 Reference=0x92472ce0 Handle=0x90bd6970
 NamespaceDump:
 Parent Cursor: sql_id=c9cux35xqtx32 parent=0x92472490 maxchild=1 plk=n ppn=n 0x8ae29450 Hash=34d4fdf0 LockMode=0 PinMode=0 LoadLockMode=0 Status=VALD
 ObjectName: Name=select count(*) from TEST_NOT_EXIST
 FullHashValue=a58ccd09c241fdc56386e65634d4fdf0 Namespace=SQL AREA(00) Type=CURSOR(00) Identifier=886373872 OwnerIdn=66
 Statistics: InvalidationCount=1 ExecutionCount=0 LoadCount=2 ActiveLocks=0 TotalLockCount=1 TotalPinCount=1
 Counters: BrokenCount=1 RevocablePointer=1 KeepDependency=0 BucketInUse=0 HandleInUse=0 HandleReferenceCount=0
 Concurrency: DependencyMutex=0x8ae29500(0, 1, 0, 0) Mutex=0x8ae29580(134, 37, 0, 6)
 Flags=RON/PIN/TIM/PN0/DBN/[10012841]
 WaitersLists:
 Lock=0x8ae294e0[0x8ae294e0,0x8ae294e0]
 Pin=0x8ae294c0[0x8ae294c0,0x8ae294c0]
 LoadLock=0x8ae29538[0x8ae29538,0x8ae29538]
 Timestamp: Current=10-18-2016 11:08:10
 HandleReference: Address=0x8ae29610 Handle=(nil) Flags=[00]
 LibraryObject: Address=0x8e067138 HeapMask=0000-0001-0001-0000 Flags=EXS[0000] Flags2=[0000] PublicFlags=[0000]
 ChildTable: size='16'
 Child: id='0' Table=0x8e067fe8 Reference=0x8e067a28 Handle=0x8ae28ff0
 NamespaceDump:
 Parent Cursor: sql_id=671r6asud9zgh parent=0x8e0671d8 maxchild=1 plk=n ppn=n

— execute the following queries for another 2 times as user caoff

-- table TEST_NOT_EXIST does not exist
select count(*) from TEST_NOT_EXIST;

-- table TEST_EXIST exists
select count(*) from TEST_EXIST;

-- table TEST_NOT_EXIST does not exist
select count(*) from TEST_NOT_EXIST;

-- table TEST_EXIST exists
select count(*) from TEST_EXIST;

— identify parent cursor and child cursor content for the above SQL

set lines 200 pages 200
col kglnaobj for a40
col KGLNAOWN for a8
select ADDR,
KGLHDADR,
KGLHDPAR,
KGLNAOWN,
KGLNAOBJ,
KGLOBHD0,
KGLOBHD6
from x$kglob
where kglnaobj like '%select count(*) from T_%'
and kglnaobj not like '%x$kglob%'
order by kglnaobj,KGLHDADR;

----
ADDR KGLHDADR KGLHDPAR KGLNAOWN KGLNAOBJ KGLOBHD0 KGLOBHD6
---------------- ---------------- ---------------- -------- ---------------------------------------- ---------------- ----------------
00007F4C5ED904C0 0000000090BD6970 0000000090BD6CE0 select count(*) from TEST_EXIST 0000000090BD68B8 0000000092472AB0
00007F4C5EDA96F8 0000000090BD6CE0 0000000090BD6CE0 select count(*) from TEST_EXIST 000000008AE28F38 00
00007F4C5ED904C0 000000008AE28FF0 000000008AE29450 select count(*) from TEST_NOT_EXIST 00 00
00007F4C5EDA96F8 000000008AE29450 000000008AE29450 select count(*) from TEST_NOT_EXIST 000000008AE29398 00

— identify child cursor information

set lines 200 pages 200
col KGLNAOBJ for a40
select kglhdadr,
kglhdpar,
kglnaobj,
kglobhd0,
kglobhd6
from x$kglcursor_child
where kglhdpar = '0000000090BD6CE0';

----
KGLHDADR KGLHDPAR KGLNAOBJ KGLOBHD0 KGLOBHD6
---------------- ---------------- ---------------------------------------- ---------------- ----------------
0000000090BD6970 0000000090BD6CE0 select count(*) from TEST_EXIST 0000000090BD68B8 0000000092472AB0

— identify child cursor sql_text information

set lines 200 pages 200
col KGLNAOBJ for a40
select kglhdadr,
kglhdpar,
kglnaobj,
kglobhd0,
kglobhd6
from x$kglcursor_child_sqlid
where kglhdpar = '0000000090BD6CE0';

KGLHDADR KGLHDPAR KGLNAOBJ KGLOBHD0 KGLOBHD6
---------------- ---------------- ---------------------------------------- ---------------- ----------------
00000000765EEC90 00000000774580E0 select count(*) from TEST_EXIST 0000000077458028 0000000076C3F330

— dump library cache level 4: include dump of object structures ( heap 0)

alter session set events 'immediate trace name library_cache level 4';

Note the InvalidationCount and ExecutionCount of the two cursors. We can see that bucket number remain the same and the ExecutionCount and InvalidationCount increase in parent cursor statistics.

Bucket: #=62562 Mutex=0x98469780(0, 145, 0, 6)
LibraryHandle: Address=0x90bd6ce0 Hash=7b6cf462 LockMode=N PinMode=0 LoadLockMode=0 Status=VALD
ObjectName: Name=select count(*) from TEST_EXIST
FullHashValue=424ef4685aa15d90c4b35d197b6cf462 Namespace=SQL AREA(00) Type=CURSOR(00) Identifier=2070738018 OwnerIdn=66
Statistics: InvalidationCount=0 ExecutionCount=3 LoadCount=2 ActiveLocks=1 TotalLockCount=3 TotalPinCount=1
Counters: BrokenCount=1 RevocablePointer=1 KeepDependency=1 BucketInUse=2 HandleInUse=2 HandleReferenceCount=0
Concurrency: DependencyMutex=0x90bd6d90(0, 1, 0, 0) Mutex=0x90bd6e10(134, 88, 0, 6)
Flags=RON/PIN/TIM/PN0/DBN/[10012841]
WaitersLists:
Lock=0x90bd6d70[0x90bd6d70,0x90bd6d70]
Pin=0x90bd6d50[0x90bd6d50,0x90bd6d50]
LoadLock=0x90bd6dc8[0x90bd6dc8,0x90bd6dc8]
Timestamp: Current=10-18-2016 11:08:14
HandleReference: Address=0x90bd6e98 Handle=(nil) Flags=[00]
LibraryObject: Address=0x924723f0 HeapMask=0000-0001-0001-0000 Flags=EXS[0000] Flags2=[0000] PublicFlags=[0000]
ChildTable: size='16'
Child: id='0' Table=0x924732a0 Reference=0x92472ce0 Handle=0x90bd6970
NamespaceDump:
Parent Cursor: sql_id=c9cux35xqtx32 parent=0x92472490 maxchild=1 plk=y ppn=n

Bucket: #=65008 Mutex=0x984815b0(0, 8103, 0, 6)
LibraryHandle: Address=0x8ae29450 Hash=34d4fdf0 LockMode=0 PinMode=0 LoadLockMode=0 Status=VALD
ObjectName: Name=select count(*) from TEST_NOT_EXIST
FullHashValue=a58ccd09c241fdc56386e65634d4fdf0 Namespace=SQL AREA(00) Type=CURSOR(00) Identifier=886373872 OwnerIdn=66
Statistics: InvalidationCount=3 ExecutionCount=0 LoadCount=4 ActiveLocks=0 TotalLockCount=3 TotalPinCount=1
Counters: BrokenCount=1 RevocablePointer=1 KeepDependency=0 BucketInUse=2 HandleInUse=2 HandleReferenceCount=0
Concurrency: DependencyMutex=0x8ae29500(0, 1, 0, 0) Mutex=0x8ae29580(134, 110, 0, 6)
Flags=RON/PIN/TIM/PN0/DBN/[10012841]
WaitersLists:
Lock=0x8ae294e0[0x8ae294e0,0x8ae294e0]
Pin=0x8ae294c0[0x8ae294c0,0x8ae294c0]
LoadLock=0x8ae29538[0x8ae29538,0x8ae29538]
Timestamp: Current=10-18-2016 11:08:10
HandleReference: Address=0x8ae29610 Handle=(nil) Flags=[00]
LibraryObject: Address=0x8e067138 HeapMask=0000-0001-0001-0000 Flags=EXS[0000] Flags2=[0000] PublicFlags=[0000]
ChildTable: size='16'
Child: id='0' Table=0x8e067fe8 Reference=0x8e067a28 Handle=0x8ae28ff0
NamespaceDump:
Parent Cursor: sql_id=671r6asud9zgh parent=0x8e0671d8 maxchild=1 plk=n ppn=n

— identify SQL parse errors

alter system set events '10035 trace name context forever, level 1';
alter system set events '10035 trace name context off';

You can see SQLs that have parse errors in alert.log:

Fri Mar 11 10:39:35 2016
PARSE ERROR: ospid=17470, error=942 for statement:
select count(*) from TEST_NOT_EXIST

Alternatively, you can execute the following commands to enable 10035 event in a particular session:

select sid, serial#
from v$session s
where s.sid =
(select sid from v$mystat where rownum=1);

SID SERIAL#
---------- ----------
56 173

exec dbms_system.set_ev(56,173,10035,1,'');

After executing SQL, one can check v$librarycache to check cumulative reloads and invalidations counts increment.

select NAMESPACE,
GETS,
GETHITS,
PINS,
PINHITS,
RELOADS,
INVALIDATIONS
from v$librarycache
where NAMESPACE='SQL AREA';

Reference:

How to Identify Hard Parse Failures (ID: 1353015.1)

Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s