ANBOB™

一套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个进程。

打赏

微信扫一扫，打赏作者吧～