某业务节点业务一条效率极低的SQL
性能调优
业务反应节点,每天晚上批量插入数据近变得极慢,影响了其他批量作业。需要协助解决
2.1 定位SQL并向业务了解批量操作程序详情
根据业务的反应,我们定位到这条SQL如下。
SQL_ID 4xhxjp4wjg7b2
--------------------
INSERT INTO xxxxxx (CH,DBLM,ZM,JRJCLX,JRJCSJ,LJDM,CX,CZT,IMPORTDATE
,ZAIZ,sxxxlx) values (:1 ,:2 ,:3 ,:4 ,to_date(:5 ,'yyyy-mm-dd
hh24:mi:ss'),:6 ,:7 ,:8 ,:9 ,:10 ,:11 )
| Id | Operation | Name |
------------------------------------------------
| 0 | INSERT STATEMENT | |
| 1 | LOAD TABLE CONVENTIONAL | xxxxxx |
执行计划也很简单,通过内存加载数据。他们是从另一个库拿数据然后放到目标库,每次插入53万条数据,为了防止大事务对数据库的冲击,他们5000条记录提交一次。开始速度可以接受,但是近几天慢的无法忍受。
2.2 收集改SQL执行的所有历史信息和相关表信息
首先通过ASH视图dba_hist_active_sess_history查询这个SQL在21号凌晨3点到4点的等待事件
SQL_ID EVENT
COUNT(*)
------------- ------------------------------------------------
4xhxjp4wjg7b2 db file sequential read
356
以及历史执行情况
图1 SQL历史执行时间和资源消耗
为了更好的分析趋势,我们做了趋势分析
图2 SQL执行消耗趋势图
从数据图可以看出,4月19号开始物理读逻辑读明显增加,用户业务完成平均时间明显增加,严重的是21号凌晨3点,平均每次执行91秒,用户业务执行了2个小时。这里还能看出两个问题,一是用户在调整这个批量加载时间,二是用户白天执行很快。我们再回到开始看看业务SQL的等待事件为 db file sequential read,这个事件以为这单块读,推断应该是跟新索引的操作。下面看看用户表的具体信息。(其他说明:为了显示友好,时间扩大了100倍)
select segment_name,bytes/1024/1024 from dba_segments where segment_name
in (select index_name from dba_indexes where table_name='xxxxxx')
SEGMENT_NAME
BYTES/1024/1024
------------------------------ ----------------
IDX$$_2648D0001
30933
INX_ZJ_C80CL3
22870
INX_ZJ_C80CL1 22935
INX_ZJ_C80CL2
18430
IDX$$_3768B0001
28964
表大小53G,非分区数据量大概839369056行,表空间YJJ
OWNER SEGMENT_NAME SEG_SIZE_M SEGMENT_CNT MAX_TBS_NAME
---------- ------------- ------------ ---------- ------------
YJJ
xxxxxx 52795 1 YJJ
这里我们分析问题应该是在更新索引时被卡住了,此时我们怀疑几个可能情况
1.索引太大,并且都是多列索引,数据分布会很分散。
2.存储层是否异常。
3.晚上收集统计信息是否是bug导致。
4.其他业务异常繁忙阻塞IO。
所以,我们让他中午11点又跑了一次,发现此时的执行时间很快,逻辑读基本一致,但是物理读大幅降低。
这个测试排除了1,2的可能,同时与业务沟通说之前屏蔽了该表的统计信息,所以可能的问题就是还有其他业务在使用该存储盘造成IO争用。
经过询问业务方反馈,他们目前批量业务很多,为了防止冲突在时间线做了调整,这个说法跟我们在SQL历史执行的情况相符合,目前确实调整到凌晨3点开始跑,并且反馈他们确实还有两个业务在跑,我抓取了同样问题时段异常的等待如下。
5yzwgd22y9n2q db file sequential read
141
4z9u91p3g7wqc control file sequential read 296
11fq10bvah8x7 db file sequential read
309
fdt9ry996npu6 control file sequential read 409
4xhxjp4wjg7b2 db file sequential read
632
可见此时等待都很长时间,并且查询数据库的控制文件竟然也被阻塞,怀疑磁盘IO应该会很高,但是该节点由于没有系统监控,我们临时部署了一个oswatcher(后来知道其实之前部署了,但是被停止)。
这里有个插曲,业务一直反馈他们通过161s链接数据库,也就是通过实例1执行,但是我通过sql_monitor发现在162s,这为我们开始 排除故障带了疑惑,再发现问题后他们合适,他们确认是21号改到162后来忘记改。在4月24号我们在节点2 查看存储盘适用情况 ,验证了我们的推测。
Global Information
Status : DONE
Instance ID : 2
<<<<<<这里是第二节点
Session : YJJ (2980:47671)
SQL ID : 4xhxjp4wjg7b2
Execution Started : 04/24/2023 05:35:44
First Refresh Time : 04/24/2023 05:35:48
Last Refresh Time : 04/24/2023 05:36:01
Module/Action : JDBC Thin Client/-
Service : xxxx162s
Program : JDBC Thin Client
下面是磁盘IO情况
图3 磁盘的实例IO情况
下面对用下我们的数据存储目录
[root@n-pc-sr850-268 ~]#lsblk
VxVM13000
199:13000 14.9T
0 disk /oradata1
VxVM13001
199:13001 14.9T
0 disk /oradata2
也就是凌晨3点开始,这个判断IO异常繁忙,业务SQL对应的数据文件(包括用户数据和索引数据)和控制文件的存储空间/oradata1
由此,我们定位这个问题是磁盘异常IO导致,然后解决方案就很自然,由于
/oradata2一直不忙,我们把索引迁移到/oradata2下来平衡IO问题,从而减少db
file sequencial read的等待。
在/oradata2下建立对应表空间yjj_idxnew.
alter index YJJ.INX_xxxxx rebuild parallel 8 tablespace yjj_idxnew;
alter index YJJ.INX_xxxxx noparallel;
此时,业务告知他们将业务继续跑在161S,这个对我们处理问题,没有影响,我们继续监控平衡IO的操作是否生效。
在4月25号,我们看改SQL的历史信息,以及业务反馈这问题解决之前需要2个多小时现在在40分钟跑完,满足业务需要。
图4监控25号SQL执行消耗
业务执行了115次,都在3点-4点执行完,这里物理读减少了一些,主要还是IO等待少了,其实找了对于减少物理读还有优化空间,感兴趣可以考虑下。
3 结论
用户并发业务,造成IO繁忙,用户所有业务数据包括索引都在一个物理磁盘,造成insert操作时更新索引异常等待,我们通过平衡IO解决,满足了用户需求。