一、发现问题
在arms监控页面看到某条insert语句的执行时长达到了431毫秒。
数据库中存在,insert语句受到了行锁阻塞,而阻塞的源头也在执行同样的insert语句,同样都是对表USERSYS_TASK_USER_LOG_TEMP01的插入操作,很是费解。
二、分析问题
1、查看数据库发现存在大量行锁阻塞(故障处置期间未截图,使用ash中查询的记录)。
分析发现这些阻塞源头也是insert语句。
2、awr报告中存在行锁阻塞
3、数据库中有微服务发起的定时job,执行delete这个表的操作,且删除的数据量大,且删除逻辑需优化,已执行9个小时,仍未执行完成。
4、继续查看会话的等待事件分析,发现最多的等待事件是gc(故障处置期间未截图,使用ash中查询的记录)
故障期间的分析语句如下:
select a.event,a.last_call_et,a.* from gv$session a where a.sql_id='gsg1d0w6n9t5x' and status='ACTIVE';
select a.blocking_session,a.event,count(*) from gv$session a where a.sql_id='gsg1d0w6n9t5x' and a.status='ACTIVE' group by a.blocking_session,a.even;
5、问题定位
(1)、行锁阻塞
该问题的原因是:由于数据库1节点发起了对这个表大量数据的delete操作,由于效率和数据量大的原因,一直未执行完成。但在删除数据的过程中,需要维护索引。
而在8-9点业务高峰期间同样会有大量insert的并发,这些并发insert同样需要去维护索引,因此就形成了enq:TX-index contention等待事件,而我们看到的就是行锁阻塞。
(2)、gc buffer busy acquire等待
由于数据库1节点在执行delete操作,且长时间执行,因此其数据块已经缓存到数据库1节点的内存中。
而微服务是连接的scan IP地址,各种查询和insert操作是随机分配到两个数据库节点上的,因此就会造成其中2节点去请求1节点缓存的内存块,而这时1节点正在使用,2节点就会等待,反之亦然。
三、解决问题
1、针对行锁阻塞问题。
将delete 操作的会话杀掉,后面再优化数据清理的脚本。让其回滚。根据之前回滚的经验,在回滚的过程中,对系统影响并不是特别大。
加快数据库回滚的方法,可以参照文章《20210302-加快数据库回滚》。
2、针对gc buffer busy acquire等待
将所有的微服务连接数据库的地址,从scanip更改为数据库1节点的IP地址。(由于delete操作是在数据库节点1发起,因此判断大部分缓存数据是在数据库节点1)。
四、问题总结
1、本次问题主要原因是gc等待造成的,而同时存在大量行锁阻塞会在排查过程中造成误导,其实行锁阻塞是表象。
2、遇到慢sql问题,首先要查看这些sql是在等待什么事件,可以使用以下脚本语句排查。
select a.event,a.last_call_et,a.* from gv$session a where a.sql_id='gsg1d0w6n9t5x' and status='ACTIVE';
select a.blocking_session,a.event,count(*) from gv$session a where a.sql_id='gsg1d0w6n9t5x' and a.status='ACTIVE' group by a.blocking_session,a.even;