【案例】Oracle等待事件library cache lock产生原因和解决办法

时间:2016-12-07 18:56   来源:Oracle研究中心   作者:网络   点击:

次

天萃荷净

Oracle研究中心案例分析：运维DBA发现Oracle数据库出现library cache lock等待事件导致cpu使用非常高，结合案例来解决此等待事件。

本站文章除注明转载外，均为本站原创： 转载自love wife & love life —Roger 的Oracle技术博客

本文链接地址: soft parse 和 library cache lock

同事遇到一个library cache lock lath等待事件的问题，导致cpu使用非常高，关于library cache lock似乎存在一点争议，我这里用实验来进行说明。

---session 1

SQL> oradebug setmypid

Statement processed.‘

SQL> SELECT ADDR,latch#,LEVEL#,name  FROM V$latchWHERE name LIKE '%library cache%';

ADDR         LATCH#     LEVEL# NAME

-------- ---------- ---------- --------------------------------------------------

200107DC        217          5 library cache

20010840        218          6 library cache LOCK

200109D0        222          5 library cache LOAD LOCK

20010908        220          3 library cache pin allocation

20010A34        223          9 library cache hash chains

2001096C        221          3 library cache LOCK allocation

200108A4        219          6 library cache pin

7 ROWS selected.

SQL> oradebug peek 0x20010840 200

[20010840, 20010908) = 00000000 00000000 000000DA 00000006 00000000 00000000

00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 ...

SQL>  oradebug peek 0x200108A4 200

[200108A4, 2001096C) = 00000000 00000000 000000DB 00000006 00000000 00000000

00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 ...

SQL> SELECT 'oradebug poke 0x' || addr || ' 4 0x00000001' FROMv$latch_children WHERE name='library cache lock';

'ORADEBUGPOKE0X'||ADDR||'40X00000001'

-------------------------------------

oradebug poke 0x287C75F8 4 0x00000001

SQL> SELECT 'oradebug poke 0x' || addr || ' 4 0x00000001' FROMv$latch_children WHERE name='library cache pin';

'ORADEBUGPOKE0X'||ADDR||'40X00000001'

-------------------------------------

oradebug poke 0x287C7594 4 0x00000001

SQL> oradebug poke 0x287C75F8 4 1

BEFORE: [287C75F8, 287C75FC) = 00000000

AFTER:  [287C75F8, 287C75FC) = 00000001

SQL> oradebug poke 0x287C7594 4 1

BEFORE: [287C7594, 287C7598) = 00000000

AFTER:  [287C7594, 287C7598) = 00000001

---session 2

SQL> SHOW USER

USER IS "ROGER"

SQL> ALTER system FLUSH shared_pool;

System altered.

SQL> SELECT * FROM roger WHERE id=100 AND rownum < 3;

----hang住

---session 3

SQL> SHOW USER

USER IS "SYS"

SQL>  SELECT s.sid,s.serial#,p.spid FROM v$process p,v$session s WHERE p.addr=s.paddr AND

2  s.username='ROGER';

SID    SERIAL# SPID

---------- ---------- ------------

145          4 11649

SQL>  oradebug setospid 11649

Oracle pid: 21, Unix process pid: 11649, image: oracle@oracleplus.net (TNS V1-V3)

SQL>  oradebug dump processstate 8

Statement processed.

SQL> oradebug tracefile_name

/home/ora10g/admin/roger/udump/roger_ora_11649.trc

trace如下：

Process global information:

process: 0x29e2ffec, call: 0x29f48a90, xact: (nil), curses: 0x29f18e94, usrses: 0x29f18e94

----------------------------------------

SO: 0x29e2ffec, type: 2, owner: (nil), flag: INIT/-/-/0x00

(process) Oracle pid=21, calls cur/top: 0x29f48a90/0x29f48a90, flag: (0) -

int error: 0, call error: 0, sess error: 0, txn error 0

(post info) last post received: 110 0 4

last post received-location: kslpsr

last process to post me: 29e2a970 1 6

last post sent: 0 0 24

last post sent-location: ksasnd

last process posted by me: 29e2a970 1 6

(latch info) wait_event=0 bits=0

Location from where call was made: kgllkdl: child: cleanup: latch

waiting for 287c75f8 Child library cache lock level=6 child#=1

Location from where latch is held: No latch:

Context saved from call: 0

state=busy, wlstate=free

waiters [orapid (seconds since: put on list, posted, alive check)]:

10 (15, 1341052397, 15)

21 (6, 1341052397, 6)

11 (3, 1341052397, 3)

waiter count=3

gotten 53797 times wait, failed first 14 sleeps 16

gotten 0 times nowait, failed: 0

on wait list for 287c75f8

可以看到在等待library cache lock latch。

---session 1

释放library cache LOCK latch

SQL> oradebug poke 0x287C75F8 4 0

BEFORE: [287C75F8, 287C75FC) = 000000FF

AFTER:  [287C75F8, 287C75FC) = 00000000

---session 3

SQL> oradebug setospid 11649

Oracle pid: 21, Unix process pid: 11649, image: oracle@oracleplus.net (TNS V1-V3)

SQL> oradebug dump processstate 8

Statement processed.

SQL> oradebug tracefile_name

/home/ora10g/admin/roger/udump/roger_ora_11649.trc

trace如下：

Process global information:

process: 0x29e2ffec, call: 0x29f48a90, xact: (nil), curses: 0x29f18e94, usrses: 0x29f18e94

----------------------------------------

SO: 0x29e2ffec, type: 2, owner: (nil), flag: INIT/-/-/0x00

(process) Oracle pid=21, calls cur/top: 0x29f48a90/0x29f48a90, flag: (0) -

int error: 0, call error: 0, sess error: 0, txn error 0

(post info) last post received: 110 0 4

last post received-location: kslpsr

last process to post me: 29e2a970 1 6

last post sent: 0 0 24

last post sent-location: ksasnd

last process posted by me: 29e2a970 1 6

(latch info) wait_event=0 bits=0

Location from where call was made: kglpnal: child: alloc space: latch

waiting for 287c7594 Child library cache pin level=6 child#=1

Location from where latch is held: kglpndl: child

Context saved from call: 0

state=busy, wlstate=free

waiters [orapid (seconds since: put on list, posted, alive check)]:

10 (24, 1341052547, 24)

21 (24, 1341052547, 24)

11 (24, 1341052547, 24)

12 (24, 1341052547, 24)

waiter count=4

gotten 14922 times wait, failed first 11 sleeps 12

gotten 0 times nowait, failed: 0

on wait list for 287c7594

可以看到在等待library cache pin latch。

---session 1

释放library cache pin latch

SQL>  oradebug poke 0x287C7594 4 0

BEFORE: [287C7594, 287C7598) = 000000FF

AFTER:  [287C7594, 287C7598) = 00000000

----session 2

SQL> select * from roger where id=100 and rownum < 3;

ID

----------

100

100

---这里原本是hang住的，当释放latch以后，执行完成下面再次执行该sql，来看看软解析的情况是怎么样的？

-----session 1

SQL>  oradebug poke 0x287C75F8 4 1

BEFORE: [287C75F8, 287C75FC) = 00000000

AFTER:  [287C75F8, 287C75FC) = 00000001

SQL> oradebug poke 0x287C7594 4 1

BEFORE: [287C7594, 287C7598) = 00000000

AFTER:  [287C7594, 287C7598) = 00000001

----session 2

SQL> SELECT * FROM roger WHERE id=100 AND rownum < 3;

---再次hang住

-----session3

[root@oracleplus~]# cat /home/ora10g/admin/roger/udump/roger_ora_11649.trc | grep "library cache"

waiting for 287c75f8 Child library cache lock level=6 child#=1

waiting for 'latch: library cache lock' wait_time=0, seconds since wait started=6

waited for 'latch: library cache lock', seq_num: 30

longest_non_idle_wait: 'latch: library cache lock'

waiting for 287c7594 Child library cache pin level=6 child#=1

waiting for 'latch: library cache pin' wait_time=0, seconds since wait started=24

for 'latch: library cache lock' count=1 wait_time=2 min 0 sec

for 'latch: library cache lock' count=1 wait_time=5.177851 sec

for 'latch: library cache lock' count=1 wait_time=5.917101 sec

waited for 'latch: library cache lock', seq_num: 32

longest_non_idle_wait: 'latch: library cache lock'

waiting for 287c75f8 Child library cache lock level=6 child#=1

waiting for 'latch: library cache lock' wait_time=0, seconds since wait started=24

for 'latch: library cache pin' count=1 wait_time=2 min 8 sec

for 'latch: library cache pin' count=1 wait_time=3.237725 sec

for 'latch: library cache pin' count=1 wait_time=23.357272 sec

for 'latch: library cache lock' count=1 wait_time=2 min 0 sec

for 'latch: library cache lock' count=1 wait_time=5.177851 sec

for 'latch: library cache lock' count=1 wait_time=5.917101 sec

可以看到，软解析仍然会申请library cache lock latch.

----session 1

SQL> oradebug poke 0x287C75F8 4 0

BEFORE: [287C75F8, 287C75FC) = 000000FF

AFTER:  [287C75F8, 287C75FC) = 00000000

----session 3

SQL> oradebug dump processstate 8

Statement processed.

trace内容如下：

[root@oracleplus~]#  cat /home/ora10g/admin/roger/udump/roger_ora_11649.trc|grep "library cache"

waiting for 287c75f8 Child library cache lock level=6 child#=1

waiting for 'latch: library cache lock' wait_time=0, seconds since wait started=6

waited for 'latch: library cache lock', seq_num: 30

longest_non_idle_wait: 'latch: library cache lock'

waiting for 287c7594 Child library cache pin level=6 child#=1

waiting for 'latch: library cache pin' wait_time=0, seconds since wait started=24

for 'latch: library cache lock' count=1 wait_time=2 min 0 sec

for 'latch: library cache lock' count=1 wait_time=5.177851 sec

for 'latch: library cache lock' count=1 wait_time=5.917101 sec

waited for 'latch: library cache lock', seq_num: 32

longest_non_idle_wait: 'latch: library cache lock'

waiting for 287c75f8 Child library cache lock level=6 child#=1

waiting for 'latch: library cache lock' wait_time=0, seconds since wait started=24

for 'latch: library cache pin' count=1 wait_time=2 min 8 sec

for 'latch: library cache pin' count=1 wait_time=3.237725 sec

for 'latch: library cache pin' count=1 wait_time=23.357272 sec

for 'latch: library cache lock' count=1 wait_time=2 min 0 sec

for 'latch: library cache lock' count=1 wait_time=5.177851 sec

for 'latch: library cache lock' count=1 wait_time=5.917101 sec

waiting for 287c7594 Child library cache pin level=6 child#=1

waiting for 'latch: library cache pin' wait_time=0, seconds since wait started=3427

for 'latch: library cache lock' count=1 wait_time=38 min 23 sec

for 'latch: library cache lock' count=1 wait_time=23.913215 sec

for 'latch: library cache pin' count=1 wait_time=2 min 8 sec

for 'latch: library cache pin' count=1 wait_time=3.237725 sec

for 'latch: library cache pin' count=1 wait_time=23.357272 sec

for 'latch: library cache lock' count=1 wait_time=2 min 0 sec

手工释放library cache lock latch以后，发现还好等待library cache pin latch。

下面继续来证明软解析获得library cache lock是什么模式呢？

---session 1

[ora10g@oracleplus~]$ sqlplus roger/roger

SQL*Plus: Release 10.2.0.5.0 - Production ON Fri Jun 29 22:32:53 2012

Copyright (c) 1982, 2010, Oracle.  ALL Rights Reserved.

Connected TO:

Oracle DATABASE 10g Enterprise Edition Release 10.2.0.5.0 - Production

WITH the Partitioning, OLAP, DATA Mining AND REAL Application Testing options

SQL> DROP TABLE killdb;

TABLE dropped.

SQL> CREATE TABLE oracleplusAS SELECT object_id FROM dba_objects;

TABLE created.

SQL> SELECT * FROM oracleplusWHERE object_id=1000;

OBJECT_ID

----------

1000

SQL> SELECT hash_value,sql_text FROM v$sqlarea WHERE sql_text LIKE 'select * from killdb%';

HASH_VALUE

----------

SQL_TEXT

--------------------------------------------------------------------------------

368615450

SELECT * FROM oracleplusWHERE object_id=1000

SQL> SELECT to_char(368615450,'xxxxxxxxxx') FROM dual;

TO_CHAR(368

-----------

15f8a01a

SQL> SELECT to_number('a01a2030','xxxxxxxxxxxxxxxx') FROM dual;

TO_NUMBER('A01A2030','XXXXXXXXXXXXXXXX')

----------------------------------------

2686066736

SQL> ALTER system FLUSH shared_pool;

System altered.

----session 2

SQL> conn /AS sysdba

Connected.

SQL> SELECT sid FROM SELECT s.sid,s.serial#,p.spid FROM v$process p,v$session s WHERE p.addr=s.paddr AND

SQL> SELECT s.sid,s.serial#,p.spid FROM v$process p,v$session s WHERE p.addr=s.paddr AND

2  s.uhttp://www.oracleplus.netsername='ROGER';

SID    SERIAL# SPID

---------- ---------- ------------

140         29 3490

SQL> oradebug setospid 3490

Oracle pid: 24, Unix process pid: 3490, image: oracle@oracleplus.net (TNS V1-V3)

SQL> oradebug event 10049 trace name context forever,level 2686066736;

Statement processed.

----session 1

SQL> SELECT * FROM oracleplusWHERE object_id=1000;

OBJECT_ID

----------

1000

—session 2

SQL> oradebug tracefile_name

/home/ora10g/admin/roger/udump/roger_ora_3490.trc

trace 内容如下：

*** 2012-06-29 22:36:37.753

*** ACTION NAME:() 2012-06-29 22:36:37.719

*** MODULE NAME:(SQL*Plus) 2012-06-29 22:36:37.719

*** SERVICE NAME:(SYS$USERS) 2012-06-29 22:36:37.719

*** SESSION ID:(140.29) 2012-06-29 22:36:37.719

Received ORADEBUG command 'event 10049 trace name context forever,level 2686066736' from process Unix process pid: 3447, image:

KGLTRCLCK kgllkal    hd = 0x0x26336978  KGL Lock addr = 0x0x27fb9f80 mode = N

KGLTRCLCK kglget     hd = 0x0x26336978  KGL Lock addr = 0x0x27fb9f80 mode = N

KGLTRCPIN kglpin     hd = 0x0x26336978  KGL Pin  addr = 0x0x27fa004c mode = X

KGLTRCPIN kglpndl    hd = 0x0x26336978  KGL Pin  addr = 0x0x27fa004c mode = X

KGLTRCLCK kgllkal    hd = 0x0x2991982c  KGL Lock addr = 0x0x27fbbaf4 mode = N

KGLTRCLCK kglget     hd = 0x0x2991982c  KGL Lock addr = 0x0x27fbbaf4 mode = N

KGLTRCPIN kglpin     hd = 0x0x2991982c  KGL Pin  addr = 0x0x27bafd14 mode = X

KGLTRCPIN kglpndl    hd = 0x0x2991982c  KGL Pin  addr = 0x0x27bafd14 mode = X

*** 2012-06-29 22:36:50.912

Received ORADEBUG command 'tracefile_name' from process Unix process pid: 3447, image:

—-session 1

SQL> select * from oraclepluswhere object_id=1000;

OBJECT_ID

----------

1000

SQL> 再次执行该sql，来观察软解析的情况

---session 2

SQL>  oradebug event 10049 trace name context forever,level 2686066736;

Statement processed.

SQL> oradebug tracefile_name

/home/ora10g/admin/roger/udump/roger_ora_3490.trc

此时trace信息如下：

Received ORADEBUG command 'tracefile_name' from process Unix process pid: 3447, image:

*** 2012-06-29 22:42:32.468

Received ORADEBUG command 'event 10049 trace name context forever,level 2686066736' from process Unix process pid: 3447, image:

KGLTRCLCK kgllkdl    hd = 0x0x2991982c  KGL Lock addr = 0x0x27fbbaf4 mode = N

KGLTRCLCK kgllkdl2   hd = 0x0x2991982c  KGL Lock addr = 0x0x27fbbaf4 mode = 0

KGLTRCLCK kgllkdl    hd = 0x0x26336978  KGL Lock addr = 0x0x27fb9f80 mode = N

KGLTRCLCK kgllkdl2   hd = 0x0x26336978  KGL Lock addr = 0x0x27fb9f80 mode = 0

KGLTRCLCK kgllkal    hd = 0x0x26336978  KGL Lock addr = 0x0x27f95bc0 mode = N

KGLTRCLCK kglget     hd = 0x0x26336978  KGL Lock addr = 0x0x27f95bc0 mode = N

KGLTRCLCK kgllkal    hd = 0x0x2991982c  KGL Lock addr = 0x0x27fa6e84 mode = N

*** 2012-06-29 22:42:42.723

Received ORADEBUG command 'tracefile_name' from process Unix process pid: 3447, image:

[root@oracleplus~]#

SQL> col KGLNAOBJ FOR a65

SQL> SET LINES 200

SQL> SELECT kglhdadr,kglhdpar,kglnaobj FROM x$kglob WHERE LOWER(kglhdadr)='&aaa';

Enter VALUE FOR aaa: 26336978

OLD   1: SELECT kglhdadr,kglhdpar,kglnaobj FROM x$kglob WHERE LOWER(kglhdadr)='&aaa'

NEW   1: SELECT kglhdadr,kglhdpar,kglnaobj FROM x$kglob WHERE LOWER(kglhdadr)='26336978'

KGLHDADR KGLHDPAR KGLNAOBJ

-------- -------- -----------------------------------------------------------------

26336978 26336978 SELECT * FROM oracleplusWHERE object_id=1000

Enter VALUE FOR aaa: 2991982c

OLD   1: SELECT kglhdadr,kglhdpar,kglnaobj FROM x$kglob WHERE LOWER(kglhdadr)='&aaa'

NEW   1: SELECT kglhdadr,kglhdpar,kglnaobj FROM x$kglob WHERE LOWER(kglhdadr)='2991982c'

KGLHDADR KGLHDPAR KGLNAOBJ

-------- -------- -----------------------------------------------------------------

2991982C 26336978 SELECT * FROM oracleplusWHERE object_id=1000

我们可以看到此时的library cache lock是N模式，并没有X。

通过前面的实验，我们可以做出如下的几点总结：

1. sql的解析顺序是先library cache lock，然后是library cache pin。

2. 针对cursor获得的library cache lock mode是null，而不是X。

3. 针对cursor获得的library cache pin mode是X。

4. sql软解析时，也需要获得library cache lock latch。

--------------------------------------ORACLE-DBA----------------------------------------

最权威、专业的Oracle案例资源汇总之【案例】Oracle等待事件library cache lock产生原因和解决办法

oracle library cache lock,【案例】Oracle等待事件library cache lock产生原因和解决办法...相关推荐

  1. oracle enq ta,【案例】Oracle等待事件event enq: KO - fast object checkpoint解决办法

    [案例]Oracle等待事件event enq: KO - fast object checkpoint解决办法 时间:2016-11-03 10:11   来源:Oracle研究中心   作者:HT ...

  2. php iframe js加载不上,js iframe的onload事件不去作用的原因及解决办法

    通过createElement_x_x创建的iframe的onload事件在有些时候不响应,具体原因和解决办法如下. 首先,我们来看一下下面这种方法: function createFrame(){ ...

  3. oracle redo wait较高,【案例】Oracle等待事件latch:row cache objects原因和解决办法

    [案例]Oracle等待事件latch:row cache objects原因和解决办法 时间:2016-11-05 13:41   来源:Oracle研究中心   作者:HTZ   点击: 次 天萃 ...

  4. oracle等待资源时间加长,案例:Oracle等待事件latch: cache buffers chains故障优化处理总结...

    天萃荷净 数据库的CPU使用率为100%,应用相应迟缓.查看AWR中数据库的latch:cache buffers chains等待较多 当一个数据块读入sga区,相应的buffer header会被 ...

  5. oracle job enq tx,【学习笔记】Oracle等待事件 enq:TX–allocate ITL entry产生原因和解决办法...

    天萃荷净 运维DBA反映Oracle数据库出现enq:TX–allocate ITL entry等待事件,结合案例分析该等待事件产生原因和解决办法 今天在分析一份awr中发现了较为明显的enq: TX ...

  6. Oracle Study之--resmgr:cpu quantum等待事件

    Oracle Study之--resmgr:cpu quantum等待事件 在AWR Report中出现"resmgr:cpu quantum"等待事件: "resmgr ...

  7. 12 c for. oracle rac,【案例】Oracle RAC FOR AIX搭建执行root.sh时两次报错的解决办法

    天萃荷净 运维DBA反映在aix 5.3 ml6安装10.2.0.1 rac报错0509-036 Cannot load program crsctl.bin because of the follo ...

  8. oracle锁mode,【案例】Oracle dml操作产生TM锁 lmode=6 分析原因和解决办法

    [案例]Oracle dml操作产生TM锁 lmode=6 分析原因和解决办法 时间:2016-12-04 20:22   来源:Oracle研究中心   作者:网络   点击: 次 天萃荷净 Ora ...

  9. oracle pls 00905,【案例】Oracle报错PLS-00714 PLS-00951原因和解决办法笔记

    [案例]Oracle报错PLS-00714 PLS-00951原因和解决办法笔记 时间:2016-11-14 11:07   来源:Oracle研究中心   作者:代某人   点击: 次 天萃荷净 P ...

最新文章

  1. java树 JTree实例（可动态添加节点）
  2. mysql group by怎么用
  3. 如何正确使用Java8的Optional机制
  4. LintCode-第k大元素
  5. 在Linux下编译安装Apache2(2)
  6. 用递归求最大值PHP,php如何使用递归来计算一个目录中所有文件的大小（代码）...
  7. QT 显示中文、解决发布乱码、获得系统特定目录、获取文件属性、列表控件、屏幕截图显示保存(定时器)、视频直播、右键菜单
  8. jsoup解析器快速入门
  9. OMP: Error #15: Initializing libiomp5md.dll, but found libiomp5md.dll already initialized.
  10. vue 前端png转pdf_Vue前端HTML保存为PDF的两种常用方式 「干货分享」
  11. hibernate5.0映射配置文件核心配置文件数据更新丢失
  12. Ubuntu一些基本软件安装方法
  13. 有1分，2分，5分，10分四种硬币，每种硬币数量无限，有多少中组合可以组成n分钱？
  14. SDI科普--- SD-SDI/HD-SDI/3G-SDI/12G-SDI
  15. Oracle EBS 后台提交请求集 FND_SUBMIT.SUBMIT_PROGRAM
  16. NR-PRACH接受端如何检测出preambleid和TA的
  17. Android安全性优化——APP加固
  18. libsvm的使用svm-scale和svm-train与svm-predict
  19. chrome —— 登录账号
  20. 用什么擦地最干净脑筋急转弯_27个有意思的脑筋急转弯（含答案）

热门文章

  1. 设计1.0 -- iterator 和const_iterator底层的模拟实现
  2. 【Visual Studio 扩展工具】如何在ComponentOneFlexGrid树中显示RadioButton
  3. 在Java连接hbase时出现的问题
  4. Oracle用户管理
  5. IE6、IE7、IE8的CSS、JS兼容
  6. Android Handler介绍
  7. linux创建用户并授予sudo权限
  8. 再也不买仙剑正版盘了
  9. 解决firefox ubuntu无法打开页面的问题
  10. Linux下C语言的fgets与fputs