Find hidden initialization parameter values

Today, hit "ORA-00600: internal error code, arguments: [20022], [2], [], [], [], [], [], []". Find this blog on the web that described the same situation. Basically it is due to _b_tree_bitmap_plans=TRUE. Metalink has a note 378117.1 about it.


The following query can be used to check the hidden parameter values:

col name format a30
col description format a40
col session_value format a10
col system_value format a10

select
   a.ksppinm  name,
   a.ksppdesc DESCRIPTION,
   b.ksppstvl SESSION_VALUE,
   c.ksppstvl SYSTEM_VALUE
from x$ksppi a, x$ksppcv b, x$ksppsv c
where a.indx = b.indx
 and a.indx = c.indx
 and a.ksppinm like '%tree%';

For examples:

In 9i:

NAME                           DESCRIPTION                              SESSION_VA SYSTEM_VAL
------------------------------ ---------------------------------------- ---------- ----------
_dump_qbc_tree                 dump top level query parse tree to trace 0          0
_b_tree_bitmap_plans           enable the use of bitmap plans for table TRUE       TRUE
                               s w. only B-tree indexes


In 10g:
NAME                           DESCRIPTION                              SESSION_VA SYSTEM_VAL
------------------------------ ---------------------------------------- ---------- ----------
_dump_qbc_tree                 dump top level query parse tree to trace 0          0
_b_tree_bitmap_plans           enable the use of bitmap plans for table TRUE       TRUE
                               s w. only B-tree indexes

_dtree_area_size               size of Decision Tree Classification wor 131072     131072
                               k area

_dtree_pruning_enabled         Decision Tree Pruning Enabled            TRUE       TRUE
_dtree_compressbmp_enabled     Decision Tree Using Compressed Bitmaps E TRUE       TRUE
                               nabled

_dtree_binning_enabled         Decision Tree Binning Enabled            TRUE       TRUE
_dtree_max_surrogates          maximum number of surrogates             1          1
_dtree_bintest_id              Decision Tree Binning Test ID            0          0
_outline_bitmap_tree           BITMAP_TREE hint enabled in outline      TRUE       TRUE

To change the value of hidden parameter at session level, I found I have to use double quotation mark, i.e.
alter session set "_b_tree_bitmap_plans"=false;

Oradebug dump errorstack and bind values

Tanel Poder's reply to a question in the Oracle-L mailing list inspired me to test the idea of using errostack dump to obtain the bind values in the 9i database. Previously I also took notes about different methods for obtaining bind values: here with sql_trace and more recently here with FGA.

Test steps:

1. create tables
script: cr_tab.sql

create two tables: p and c, which has parent-child relationship

2. In Session 1, insert into the parent table without commit:
SQL> variable n number
SQL> exec :n := 201
PL/SQL procedure successfully completed.
SQL> insert into p values(:n, 35);
1 row created.

3. In Session 2, insert into the child table:

SQL> variable n number
SQL> exec :n := 201
PL/SQL procedure successfully completed.
SQL> insert into c values(2, :n);

4. In another session, we can see the blocker and waiter sessions:

SQL> @bw
'WAITER'                      : WAITER
SID                           : 87
SERIAL#                       : 24
SPID                          : 27274
USERNAME                      : Zxxx294
MACHINE                       : MSHOME\NTBK
SESS_AGE_MIN                  : 17
HASH_VALUE                    : 3262381862
QUERY_TXT                     : insert into c values(:"SYS_B_0", :n)
-----------------

PL/SQL procedure successfully completed.

'BLOCKER'                     : BLOCKER
SID                           : 126
SERIAL#                       : 512
SPID                          : 57
USERNAME                      : Zxxx294
MACHINE                       : MSHOME\NTBK
SESS_AGE_MIN                  : 2
HASH_VALUE                    : 716205104
QUERY_TXT                     : insert into p values(:n, :"SYS_B_0")
-----------------

5. Logon to the server, issue the following command:

$> estk_dump.sh 27274
$> estk_dump.sh 512

Where 27274 and 512 are the OS pid (SPID) of the blocker and waiter session respectively

6. Analyze the trace files:

In the udump dir, trace files were generated, for the waiter session, we can see the bind value
(by search value=), for example:

In the trace file from pid=512

----------------------------------------
Cursor 1 (ffffffff7ca60458): CURBOUND  curiob: ffffffff7ca69828
curflg: 4c curpar: 0 curusr: b7 curses 3b433bb88
cursor name: insert into c values(:"SYS_B_0", :n)
child pin: 3b7b98c88, child lock: 3b7b947f8, parent lock: 3b7b94bb0
xscflg: 110664, parent handle: 3bcaae0a0, xscfl2: f900008
Dumping Literal Information
Bind Pos: 0, Bind Len: 2, Bind Val:
nxt: 3.0x00000420  nxt: 2.0x000001d0  nxt: 1.0x00000208
Cursor frame allocation dump:
frm: -------- Comment --------  Size  Seg Off
bhp size: 216/600
bind 0: dty=2 mxl=22(02) mal=00 scl=00 pre=00 oacflg=10 oacfl2=100 size=24 offset=0
bfp=ffffffff7ca694f0 bln=22 avl=02 flg=09
value=2
bind 1: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=03 oacfl2=0 size=24 offset=0
bfp=ffffffff7ca5e040 bln=22 avl=03 flg=05
value=201
End of cursor dump

In addtion,we can find DML LOCK information as can be seen:

DML LOCK: tab=508254 flg=11 chi=0
his[0]: mod=3 spn=302
(enqueue) TM-0007C15E-00000000  DID: 0001-000D-0000005A
lv: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
res: 3b4a42960, mode: SX, prv: 3b4a42970, sess: 3b433bb88, proc: 3b41ac6d8
----------------------------------------
SO: 3b60e47b0, type: 34, owner: 3b63c7540, flag: INIT/-/-/0x00
DML LOCK: tab=508252 flg=11 chi=0
his[0]: mod=2 spn=302
(enqueue) TM-0007C15C-00000000  DID: 0001-000D-0000005A
lv: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
res: 3b4a45758, mode: SS, prv: 3b4a45768, sess: 3b433bb88, proc: 3b41ac6d8

However, from the blocker session trace file, we can not find any bind values. Notice that waiter session was shown as 'ACTIVE' and blocker session shown as 'INACTIVE' in the v$session view. Nevertheless, we can still find DML lock info:

----------------------------------------
SO: 3b60e4540, type: 34, owner: 3b643fbe0, flag: INIT/-/-/0x00
DML LOCK: tab=508254 flg=11 chi=0
his[0]: mod=2 spn=11931
(enqueue) TM-0007C15E-00000000  DID: 0001-000A-00000E56
lv: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
res: 3b4a42960, mode: SS, prv: 3b60e4b28, sess: 3b4355778, proc: 3b41ab6b8
----------------------------------------
SO: 3b60e4060, type: 34, owner: 3b643fbe0, flag: INIT/-/-/0x00
DML LOCK: tab=508252 flg=11 chi=0
his[0]: mod=3 spn=11931
(enqueue) TM-0007C15C-00000000  DID: 0001-000A-00000E56
lv: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
res: 3b4a45758, mode: SX, prv: 3b60e47e8, sess: 3b4355778, proc: 3b41ab6b8

If we feed the DML lock information from the trace file (i.e. tab=508252) into the following query, we canget:

SQL> select object_name from dba_objects where object_id=508252;

OBJECT_NAME
------------------------------
P

SQL> select object_name from dba_objects where object_id=508254;

OBJECT_NAME
------------------------------
C

So it is interesting to know the blocker session holds SX mode DML lock on P, and SS mode DML lock on C; whereas the waiter session holds SS mode DML lock on P, and SX mode DML lock on C. If we see such kind of info, we can check the relationship between P and C, and may speculate the block/waiter is caused by FK constriant.


Appendix:

--- script: estk_dump.sh -----
#!/bin/ksh
ospid=$1
sqlplus -s "/ as sysdba" <<EOF
oradebug setospid $ospid
oradebug unlimit
oradebug dump errorstack 2 
EOF



--- script: bw.sql ------------
exec print_table(' select distinct ''WAITER'', vs.sid, vs.serial#, vp.SPID, vs.username, vs.machine, round((sysdate - vs.logo
n_time) * (24*60)) sess_age_min, va.hash_value, substr(va.sql_text,1,800) Query_Txt from v$sqlarea va, dba_waiters wait, v$se
ssion vs, v$process vp where vs.sid=wait.waiting_session and  vs.PADDR = vp.ADDR (+) and vs.sql_address=va.address (+) and vs
.sql_hash_value=va.hash_value (+) ');

exec print_table(' select distinct ''BLOCKER'' ,vs.sid, vs.serial#, vp.SPID, vs.username, vs.machine, round((sysdate - vs.log
on_time) * (24*60)) sess_age_min,va.hash_value, substr(va.sql_text,1,800) Query_Txt from v$sqlarea va, dba_blockers block, v$
session vs, v$process vp where vs.sid=block.holding_session and  vs.PADDR = vp.ADDR (+) and vs.sql_address=va.address (+) and
vs.sql_hash_value=va.hash_value (+) ');



---- script: cr_tab.sql ----------
set echo on
drop table c;
drop table p;

create table p
as
select  rownum id,
trunc(rownum/20) d
from all_objects
where rownum <=200;  

alter table p add constraint p_pk primary key (id);  

create table c 
as 
select   
rownum id,   
mod(rownum+1000, 200) + 1 fk1 
from all_objects where rownum <=200; 
alter table c add constraint c_fk foreign key(fk1) references p(id);

exec dbms_stats.gather_table_stats(user, 'p', cascade=> true);
exec dbms_stats.gather_table_stats(user, 'c', cascade=> true);

Update: Feb 2012
Reference: How to read ERRORSTACK output

Gather table column statistics

In a 9i production database, a table has a column that is subjected to have histogram. In the current script, there are two steps to gather the statistics of this table. The command looks similiar to the following:

exec dbms_stats.gather_table_stats('MY_SCHM','MY_TAB', -
estimate_percent =>20, -
cascade => TRUE,degree => 16);

exec dbms_stats.gather_table_stats('MY_SCHM','MY_TAB', -
method_opt => 'FOR COLUMNS SIZE auto MY_TAB_ID',-
degree => 8);

The problem of this approach is when the first gather_table_stats finishes, the cursors involving that table will be invalidated, and Oracle will not have correct statistics about that column untill the second gather_table_stats finishes. (Note: in 9i, the default value of method_opt parameter is 'FOR ALL COLUMNS SIZE 1', in 10g, it has been changed to 'FOR ALL COLUMNS SIZE AUTO')

Possible solutions:

(1) Keep the second step, change the first step to the use following command:
exec dbms_stats.gather_table_stats('MY_SCHM','MY_TAB', -
estimate_percent =>20, -
cascade => TRUE,degree => 16, -
no_invalidate=>true);

By specifying no_invalidate=>true, we tell Oracle not to invalidate the cursor currently in the shared pool.

(2) Combine the two steps into one, as shown here:

exec dbms_stats.gather_table_stats('MY_SCHM','MY_TAB', -
estimate_percent =>20, -
method_opt => 'FOR COLUMNS SIZE auto MY_TAB_ID, FOR ALL COLUMNS size 1',-
cascade => TRUE,degree => 16);


The following test demonstrated that we can have several 'FOR COLUMNS' for the method_opt parameter

SQL> create table t
  2  as
  3  select
  4    level c1,
  5    trunc(level/20) c2,
  6    level+ 5 c3,
  7    trunc(dbms_random.value(1, 100)) c4
  8  from dual
  9  connect by level <=5000;  Table created.  SQL>
SQL>
SQL>
SQL> begin
  2   dbms_stats.gather_table_stats(user,'T',
  3     method_opt => 'FOR COLUMNS size 10 c1, FOR columns size 20 c2, FOR COLUMNS size 5 c3, FOR ALL COLUMNS size 1');
  4  end;
  5  /

PL/SQL procedure successfully completed.

SQL>
SQL> select table_name, column_name, num_distinct, num_buckets,
  2  last_analyzed from user_tab_col_statistics where
  3  table_name='T';

TABLE_NAME COLUMN_NAME NUM_DISTINCT NUM_BUCKETS LAST_ANALYZED
---------- ----------- ------------ ----------- -------------------
T          C1                  5000          10 2009-05-25 09:26:39
T          C2                   251          20 2009-05-25 09:26:39
T          C3                  5000           5 2009-05-25 09:26:39
T          C4                    99           1 2009-05-25 09:26:39

FGA and bind values

In a 9i production database, from time to time, we see long blocking/blocked sessions that make the application slow down noticably. We were able to provide the SQLs that the blocking sessions excuted. However, when asked to proivde bind values of those SQLs, we were out of luck. Inspired by Dion's post, I looked at the possibilities of using FGA to find the bind values. At the end of some testing, however, I should say no luck with 9i database still.

In 10g version, it is possible to get bind values in the select, update, delete and insert statements, however, in 9i only select is supported.

My test in 10g is shown as follows. It can be seen that we can obtain the bind values for select, update, insert and delete statement.

(1) Create the table

zxxxx94@DBWRKEV1> create table t
  2  as
  3  select
  4   rownum id
  5  , owner
  6  , object_name
  7  , object_type
  8  , object_id
  9  , created
 10  from all_objects
 11  where rownum <=5000;  Table created.  zxxxx94@DBWRKEV1>
zxxxx94@DBWRKEV1> alter table t add constraint t_pk primary key(id);

Table altered.

zxxxx94@DBWRKEV1>
zxxxx94@DBWRKEV1> begin
  2   dbms_stats.gather_table_stats(user, 'T', cascade=>true);
  3  end;
  4  /

PL/SQL procedure successfully completed.

(2) Add a FGA policy

zxxxx94@DBWRKEV1> begin
  2   dbms_fga.add_policy (
  3       object_schema => user,
  4       object_name   => 'T',
  5       policy_name   => 'T_PLY2',
  6       audit_column  => 'ID',
  7       statement_types=> 'SELECT,UPDATE,DELETE,INSERT');
  8  end;
  9  /

(3) Issue select/update/insert/delete statements with bind variables

zxxxx94@DBWRKEV1>
zxxxx94@DBWRKEV1> variable id number
zxxxx94@DBWRKEV1> variable obj_name varchar2(20)
zxxxx94@DBWRKEV1> execute :id := 200

PL/SQL procedure successfully completed.

zxxxx94@DBWRKEV1> execute :obj_name := 'DENIS'

PL/SQL procedure successfully completed.

zxxxx94@DBWRKEV1>
zxxxx94@DBWRKEV1> select object_name from t where id = :id;

OBJECT_NAME
------------------------------
REFCON$

zxxxx94@DBWRKEV1>
zxxxx94@DBWRKEV1> execute :id := 100

PL/SQL procedure successfully completed.

zxxxx94@DBWRKEV1> update t set object_name=lower(object_name) where id = :id;

1 row updated.

zxxxx94@DBWRKEV1> delete from t where id = :id;

1 row deleted.

zxxxx94@DBWRKEV1>
zxxxx94@DBWRKEV1> execute :id := 5001

PL/SQL procedure successfully completed.

zxxxx94@DBWRKEV1> insert into t values( :id, 'OWNER', :obj_name,'TABLE',12345,sysdate);

1 row created.

zxxxx94@DBWRKEV1> commit;

Commit complete.

(4) Query DBA_FGA_AUDIT_TRAIL

zxxxx94@DBWRKEV1>
zxxxx94@DBWRKEV1> exec print_table( 'select * from dba_fga_audit_trail' );

(... cut ...)
-----------------
SESSION_ID                    : 2430
TIMESTAMP                     : 20-may-2009 12:01:50
DB_USER                       : Zxxxx94
OS_USER                       : Yu
USERHOST                      : MSHOME\NTBK
CLIENT_ID                     :
ECONTEXT_ID                   :
EXT_NAME                      :
OBJECT_SCHEMA                 : Zxxxx94
OBJECT_NAME                   : T
POLICY_NAME                   : T_PLY2
SCN                           : 167297644
SQL_TEXT                      : select object_name from t where id = :id
SQL_BIND                      :  #1(3):200
COMMENT$TEXT                  :
STATEMENT_TYPE                : SELECT
EXTENDED_TIMESTAMP            : 20-MAY-09 12.01.49.563831 PM -04:00
PROXY_SESSIONID               :
GLOBAL_UID                    :
INSTANCE_NUMBER               : 0
OS_PROCESS                    : 9035
TRANSACTIONID                 :
STATEMENTID                   : 156
ENTRYID                       : 2
-----------------
SESSION_ID                    : 2430
TIMESTAMP                     : 20-may-2009 12:01:52
DB_USER                       : Zxxxx94
OS_USER                       : Yu
USERHOST                      : MSHOME\NTBK
CLIENT_ID                     :
ECONTEXT_ID                   :
EXT_NAME                      :
OBJECT_SCHEMA                 : Zxxxx94
OBJECT_NAME                   : T
POLICY_NAME                   : T_PLY2
SCN                           : 167297646
SQL_TEXT                      : update t set object_name=lower(object_name) where id = :id
SQL_BIND                      :  #1(3):100
COMMENT$TEXT                  :
STATEMENT_TYPE                : UPDATE
EXTENDED_TIMESTAMP            : 20-MAY-09 12.01.52.465334 PM -04:00
PROXY_SESSIONID               :
GLOBAL_UID                    :
INSTANCE_NUMBER               : 0
OS_PROCESS                    : 9035
TRANSACTIONID                 : 0006000B000252F3
STATEMENTID                   : 160
ENTRYID                       : 3
-----------------
SESSION_ID                    : 2430
TIMESTAMP                     : 20-may-2009 12:01:53
DB_USER                       : Zxxxx94
OS_USER                       : Yu
USERHOST                      : MSHOME\NTBK
CLIENT_ID                     :
ECONTEXT_ID                   :
EXT_NAME                      :
OBJECT_SCHEMA                 : Zxxxx94
OBJECT_NAME                   : T
POLICY_NAME                   : T_PLY2
SCN                           : 167297649
SQL_TEXT                      : delete from t where id = :id
SQL_BIND                      :  #1(3):100
COMMENT$TEXT                  :
STATEMENT_TYPE                : DELETE
EXTENDED_TIMESTAMP            : 20-MAY-09 12.01.52.992022 PM -04:00
PROXY_SESSIONID               :
GLOBAL_UID                    :
INSTANCE_NUMBER               : 0
OS_PROCESS                    : 9035
TRANSACTIONID                 : 0006000B000252F3
STATEMENTID                   : 162
ENTRYID                       : 4
-----------------
SESSION_ID                    : 2430
TIMESTAMP                     : 20-may-2009 12:01:54
DB_USER                       : Zxxxx94
OS_USER                       : Yu
USERHOST                      : MSHOME\NTBK
CLIENT_ID                     :
ECONTEXT_ID                   :
EXT_NAME                      :
OBJECT_SCHEMA                 : Zxxxx94
OBJECT_NAME                   : T
POLICY_NAME                   : T_PLY2
SCN                           : 0
SQL_TEXT                      : insert into t values( :id, 'OWNER', :obj_name,'TABLE',12345,sysdate)
SQL_BIND                      :  #1(4):5001 #2(5):DENIS
COMMENT$TEXT                  :
STATEMENT_TYPE                : INSERT
EXTENDED_TIMESTAMP            : 20-MAY-09 12.01.53.973038 PM -04:00
PROXY_SESSIONID               :
GLOBAL_UID                    :
INSTANCE_NUMBER               : 0
OS_PROCESS                    : 9035
TRANSACTIONID                 : 0006000B000252F3
STATEMENTID                   : 166
ENTRYID                       : 5
-----------------

PL/SQL procedure successfully completed.

Find the session holding a library cache lock by examining the x$kgllk table

Metalink Note: 122793.1 "HOW TO FIND THE SESSION HOLDING A LIBRARY CACHE LOCK" describes two methods to find the blocking session:

1. SYSTEMSTAT analysis
2. Examine THE X$KGLLK TABLE

In a previous post, I practised method 1. In this post I demonstrate how to use method 2.

First, I created the following two scrpipts based on the note:

rem librarycache_blkng_sess.sql
rem   --  find the blocking session holding library cache lock
rem  input the SID of the session waiting for libary cache lock
rem

col saddr new_val SADDR_OF_BLOCKED_SESSION
select saddr  from v$session where sid= &sid;

col sid format 9999
col username format a15
col terminal format a10
col program format a15

SELECT SID,USERNAME,TERMINAL,PROGRAM FROM V$SESSION
WHERE SADDR in
(SELECT KGLLKSES FROM X$KGLLK LOCK_A
WHERE KGLLKREQ = 0
AND EXISTS (SELECT LOCK_B.KGLLKHDL FROM X$KGLLK LOCK_B
WHERE KGLLKSES = '&SADDR_OF_BLOCKED_SESSION'
AND LOCK_A.KGLLKHDL = LOCK_B.KGLLKHDL
AND KGLLKREQ > 0)
);

rem librarycache_blked_sess.sql
rem
rem    find the blocked sessions waiting for library cache lock
rem    input the SID of the bocking session
rem    run as sysdba
rem ref: ML122793.1

col saddr new_val SADDR_OF_BLKING_SESS
select saddr  from v$session where sid= &sid;

set linesize 120
col sid format 9999
col username format a15
col terminal format a10
col program format a15

SELECT SID,USERNAME,TERMINAL,PROGRAM FROM V$SESSION
WHERE SADDR in
(SELECT KGLLKSES FROM X$KGLLK LOCK_A
WHERE KGLLKREQ > 0
AND EXISTS (SELECT LOCK_B.KGLLKHDL FROM X$KGLLK LOCK_B
WHERE KGLLKSES = '&SADDR_OF_BLKING_SESS'
AND LOCK_A.KGLLKHDL = LOCK_B.KGLLKHDL
AND KGLLKREQ = 0)
);

Here is the screen output when using the above scripts in a testing database:

(1) Find the session currently waiting for library cache lock

SQL> @sess_by_event
Enter value for event: library

SECONDS      
SID Username   EVENT                       P1         P2  WAIT_TIME  IN WAIT STATE
---- ---------- ------------------- ---------- ---------- ---------- -------- ---------
160 DBSCRUB    library cache lock  1.6029E+10 1.5969E+10          0     2186 WAITING
260 DBSCRUB    library cache lock  1.6029E+10 1.5969E+10          0     2186 WAITING

(2) Find who is the blocker

SQL> @librarycache_blkng_sess.sql
Enter value for sid: 160
old   1: select saddr  from v$session where sid= &sid
new   1: select saddr  from v$session where sid= 160

SADDR
----------------
00000003B436BE98

old   6:                  WHERE KGLLKSES = '&SADDR_OF_BLOCKED_SESSION'
new   6:                  WHERE KGLLKSES = '00000003B436BE98'

SID USERNAME        TERMINAL   PROGRAM
----- --------------- ---------- ---------------
56 DBSCRUB

SQL> @librarycache_blkng_sess.sql
Enter value for sid: 260
old   1: select saddr  from v$session where sid= &sid
new   1: select saddr  from v$session where sid= 260

SADDR
----------------
00000003B43ADED8

old   6:                  WHERE KGLLKSES = '&SADDR_OF_BLOCKED_SESSION'
new   6:                  WHERE KGLLKSES = '00000003B43ADED8'

SID USERNAME        TERMINAL   PROGRAM
----- --------------- ---------- ---------------
56 DBSCRUB

It can be seen that the blocking session is sid=56

(3) Who is blocked by sid=56

SQL> @librarycache_blked_sess.sql
Enter value for sid: 56
old   1: select saddr  from v$session where sid= &sid
new   1: select saddr  from v$session where sid= 56

SADDR
----------------
00000003B4327418

old   6:                  WHERE KGLLKSES = '&SADDR_OF_BLKING_SESS'
new   6:                  WHERE KGLLKSES = '00000003B4327418'

SID USERNAME        TERMINAL   PROGRAM
----- --------------- ---------- ---------------
160 DBSCRUB
260 DBSCRUB

The above demonstrated that the scripts worked well as expected.

Resolving a library cache lock issue

In a testing database, I found there were three sessions waiting for library cache lock:

SECONDS
SID USERNAME   EVENT                             P1         P2  WAIT_TIME  IN WAIT STATE
------ ---------- ------------------------- ---------- ---------- ---------- -------- --------------
248 SYSTEM     library cache lock        1.6015E+10 1.5964E+10          0    41173 WAITING
97 DBSCRUB    library cache lock        1.6098E+10 1.5961E+10          0    29840 WAITING
85 DBSCRUB    library cache lock        1.5989E+10 1.5970E+10          0    27361 WAITING

I followed Metalink note: 122793.1 to find the sessions holding library cache locks by using systemstate analysis.

(1) Open a new session and launch the following statement:

ALETER SESSION SET EVENTS 'IMMEDIATE TRACE NAME SYSTEMSTATE LEVEL 10';

Oracle will create a systemstate tracefile in the USER_DUMP_DEST directory.

(2) Obtain Oracle process PID of the hanging session by the following statement:

SELECT PID FROM V$PROCESS WHERE ADDR=
(SELECT PADDR FROM V$SESSION WHERE SID=&sid_of_hanging_session);

In my case, sid=248, I obtained pid=16

(3) Search PROCESS 16 in the trace file, in the "wait for" line we can obtain the 'handle address':
e.g.

PROCESS 16:
----------------------------------------
SO: 3b41ad6f8, type: 2, owner: 0, flag: INIT/-/-/0x00
(process) Oracle pid=16, calls cur/top: 3b46e43c8/3b46e43c8, flag: (0) -
int error: 0, call error: 0, sess error: 0, txn error 0
(post info) last post received: 0 0 0
last post received-location: No post
( .. cut ...)

waiting for 'library cache lock' blocking sess=0x0 seq=13718 wait_time=0
handle address=3ba93b8b0, lock address=3b78e1880, 100*mode+namespace=c9
temporary object counter: 0

(4) Search the handle address (3ba93b8b0) to find the Oracle process pid, then based on the pid, find the session sid that is holding the library cache lock:
select sid from v$session where paddr =
( select addr from v$process where pid=&pid);

(5) After killing the session holding the library cache lock, the wait event is gone.


This testing database is refreshed every Saturday morning by imp. During refreshing it should be shutdown and re-startup first. However, I found the logon time of the sessions holding the library lock is earlier than last Saturday. So I checked the alert log, found the following line:

...
Active call for process 28031 user 'oracle' program 'oracle@bxxxqsd2 (TNS V1-V3)'
Active call for process 17980 user 'oracle' program 'oracle@bxxxqsd2 (TNS V1-V3)'
SHUTDOWN: waiting for active calls to complete.
Sat May 16 07:56:31 2009
SHUTDOWN: Active sessions prevent database close operation
Starting ORACLE instance (normal)
Sat May 16 07:58:02 2009

It showed that the db had not been shutdown at all. Failed to close the database due to active calls. Next Saturdy I will shutdown it manually.


The Metalink note also describes some situations that can cause the library cache lock:

* A DML operation that is hanging because the table which is accessed is currently
undergoing changes (ALTER TABLE). This may take quite a long time depending on
the size of the table and the type of the modification
(e.g. ALTER TABLE x MODIFY (col1 CHAR(200) on thousands of records).

* The compilation of package will hang on Library Cache Lock and Library Cache Pin
if some users are executing any Procedure/Function defined in the same package.

Another method to find the session holding library cache lock is described here.

Check the content of the script before executing in production database

Last weekend, I supported the code release in a production database. There were 39 scripts to be executed. When I executed the 9th script, strange thing happened. Lots of scripts got executed which should not at that stage. This caused extra time to fix the mess. Checking the content of this script, I found that there are strange characters and some other scripts's content. I recalled that I tarred the whole scripts before I uploaded to the server. When I did the tar at the first time I issued the wrong syntax without providing the target file name. That was probably the reason that caused the 9th script garbged.

Bottom line is I should check the content of every script that is going to be dropped in the prodcution database. This is a big lesson.

Bulk collect limit clause and %NOTFOUND

Recently I have learned that when using limit clause in the bulk collect, if one sets limit to be N, and if Oralce is unable to fetch N records from the cursor C (even being able to fetch N-1 records), then Oracle will evaluate C%NOTFOUND to TRUE.

Steven Feuerstein has a good article on this topic: http://www.oracle.com/technology/oramag/oracle/08-mar/o28plsql.html .

The whole story can be seen in my post on Oracle-PLSQL google group:
http://groups.google.com/group/Oracle-PLSQL/browse_thread/thread/3928ff1d0a4fad50