system waits for "library cache pin" 
Author Message
 system waits for "library cache pin"

Hello.
We have a problem with an insert statement that suddenly started to run
very slow after about 350000 inserts. I run utlstat, and it showed a
high wait for "library cache pin".

Event Name                       Count     Total Time    Avg Time    
-------------------------------- --------- ------------- -------------
SQL*Net message from client           1981       3434781       1733.86
library cache pin                    10320        426594         41.34

Article 62161.1 on MetaLink had the following suggestions:

Run this query to see if the waits are always for a single "handle".

SQL> r
  1* select p1 "Handle" from v$session_wait
     where event = 'library cache pin'

    Handle
----------
2382918416
2382918416
2382918416
2382918416
2382918416
2382918416
2382918416
2382918416
2382918416
2382918416
2382918416

11 rows selected.

SQL> r
  1* select p1 "Handle" from v$session_wait
     where event = 'library cache pin'

    Handle
----------
2382918416
2382918416
2382918416
2382918416
2382918416
2382918416
2382918416
2365896684
2382918416

As you can see the waits are always for the same handle.

Then the article suggested to isolate statements with high version
counts, so I did:

SQL> r
  1  select address, to_char(hash_value,'9999999999999'),
     version_count,sql_text
  2  from v$sqlarea
  3  where version_count>10
  4* order by version_count

ADDRESS  TO_CHAR(HASH_V VERSION_COUNT
-------- -------------- -------------
SQL_TEXT
---------------------------------------------------------------------------
8E087310      760830653            55
insert into
table_name(a1,a2,a3,a4,a5,a6,a7,a8,a9,a10,a11,a12,a13,a14,a15,a16,a17,a18,
a19,a20,a21,a22,a23,a24,a25,a26,a27,a28)
values (to_number(
:b0),:b1,to_date(:b2,'YYYYMMDD HH24MISS'),to_number(:b3),
to_date(:b4,'YYYYMMDD HH24MISS'),:b5,:b6,:b7,:b8,:b9,:b10,
to_date(:b11,'YYYYMMDD HH24MISS'),:b12,:b13,:b14,:b15,
to_number(:b16),to_number(:b17),to_number(:b18),
to_number(:b19),to_number(:b20),to_number(:b21),to_number(:b22),
to_number(:b23),to_number(:b24),to_number(:b25),to_number(:b26),
to_number(:b27),:b28)

This is the statements that suddenly started to run very slow. It takes
several seconds to complete.

I flushed the shared pool and retried the operation, and the statement
immediately showed up with a version count of 39, and it's increasing.

We are running Oracle EE version 8.1.5 on Sun SPARC Solaris 2.6. The
program doing the inserts is a Pro*C program (version 7.3.4). There are
severel instanses of this program running simultaneously
executing the same insert statement. I should also mention that the
table is partitioned.

A trace of one of the session showed the following:

insert into table_name
(a1,a2,a3,a4,a5,a6,a7,a8,a9,a10,a11,a12,a13,a14,a15,
a16,a17,a18,a19,a20,a21,a22,a23,a24,a25,a26,a27,a28)
values
 (to_number(:b0),:b1,to_date(:b2,'YYYYMMDD HH24MISS'),to_number(:b3),
  to_date(:b4,'YYYYMMDD HH24MISS'),:b5,:b6,:b7,:b8,:b9,:b10,to_date(:b11,
  'YYYYMMDD HH24MISS'),:b12,:b13,:b14,:b15,to_number(:b16),to_number(:b17),
  to_number(:b18),to_number(:b19),to_number(:b20),to_number(:b21),
  to_number(:b22),to_number(:b23),to_number(:b24),to_number(:b25),
  to_number(:b26),to_number(:b27),:b28)

call     count       cpu    elapsed   disk    query    current    rows
------- ------  -------- ---------- ------ -------- ----------  ------
Parse       41      0.35      28.51      0        0          0       0
Execute     41      0.32       0.40      0       41        410       0
Fetch        0      0.00       0.00      0        0          0       0
------- ------  -------- ---------- ------ -------- ----------  ------
total       82      0.67      28.91      0       41        410       0

Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 23  

Does anyone have an idea what could cause this problem?

--
Regards
Thor-Ivar Skofsrud
Nextra AS



Sat, 20 Jul 2002 03:00:00 GMT
 system waits for "library cache pin"



Quote:
>Hello.
>We have a problem with an insert statement that suddenly started to run
>very slow after about 350000 inserts. I run utlstat, and it showed a
>high wait for "library cache pin".

>Event Name                       Count     Total Time    Avg Time    
>-------------------------------- --------- ------------- -------------
>SQL*Net message from client           1981       3434781       1733.86
>library cache pin                    10320        426594         41.34

>Article 62161.1 on MetaLink had the following suggestions:

>Run this query to see if the waits are always for a single "handle".

>SQL> r
>  1* select p1 "Handle" from v$session_wait
>     where event = 'library cache pin'

>    Handle
>----------
>2382918416
>2382918416
>2382918416
>2382918416
>2382918416
>2382918416
>2382918416
>2382918416
>2382918416
>2382918416
>2382918416

>11 rows selected.

>SQL> r
>  1* select p1 "Handle" from v$session_wait
>     where event = 'library cache pin'

>    Handle
>----------
>2382918416
>2382918416
>2382918416
>2382918416
>2382918416
>2382918416
>2382918416
>2365896684
>2382918416

>As you can see the waits are always for the same handle.

>Then the article suggested to isolate statements with high version
>counts, so I did:

>SQL> r
>  1  select address, to_char(hash_value,'9999999999999'),
>     version_count,sql_text
>  2  from v$sqlarea
>  3  where version_count>10
>  4* order by version_count

>ADDRESS  TO_CHAR(HASH_V VERSION_COUNT
>-------- -------------- -------------
>SQL_TEXT
>---------------------------------------------------------------------------
>8E087310      760830653            55
>insert into
>table_name(a1,a2,a3,a4,a5,a6,a7,a8,a9,a10,a11,a12,a13,a14,a15,a16,a17,a18,
>a19,a20,a21,a22,a23,a24,a25,a26,a27,a28)
>values (to_number(
>:b0),:b1,to_date(:b2,'YYYYMMDD HH24MISS'),to_number(:b3),
>to_date(:b4,'YYYYMMDD HH24MISS'),:b5,:b6,:b7,:b8,:b9,:b10,
>to_date(:b11,'YYYYMMDD HH24MISS'),:b12,:b13,:b14,:b15,
>to_number(:b16),to_number(:b17),to_number(:b18),
>to_number(:b19),to_number(:b20),to_number(:b21),to_number(:b22),
>to_number(:b23),to_number(:b24),to_number(:b25),to_number(:b26),
>to_number(:b27),:b28)

>This is the statements that suddenly started to run very slow. It takes
>several seconds to complete.

>I flushed the shared pool and retried the operation, and the statement
>immediately showed up with a version count of 39, and it's increasing.

>We are running Oracle EE version 8.1.5 on Sun SPARC Solaris 2.6. The
>program doing the inserts is a Pro*C program (version 7.3.4). There are
>severel instanses of this program running simultaneously
>executing the same insert statement. I should also mention that the
>table is partitioned.

>A trace of one of the session showed the following:

>insert into table_name
>(a1,a2,a3,a4,a5,a6,a7,a8,a9,a10,a11,a12,a13,a14,a15,
>a16,a17,a18,a19,a20,a21,a22,a23,a24,a25,a26,a27,a28)
>values
> (to_number(:b0),:b1,to_date(:b2,'YYYYMMDD HH24MISS'),to_number(:b3),
>  to_date(:b4,'YYYYMMDD HH24MISS'),:b5,:b6,:b7,:b8,:b9,:b10,to_date(:b11,
>  'YYYYMMDD HH24MISS'),:b12,:b13,:b14,:b15,to_number(:b16),to_number(:b17),
>  to_number(:b18),to_number(:b19),to_number(:b20),to_number(:b21),
>  to_number(:b22),to_number(:b23),to_number(:b24),to_number(:b25),
>  to_number(:b26),to_number(:b27),:b28)

>call     count       cpu    elapsed   disk    query    current    rows
>------- ------  -------- ---------- ------ -------- ----------  ------
>Parse       41      0.35      28.51      0        0          0       0
>Execute     41      0.32       0.40      0       41        410       0
>Fetch        0      0.00       0.00      0        0          0       0
>------- ------  -------- ---------- ------ -------- ----------  ------
>total       82      0.67      28.91      0       41        410       0

>Misses in library cache during parse: 0
>Optimizer goal: CHOOSE
>Parsing user id: 23  

>Does anyone have an idea what could cause this problem?

>--
>Regards
>Thor-Ivar Skofsrud
>Nextra AS

Somehow the cursor is closed AND released. This forces a reparse. You
can see your statement is executed 41 times and parsed 41 times, and
it contains all host variables, so the parses are completely
redundant.
In previous versions of the Pro* products you had the compiler
switches
HOLD_CURSOR=Y RELEASE_CURSOR=N

I don't know whether they still exist.
You could also try to change the init<sid>.ora
parameter session_cached_cursors to say 50, though I seem to remember
this parameter has been made obsolete in one of the newer releases.
Definitely your problem is parsing.

Hth,

Sybrand Bakker, Oracle DBA



Sat, 20 Jul 2002 03:00:00 GMT
 system waits for "library cache pin"
Hello Thor-Ivar,

This looks like bug number 315199 in which references to remote objects
via a synonym and database link were not recognized as identical, and
resulted in spiraling version counts. In that case, the workaround was
to use a fully-qualified reference.

It may be that a similar bug has been re-introduced. I suggest you
contact Oracle support.

Regards,
Steve Adams
http://www.ixora.com.au/
http://www.oreilly.com/catalog/orinternals/
http://www.christianity.net.au/



Quote:
>Hello.
>We have a problem with an insert statement that suddenly started to run
>very slow after about 350000 inserts. I run utlstat, and it showed a
>high wait for "library cache pin".

>Event Name                       Count     Total Time    Avg Time    
>-------------------------------- --------- ------------- -------------
>SQL*Net message from client           1981       3434781       1733.86
>library cache pin                    10320        426594         41.34

>Article 62161.1 on MetaLink had the following suggestions:

>Run this query to see if the waits are always for a single "handle".

>SQL> r
>  1* select p1 "Handle" from v$session_wait
>     where event = 'library cache pin'

>    Handle
>----------
>2382918416
>2382918416
>2382918416
>2382918416
>2382918416
>2382918416
>2382918416
>2382918416
>2382918416
>2382918416
>2382918416

>11 rows selected.

>SQL> r
>  1* select p1 "Handle" from v$session_wait
>     where event = 'library cache pin'

>    Handle
>----------
>2382918416
>2382918416
>2382918416
>2382918416
>2382918416
>2382918416
>2382918416
>2365896684
>2382918416

>As you can see the waits are always for the same handle.

>Then the article suggested to isolate statements with high version
>counts, so I did:

>SQL> r
>  1  select address, to_char(hash_value,'9999999999999'),
>     version_count,sql_text
>  2  from v$sqlarea
>  3  where version_count>10
>  4* order by version_count

>ADDRESS  TO_CHAR(HASH_V VERSION_COUNT
>-------- -------------- -------------
>SQL_TEXT
>---------------------------------------------------------------------------
>8E087310      760830653            55
>insert into
>table_name(a1,a2,a3,a4,a5,a6,a7,a8,a9,a10,a11,a12,a13,a14,a15,a16,a17,a18,
>a19,a20,a21,a22,a23,a24,a25,a26,a27,a28)
>values (to_number(
>:b0),:b1,to_date(:b2,'YYYYMMDD HH24MISS'),to_number(:b3),
>to_date(:b4,'YYYYMMDD HH24MISS'),:b5,:b6,:b7,:b8,:b9,:b10,
>to_date(:b11,'YYYYMMDD HH24MISS'),:b12,:b13,:b14,:b15,
>to_number(:b16),to_number(:b17),to_number(:b18),
>to_number(:b19),to_number(:b20),to_number(:b21),to_number(:b22),
>to_number(:b23),to_number(:b24),to_number(:b25),to_number(:b26),
>to_number(:b27),:b28)

>This is the statements that suddenly started to run very slow. It takes
>several seconds to complete.

>I flushed the shared pool and retried the operation, and the statement
>immediately showed up with a version count of 39, and it's increasing.

>We are running Oracle EE version 8.1.5 on Sun SPARC Solaris 2.6. The
>program doing the inserts is a Pro*C program (version 7.3.4). There are
>severel instanses of this program running simultaneously
>executing the same insert statement. I should also mention that the
>table is partitioned.

>A trace of one of the session showed the following:

>insert into table_name
>(a1,a2,a3,a4,a5,a6,a7,a8,a9,a10,a11,a12,a13,a14,a15,
>a16,a17,a18,a19,a20,a21,a22,a23,a24,a25,a26,a27,a28)
>values
> (to_number(:b0),:b1,to_date(:b2,'YYYYMMDD HH24MISS'),to_number(:b3),
>  to_date(:b4,'YYYYMMDD HH24MISS'),:b5,:b6,:b7,:b8,:b9,:b10,to_date(:b11,
>  'YYYYMMDD HH24MISS'),:b12,:b13,:b14,:b15,to_number(:b16),to_number(:b17),
>  to_number(:b18),to_number(:b19),to_number(:b20),to_number(:b21),
>  to_number(:b22),to_number(:b23),to_number(:b24),to_number(:b25),
>  to_number(:b26),to_number(:b27),:b28)

>call     count       cpu    elapsed   disk    query    current    rows
>------- ------  -------- ---------- ------ -------- ----------  ------
>Parse       41      0.35      28.51      0        0          0       0
>Execute     41      0.32       0.40      0       41        410       0
>Fetch        0      0.00       0.00      0        0          0       0
>------- ------  -------- ---------- ------ -------- ----------  ------
>total       82      0.67      28.91      0       41        410       0

>Misses in library cache during parse: 0
>Optimizer goal: CHOOSE
>Parsing user id: 23  

>Does anyone have an idea what could cause this problem?

>--
>Regards
>Thor-Ivar Skofsrud
>Nextra AS



Sun, 21 Jul 2002 03:00:00 GMT
 
 [ 3 post ] 

 Relevant Pages 

1. Library cache pin Wait

2. max of ("...","...","..")

3. Library Cache Pin problems

4. Persistent library cache pin

5. Query Optimizing with "CREATE CACHE" and "WITH CACHE"

6. Query in "exchange" in wait type

7. Wait Type "miscellaneous"

8. "Waiting for a worker Thread"

9. stupid Q regarding "UPDATE waiting"

10. Help with a "wait" interval

11. Urgent - startup problem "ORA-27146: post/wait initialization failed"-Error

12. "LOCK MODE TO WAIT" seemingly ignored


 
Powered by phpBB® Forum Software