标签归档：library cache lock

dblink会话引起library cache lock

发表于 2020 年 12 月 13 日由惜分飞

有客户反馈,系统最近几天晚上都有卡顿
alert日志里面报如下错误

查看对应的trace文件

确定在收集统计信息的时候报ORA-04021错误.
查看这段时间ash报告

大量的library cache lock等待,而且引起等待的是类似语句,主要都是集中在一张表上,和收集统计信息报错的trace表匹配.
正好当天有对该表进行增加分区维护hang住

查询等待事件和阻塞情况

SQL> select distinct sid,a.BLOCKING_SESSION_STATUS,a.BLOCKING_INSTANCE,a.BLOCKING_SESSION
  2  ,event from gv$session a where sid=7399;

       SID BLOCKING_SE BLOCKING_INSTANCE BLOCKING_SESSION
---------- ----------- ----------------- ----------------
EVENT
----------------------------------------------------------------
      7399 VALID                       3             3593
library cache lock

SQL>  select a.INST_ID,a.sid,a.paddr,a.sql_id,a.event,a.MACHINE,a.PROGRAM 
   2 ,status from gv$session a where a.sid=3593;

   INST_ID        SID PADDR            SQL_ID
---------- ---------- ---------------- -------------
EVENT
----------------------------------------------------------------
MACHINE
----------------------------------------------------------------
PROGRAM                                          STATUS
------------------------------------------------ --------
         3       3593 0000001F91E80670 grxhz2vpmsrc6
SQL*Net message from dblink
WORKGROUP\XG
PlatformSyn.exe                                  ACTIVE

由于对应的sql_id 无法找到sql语句,不过根据等待事件基本上确认是调用一个dblink导致该问题,通过查询该回话,发现该回话一致处于active状态,但是一致无任何变化,实在可能处于僵死状态,对其进行kill之后,增加分区正常,收集统计信息正常.

发表在 Oracle | 标签为 library cache lock | 评论关闭

DBMS_STATS收集子分区表导致library cache lock等待

发表于 2018 年 2 月 4 日由惜分飞

有客户反馈一个问题,业务中有一张表无论是查询还是dml操作都非常慢,让我们介入分析
数据库版本
打上了170814比较新的psu

[oracle@xffdb1 ~]$ $ORACLE_HOME/OPatch/opatch lsinventory

Oracle 中间补丁程序安装程序版本 11.2.0.3.15
版权所有 (c) 2018, Oracle Corporation。保留所有权利。


Oracle Home       : /u01/app/oracle/product/11.2.0/db_1
Central Inventory : /u01/app/oraInventory
   from           : /u01/app/oracle/product/11.2.0/db_1/oraInst.loc
OPatch version    : 11.2.0.3.15
OUI version       : 11.2.0.4.0
Log file location : /u01/app/oracle/product/11.2.0/db_1/cfgtoollogs/opatch/opatch2018-01-06_16-20-22下午_1.log


--------------------------------------------------------------------------------
Local Machine Information::
Hostname: xffdb1
ARU platform id: 226
ARU platform description:: Linux x86-64

已安装的顶级产品 (1):

Oracle Database 11g                                                  11.2.0.4.0
此 Oracle 主目录中已安装 1 个产品。


中间补丁程序 (2) :

Patch  26609929     : applied on Fri Sep 15 14:28:51 CST 2017
Unique Patch ID:  21482966
Patch description:  "OCW Patch Set Update : 11.2.0.4.170814 (26609929)"

Patch  26609445     : applied on Fri Sep 15 14:28:04 CST 2017
Unique Patch ID:  21482382
Patch description:  "Database Patch Set Update : 11.2.0.4.170814 (26609445)"

awr数据结果

这里显示大量的library cache lock等待
做systemstate分析

                    Resource Holder State
   LOCK: Handle=0x325d938e08    74: 74: is waiting for PIN: Handle=0x325d938e08
    Enq TX-00E0001B-000004D3   488: 488: is waiting for 74:
              Mutex 1e7fbf6c   322: 322: is waiting for 74:
    Enq TX-02850009-00000086   630: 630: is waiting for 74:
    Enq TX-02BC000A-0000009E    ??? Blocker
    Enq TX-0075000E-000010BE    ??? Blocker
    PIN: Handle=0x325d938e08    ??? Blocker
    Enq TX-049A000C-00000002    ??? Blocker
    Enq TX-034C001D-00000038    ??? Blocker
    Enq TX-052C0012-00000002   669: 669: is waiting for 74:
    Enq TX-04620004-00000003    ??? Blocker
    Enq TX-009B0020-00000DA6    ??? Blocker
              Mutex af4db5a8   242: 242: is waiting for 74:
    Enq TX-041E0002-00000005    ??? Blocker
              Mutex 663b253d   727: 727: is waiting for 74:
    Enq TX-04FA0008-00000003   124: 124: is waiting for 69:
    Enq TX-031D0010-0000005B    ??? Blocker
    Enq TX-02BB0004-000000A2    ??? Blocker
    Enq TX-0248001A-000000CD    69: 69: is waiting for Enq TX-02BC000A-0000009E
    Enq TX-03D70008-00000002    ??? Blocker
    Enq TX-02B1001D-00000081    ??? Blocker
    Enq TX-0423001A-00000003    ??? Blocker
    Enq TX-051A0007-00000003   506: 506: is waiting for 74:
              Mutex 2aceb8e9   602: 602: is waiting for 74:
              Mutex c6b2e0f4   196: 196: is waiting for 74:
    Enq TX-00A30020-0000055A    ??? Blocker
    Enq TX-00D70015-00000315    ??? Blocker
    Enq TX-03B30006-00000012    ??? Blocker
    Enq TX-008C0003-00001005    ??? Blocker
    Enq TX-05470014-00000006   219: 219: is waiting for 74:
    Enq TX-054E0018-00000006   673: 673: is waiting for 74:
              Mutex f28c06f8   279: 279: is waiting for 74:
    Enq TX-03D30012-00000002    ??? Blocker
    Enq TX-055C001B-00000005   333: 333: is waiting for Enq TX-01CF000B-00000B2F

              Mutex 2ff03da9   276: 276: is waiting for 74:
    Enq TX-030A000A-000000B6    ??? Blocker
    Enq TX-00530004-000023DF   212: 212: is waiting for 74:
    Enq TX-05550017-00000002   469: 469: is waiting for 74:
              Mutex 724ba5e3   177: 177: is waiting for 74:
    Enq TX-03C10007-00000015    ??? Blocker
    Enq TX-02E30006-00000079    ??? Blocker
                       IPC 6      6 Blocker
    Enq TX-0289000B-0000005F   449: 449: is waiting for 74:
    Enq TX-021E0002-000001DA    ??? Blocker
              Mutex a9fcc7b8   131: 131: is waiting for 74:
    Enq TX-0483001F-00000009    ??? Blocker
    Enq TX-00800010-00000BA0    ??? Blocker
              Mutex c0af249e   666: 666: is waiting for 74:
              Mutex 94389ed4    78: 78: is waiting for 74:
              Mutex 4ac40611   143: 143: is waiting for 74:
              Mutex 24c1c387   168: 168: is waiting for 74:
              Mutex 930636c9   752: 752: is waiting for 74:
    Enq TX-04660001-00000003    ??? Blocker
    Enq TX-01B6000A-00000022    ??? Blocker
    Enq TX-0166000F-000002C7    ??? Blocker
    Enq TX-02FF0008-000000A1    ??? Blocker
    Enq TX-01E10001-00000023    ??? Blocker
    Enq TX-0327000E-0000009E    ??? Blocker
    Enq TX-05120016-00000002   615: 615: is waiting for 74:
    Enq TX-039F001D-00000011    ??? Blocker
    Enq TX-01CF000B-00000B2F    ??? Blocker
    Enq TX-01130020-000001B6    ??? Blocker
    Enq TX-052A0021-00000002   635: 635: is waiting for 74:
              Mutex ebf68fee   579: 579: is waiting for 74:
    Enq TX-02350017-000000D6    ??? Blocker
    Enq TX-00BB0000-00000598    ??? Blocker
    Enq TX-0443000E-00000003    ??? Blocker
              Mutex e7bae014   344: 344: is waiting for 74:
              Mutex fe251793   616: 616: is waiting for 74:
              Mutex 750494ae   180: 180: is waiting for 74:
    Enq TX-01230010-000001C0    ??? Blocker
    Enq TX-0543001C-00000003   119: 119: is waiting for 124:
    Enq TX-04E60014-00000005    ??? Blocker
    Enq TX-00F1000A-000002AB    ??? Blocker
              Mutex aa83fbd7   651: 651: is waiting for 74:
    Enq TX-058A0002-00000003    ??? Blocker
    Enq TX-03B00016-0000000F    ??? Blocker
              Mutex 26e065a4   150: 150: is waiting for 74:
    Enq TX-0219001B-000001BE    ??? Blocker
    Enq TX-00B9001D-00000069    ??? Blocker
    Enq TX-01110020-00000198    ??? Blocker
    Enq TX-04F3001B-00000002    ??? Blocker
    Enq TX-04A60015-00000002    ??? Blocker
    Enq TX-02D30015-0000008A    ??? Blocker
    Enq TX-01540018-000001B7    ??? Blocker
    Enq TX-02240019-0000001C    ??? Blocker
              Mutex e595002d   502: 502: is waiting for 74:
              Mutex 1661a4cb   732: 732: is waiting for 74:
    Enq TX-00320010-00003A12    ??? Blocker
    Enq TX-020F001F-00000027    ??? Blocker
    Enq TX-0387000A-0000004D   515: 515: is waiting for 74:
    Enq TX-01260014-0000012D    ??? Blocker
    Enq TX-02EE001D-0000005F    ??? Blocker
    Enq TX-004A0001-00000882   603: 603: is waiting for Enq TX-02240019-0000001C

              Mutex 4a18a781   258: 258: is waiting for 74:
   LOCK: Handle=0x325aa4c428   643: 643: is waiting for 74:
    Enq TX-037A0002-0000006E   118: 118: is waiting for 74:
    Enq TX-02460020-0000006D   493: 493: is waiting for Enq TX-00F1000A-000002AB


PROCESS 74: J000
  ----------------------------------------
  SO: 0x31a2b2e440, type: 2, owner: (nil), flag: INIT/-/-/0x00 if: 0x3 c: 0x3
   proc=0x31a2b2e440, name=process, file=ksu.h LINE:12721, pg=0
  (process) Oracle pid:74, ser:153, calls cur/top: 0x305d24c378/0x305f3f5eb0
            flags : (0x0) -
            flags2: (0x10),  flags3: (0x10) 
            intr error: 0, call error: 0, sess error: 0, txn error 0
            intr queue: empty
    ksudlp FALSE at location: 0
  (post info) last post received: 0 0 80
              last post received-location: kji.h LINE:3691 ID:kjata: wake up enqueue owner
              last process to post me: 0x3182a6fca0 1 6
              last post sent: 0 0 26
              last post sent-location: ksa2.h LINE:285 ID:ksasnd
              last process posted by me: 0x3182a75038 2 6
    (latch info) wait_event=0 bits=0x0
    Process Group: DEFAULT, pseudo proc: 0x3162ddbe90
    O/S info: user: oracle, term: UNKNOWN, ospid: 103036 
    OSD pid info: Unix process pid: 103036, image: oracle@xffdb1 (J000)
    Short stack dump: 
      ksedsts()+465<-ksdxfstk()+32<-ksdxcb()+1927<-sspuser()+112<-__sighandler()<-semtimedop()+10
      <-skgpwwait()+178<-ksliwat()+2046<-kslwaitctx()+163<-kjusuc()+3400
      <-ksipgetctxi()+1759<-kqlmPin()+2943<-kqlmClusterLock()+237<-kglpnal()+4072
      <-kglpin()+1381<-qostobkglcrt1()+640<-qostobkglcrt()+255<-qospsts()+1639
      <-spefcmpa()+196<-spefmccallstd()+235<-pextproc()+41<-peftrusted()+150
      <-psdexsp()+255<-rpiswu2()+1776<-psdextp()+700<-pefccal()+726<-pefcal()+224
      <-pevm_FCAL()+169<-pfrinstr_FCAL()+75<-pfrrun_no_tool()+63<-pfrrun()+627
      <-plsql_run()+649<-peidxr_run()+263<-peidxexe()+79<-kkxdexe()+338
      <-kkxmpexe()+241<-kgmexwi()+605<-kgmexec()+2193<-evapls()+813
      <-evaopn2()+808<-kkxmexcs()+133<-opiexe()+20880<-kpoal8()+2380
      <-opiodr()+917<-kpoodr()+1401<-upirtrc()+2436<-kpurcsc()+98
      <-kpuexec()+10790<-OCIStmtExecute()+39<-jslvec_execcb1()+672
      <-jslvswu()+56<-jslve_execute0()+2257<-jslve_execute()+332
      <-rpiswu2()+1776<-kkjex1e()+379<-kkjsexe()+711<-kkjrdp()+694
      <-opirip()+958<-opidrv()+603<-sou2o()+103<-opimai_real()+250
      <-ssthrdmain()+265<-main()+201<-__libc_start_main()+253


    SO: 0x31c382f010, type: 4, owner: 0x31a2b2e440, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
     proc=0x31a2b2e440, name=session, file=ksu.h LINE:12729, pg=0
    (session) sid: 6001 ser: 679 trans: 0x311e36fa28, creator: 0x31a2b2e440
              flags: (0x8010041) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
              flags2: (0x40009) -/-/INC
              DID: , short-term DID: 
              txn branch: (nil)
              edition#: 100              oct: 170, prv: 0, sql: 0x323de178e8, psql: 0x32b5d0fc98, user: 0/SYS
    ksuxds FALSE at location: 0
    service name: SYS$USERS
    client details:
      O/S info: user: oracle, term: UNKNOWN, ospid: 103036
      machine: xffdb1 program: oracle@xffdb1 (J000)
      application name: DBMS_SCHEDULER, hash value=2478762354
      action name: ORA$AT_OS_OPT_SY_1594, hash value=1524069073
    Current Wait Stack:
     0: waiting for 'library cache pin'
        handle address=0x325d938e08, pin address=0x325baec3e0, 100*mode+namespace=0x850fe00010003
        wait_id=46488 seq_num=46502 snap_id=1
        wait times: snap=6 min 2 sec, exc=6 min 2 sec, total=6 min 2 sec
        wait times: max=15 min 0 sec, heur=6 min 2 sec
        wait counts: calls=727 os=727
        in_wait=1 iflags=0x15a2
    There are 2136 sessions blocked by this session.

发现主要是74号进程阻塞了其他的
做hanganalyze分析

-------------------------------------------------------------------------------
Chain 1:
-------------------------------------------------------------------------------
    Oracle session identified by:
    {
                instance: 1 (xffdb.xffdbsv1)
                   os id: 82310
              process id: 224, oracle@xffdb1
              session id: 4
        session serial #: 12237
    }
    is waiting for 'enq: TX - row lock contention' with wait info:
    {
                      p1: 'name|mode'=0x54580006
                      p2: 'usn<<16 | slot'=0x21e0002
                      p3: 'sequence'=0x1da
            time in wait: 3 min 48 sec
           timeout after: never
                 wait id: 1260
                blocking: 0 sessions
             current sql: UPDATE t_xifenfei subpartition(p201801_s32)
                            SET INDICATORCODE   = :1,
                                LOWERLIMIT      = :2,
                                UPPERLIMIT      = :3,
                                AVGUNITPRICE    = :4,
                                TRADEITEMNAME   = :5,
    
             short stack: ………………
            wait history:
              * time between current wait and wait #1: 0.000220 sec
              1.       event: 'gc cr block 2-way'
                 time waited: 0.000341 sec
                     wait id: 1259            p1: ''=0x6
                                              p2: ''=0x3590
                                              p3: ''=0x44b
              * time between wait #1 and #2: 0.000284 sec
              2.       event: 'gc current block 3-way'
                 time waited: 0.000663 sec
                     wait id: 1258            p1: ''=0xa
                                              p2: ''=0x3ad02
                                              p3: ''=0x2000001
              * time between wait #2 and #3: 0.000383 sec
              3.       event: 'gc cr block 2-way'
                 time waited: 0.000288 sec
                     wait id: 1257            p1: ''=0x5
                                              p2: ''=0x2e20
                                              p3: ''=0x957
    }
    and is blocked by
 => Oracle session identified by:
    {
                instance: 3 (xffdb.xffdbsv3)
                   os id: 39472
              process id: 587, oracle@xffdb3
              session id: 2215
        session serial #: 8213
    }
    which is waiting for 'library cache lock' with wait info:
    {
                      p1: 'handle address'=0x327f5ecea0
                      p2: 'lock address'=0x327a5ab660
                      p3: '100*mode+namespace'=0x850fe00010002
            time in wait: 3 min 43 sec
           timeout after: 11 min 16 sec
                 wait id: 2343
                blocking: 3 sessions
             current sql: SELECT COUNT(*) COUNT
                          FROM t_xifenfei subpartition(p201801_s32)
                         WHERE TRADEITEMID = '679EA6DE428F414D014B3D5EC8DE5E32'
             short stack:  ………………
                 wait history:
              * time between current wait and wait #1: 0.000908 sec
              1.       event: 'SQL*Net message from client'
                 time waited: 0.001074 sec
                     wait id: 2342            p1: 'driver id'=0x54435000
                                              p2: '#bytes'=0x1
              * time between wait #1 and #2: 0.000033 sec
              2.       event: 'SQL*Net message to client'
                 time waited: 0.000003 sec
                     wait id: 2341            p1: 'driver id'=0x54435000
                                              p2: '#bytes'=0x1
              * time between wait #2 and #3: 0.000069 sec
              3.       event: 'SQL*Net message from client'
                 time waited: 0.001232 sec
                     wait id: 2340            p1: 'driver id'=0x54435000
                                              p2: '#bytes'=0x1
    }
    and is blocked by
 => Oracle session identified by:
    {
                instance: 1 (xffdb.xffdbsv1)
                   os id: 103036
              process id: 74, oracle@xffdb1 (J000)
              session id: 6001
        session serial #: 679
    }
    which is waiting for 'library cache pin' with wait info:
    {
                      p1: 'handle address'=0x325d938e08
                      p2: 'pin address'=0x325baec3e0
                      p3: '100*mode+namespace'=0x850fe00010003
            time in wait: 3 min 47 sec
           timeout after: 11 min 12 sec
                 wait id: 46488
                blocking: 2099 sessions
             current sql: call dbms_stats.gather_database_stats_job_proc (  )
             short stack: …………
            wait history:
              * time between current wait and wait #1: 0.000038 sec
              1.       event: 'library cache lock'
                 time waited: 0.012353 sec
                     wait id: 46487           p1: 'handle address'=0x325d938e08
                                              p2: 'lock address'=0x3259aee680
                                              p3: '100*mode+namespace'=0x850fe00010003
              * time between wait #1 and #2: 0.002509 sec
              2.       event: 'enq: IV -  contention'
                 time waited: 0.001079 sec
                     wait id: 46486           p1: 'type|mode'=0x49560005
                                              p2: 'id1'=0x53594e43
                                              p3: 'id2'=0x15
              * time between wait #2 and #3: 0.000085 sec
              3.       event: 'enq: IV -  contention'
                 time waited: 0.001817 sec
                     wait id: 46485           p1: 'type|mode'=0x49560005
                                              p2: 'id1'=0x4c4f434b
                                              p3: 'id2'=0x15
    }
 
Chain 1 Signature: 'library cache pin'<='library cache lock'<='enq: TX - row lock contention'
Chain 1 Signature Hash: 0xa08ff7bf

到这里基本上可以确定是由于自动任务收集统计信息导致系统出现大量的library cache lock和library cache pin,另外可以确定大部分被阻塞在library cache 相关的select和dml语句都集中在t_xifenfei这个子分区表中,通过查询mos,发现相关bug:Bug 19790972 – “library cache lock” waits due to DBMS_STATS gather of stats for a subpartition

发表在 Oracle Bug | 标签为 19790972, library cache lock | 评论关闭

library cache lock等待事件

发表于 2012 年 5 月 17 日由惜分飞

Library cache lock介绍
Oracle利用Library cache lock和Library cache pin来实现并发控制，Library cache lock是在handle上获取的，而Library cache pin则是在data heap上获取。访问对象时，首先必须获取handle上的lock，然后将访问的数据pin在内存中。lock的作用是控制进程间的并发访问，而pin的作用是保证数据一致性，防止数据在访问时被交换出去。
lock和pin的实现类似于enqueue，在每个handle上都有lock和pin的holder list和waiter list，用来保存持有该资源和等待该资源的队列。

Library cache lock相关sql语句

--找出library cache lock等待sid,saddr信息
select sid,saddr from v$session where event= 'library cache lock';

SID        SADDR
---------- --------
16         572ed244

--找出blocked信息
select kgllkhdl Handle,kgllkreq Request, kglnaobj Object
from x$kgllk where kgllkses = '572ed244'
and kgllkreq > 0;

HANDLE   REQUEST   OBJECT
-------- ---------- ------------------
62d064dc          2 EMPLOYEES

--找出blocking信息
select kgllkses saddr,kgllkhdl handle,kgllkmod mod,kglnaobj object
from x$kgllk lock_a
where kgllkmod > 0
and exists (select lock_b.kgllkhdl from x$kgllk lock_b
where kgllkses = '572ed244' /* blocked session */
and lock_a.kgllkhdl = lock_b.kgllkhdl
and kgllkreq > 0);

SADDR     HANDLE   MOD         OBJECT
--------  -------- ---------- ------------
572eac94  62d064dc          3  EMPLOYEES

--blocking 会话信息
select sid,username,terminal,program from v$session where saddr = '572eac94'

SID        USERNAME     TERMINAL  PROGRAM
---------- -----------  --------- --------------------------------------------
12          SCOTT        pts/20    sqlplus@goblin.forgotten.realms (TNS V1-V3)

--所有blocked 会话
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 = '572eac94' /* blocking session */
             and lock_a.kgllkhdl = lock_b.kgllkhdl
             and kgllkreq = 0)
);

SID        USERNAME  TERMINAL  PROGRAM
---------- --------- --------- -------------------------------------------
13         SCOTT     pts/22    sqlplus@goblin.forgotten.realms (TNS V1-V3)
16         SCOTT     pts/7     sqlplus@goblin.forgotten.realms (TNS V1-V3)

发表在 Oracle性能优化 | 标签为 library cache lock | 一条评论

17813235971

QQ 咨询

标签归档：library cache lock

dblink会话引起library cache lock

DBMS_STATS收集子分区表导致library cache lock等待

library cache lock等待事件

文章分类

最近发表

标签归档：library cache lock

dblink会话引起library cache lock

DBMS_STATS收集子分区表导致library cache lock等待

library cache lock等待事件

标签云

文章分类

最近发表