首页 » ORACLE, ORACLE [C]系列 » Troubleshooting long wait “enq: US – contention” & “enq: IV – contention” after DDL, alert show “libcache interrupt action by LCK”

Troubleshooting long wait “enq: US – contention” & “enq: IV – contention” after DDL, alert show “libcache interrupt action by LCK”

一套12C R2版本的4节点RAC数据库,记录一起高并发业务繁忙时,DDL导致数据库出现大量前台会话长时间等待”enq: US – contention” & “enq: IV – contention” ,该SQL(INSRT VALUE)的只是一个Children cursor无法执行(sql_start_exec 时间已过去数小时),第二个的children cursor执行效率正常,最终KILL 这些长时间运行前端会话解决.

enq: IV – contention
IV Library Cache Invalidation Synchronizes library cache object invalidations across instances

enq: US – contention
US Undo Segment Lock held to perform DDL on the undo segment

db alert log

2020-01-08T09:18:46.175252+08:00
LCK1 (ospid: 62157) waits for event 'libcache interrupt action by LCK' for 72 secs.
2020-01-08T09:18:46.175342+08:00
LCK1 (ospid: 62157) is hung in an acceptable location (libcache 0x41.02).
2020-01-08T09:22:36.304180+08:00
LCK1 (ospid: 62157) waits for event 'libcache interrupt action by LCK' for 84 secs.
2020-01-08T09:22:36.304278+08:00
LCK1 (ospid: 62157) is hung in an acceptable location (libcache 0x41.02).
2020-01-08T09:28:58.571536+08:00
LCK1 (ospid: 62157) waits for event 'libcache interrupt action by LCK' for 74 secs.
2020-01-08T09:28:58.571626+08:00
LCK1 (ospid: 62157) is hung in an acceptable location (libcache 0x41.02).
2020-01-08T09:31:23.535829+08:00
LCK1 (ospid: 62157) waits for event 'libcache interrupt action by LCK' for 225 secs.
2020-01-08T09:31:23.535924+08:00
LCK1 (ospid: 62157) is hung in an acceptable location (libcache 0x41.02).
2020-01-08T09:33:55.656437+08:00
LCK1 (ospid: 62157) waits for event 'libcache interrupt action by LCK' for 64 secs.
2020-01-08T09:33:55.656529+08:00
LCK1 (ospid: 62157) is hung in an acceptable location (libcache 0x41.02).
2020-01-08T09:39:44.754781+08:00
LCK1 (ospid: 62157) waits for event 'libcache interrupt action by LCK' for 84 secs. 

什么是event ‘libcache interrupt action by LCK’
似乎显示LCKn进程正在处理中,未被另一个会话堵塞,这个等待事件不是真正的等待,而是在尝试在把lock处理为失效时给会话显示为这个等待event. 当出现这个问题时可能的原因有:
* A long list of locks to invalidate
* A large reference list for the objects to invalidate
* Some form of linked list corruption

在lck trace中有如下记录

*** 2020-01-08T02:06:27.966915+08:00
kqlmClusterMessage: sync lock contention.
kqlmClusterMessage: sync lock contention.
kqlmClusterMessage: sync lock contention.
kqlmClusterMessage: sync lock contention.
kqlmClusterMessage: sync lock contention.

等待FG会话的wait “enq: IV – contention”, call stack

short stack: ksedsts()+346<-ksdxfstk()+71<-ksdxcb()+912<-sspuser()+217<-__sighandler()<-semtimedop()+10
<-skgpwwait()+200<-ksliwat()+2300<-kslwaitctx()+197<-kjuscv_wait()+2184<-kjuscv()+1778<-ksicon()+2008<-
kqlmClusterMessage()+1169<-kqrSendInvalidationMessage()+648<-kqrGetClusterLock()+3423<-kqrLockAndPinPo()
+1509<-kqrpre1()+3041<-ktuGetRowCache1()+84<-ktuVerifyUsnForCreate()+154<-ktuFindNextUsnForCrt()+651<-
ktuFindNextFreeUsn()+135<-ktuCreateUndoSegment()+1059<-ktusmcus()+202<-ktusmAddUndoSegment()+897<-
ktusmaus_add_us()+808<-ktubnd()+19002<-ktuchg2()+12560<-ktbchg2()+236<-kdtchg()+1204<-kdtwrp()+2522<-kdtInsRow()+659<

LCK1 进程WAIT “enq: IV – contention” ,call stack

ksedsts()+346<-ksdxfstk()+71<-ksdxcb()+912<-sspuser()+217<-__sighandler()<-__poll()+16<-sskgxp_selectex()
+309<-skgxpiwait()+1587<-skgxpwaiti()+404<-skgxpwait()+176<-ksxpwait_int()+2930<-ksxpwait()+1664<-ksliwat()
+10782<-kslwaitctx()+197<-kjusuc()+9058<-ksigeti()+6782<-kqlmbinv()+192<-kqlmba()+502<-ksbcti()+247<-ksbabs()
+551<-ksbrdp()+1079<-opirip()+609<-opidrv()+602<-sou2o()+145<-opimai_real()+202<-ssthrdmain()+417<-main()

kslwaitctx()+197 kernel service latching and post-wait wait for n centi-seconds or until posted wait context; wait until timeout
kjusuc()+9058 kernel lock management global enqueue service synchronous open and convert a lock
ksigeti()+6782 kernel service instance locking [partial hit for: ksi ]
kqlmbinv()+192 kernel query library cache multi-instance manager [partial hit for: kqlm ]
kqlmba()+502 kernel query library cache multi-instance manager [partial hit for: kqlm ]
ksbcti()+247 kernel service background processes call timeout/interrupts
ksbabs()+551 kernel service background processes action based server

问题时建议做
Systemstate, hanganalye dump, 和ASH 持久化, undostat。

分析ASH信息
00:39 到 01:08分 主要等待为enq: TM – contention,1个实例有4000左右session等待,从DDL审计中可以查到对INSERT的相关表做了DDL
01:09 到 01:18      有出现过大量row cache lock应该为DDL过后DICT 争用
01:09 到 现在      主要等等为enq: US – contention,enq: IV – contention 并大量并发事务开始等待分配UNDO SEGMENTS和lock invalid

这时一个高并发业务的数据库,当业务运行时,对table做DDL,会导致TABLE 相关的对象在library cache lock中失效, 而在RAC环境中是lck进程负责local节点library cache的IV操作和通知其它节点lck, 之前一个案例中也出现过https://www.anbob.com/archives/2942.html , 这是一个12c r2的数据库,已知BUG中没有发现,以12.1 和11.2.0.4 中有个Bug 17052702 – LCK hang with ‘enq: IV – contention’ (Doc ID 2410520.1) .

12.2中启用CURSOR_INVALIDATION控制DDL后deferred cursor invalidation or immediate cursor invalidation ,默认是immediate。滚动失效的窗口是有_optimizer_invalidation_period参数控制,单位秒,默认5小时, 和12.2之前的版本在dbms_stats中使用一样,可以修改参数cursor_invalidation=deferred或对index DDL时加”DEFERRED INVALIDATION”滚动失效SQL children cursor, 但是并不是所有情况都可以rolling invalidation。

select sql_text,invalidations,loads,parse_calls,executions,first_load_time,last_load_time,last_active_time,is_rolling_invalid from v$sql where xxx

— 另外注意从12c 开始LCK 出现了2个进程。

打赏

, ,

目前这篇文章还没有评论(Rss)

我要评论