技术分享 | 一则Oracle数据库IO性能问题分析案例

本文为墨天轮数据库管理服务团队第165期技术分享，内容原创，作者为技术顾问王君慧，如需转载请联系小墨（VX：modb666）并注明来源。如需查看更多文章可关注【墨天轮】公众号。

问题描述

客户反馈，一套Oracle 11g集群在本周内出现整体性的性能下降问题。

对比历史（上周）、及当前的AWR报告TOP等待，可以发现log file sequential read，db file scattered read 等待事件的DBTIME占比明显提升，system io平均等待时间翻倍。

20250815（周五）17：00-18：00
Top 10 Foreground Events by Total Wait Time
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Tota Wait % DB
Event Waits Time Avg(ms) time Wait Class
------------------------------ ------------ ---- ------- ------ ----------
log file sequential read 2,223,733 177. 80 79.6 System I/O
db file scattered read 384,111 20.9 54 9.4 User I/O
DB CPU 8890 4.0
db file sequential read 1,092,125 6853 6 3.1 User I/O
control file sequential read 827,641 6166 7 2.8 System I/O
Disk file Mirror Read 167,433 1393 8 .6 User I/O
direct path read 127,734 712. 6 .3 User I/O
read by other session 12,120 181. 15 .1 User I/O
enq: MN - contention 639,669 99.5 0 .0 Other
gc cr multi block request 287,389 75 0 .0 Cluster
Wait Classes by Total Wait Time
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Avg Avg
Total Wait Wait % DB Active
Wait Class Waits Time (sec) (ms) time Sessions
---------------- ---------------- ---------------- -------- ------ --------
System I/O 3,102,616 183,436 59 82.4 51.4
User I/O 1,945,398 30,187 16 13.6 8.5

20250808（周五）17：00-18：00
Top 10 Foreground Events by Total Wait Time
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Tota Wait % DB
Event Waits Time Avg(ms) time Wait Class
------------------------------ ------------ ---- ------- ------ ----------
enq: MN - contention 4,069,734 25.3 6 52.9 Other
log file sequential read 1,036,220 9203 9 19.2 System I/O
DB CPU 7116 14.9
control file sequential read 5,032,787 2655 1 5.6 System I/O
db file scattered read 808,945 1722 2 3.6 User I/O
db file sequential read 3,253,719 1140 0 2.4 User I/O
Disk file Mirror Read 977,217 444. 0 .9 User I/O
ASM file metadata operation 704,699 267. 0 .6 Other
gc cr multi block request 665,083 170. 0 .4 Cluster
gc cr block 2-way 530,666 53 0 .1 Cluster
Wait Classes by Total Wait Time
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Avg Avg
Total Wait Wait % DB Active
Wait Class Waits Time (sec) (ms) time Sessions
---------------- ---------------- ---------------- -------- ------ --------
Other 6,451,726 25,636 4 53.6 7.1
System I/O 6,115,082 11,875 2 24.8 3.3
DB CPU 7,117 14.9 2.0
User I/O 5,674,785 3,381 1 7.1 0.9

问题分析

通过AWR报告看，造成整体性能下降的原因主要为IO性能下降，进一步分析操作系统资源占用及进程占用情况。

检查单块磁盘IO情况

发现数多块数据盘读IO很高，平均在100MB/s左右；读延迟达到50ms左右，远远大于avctm的值，说明不仅读延迟高，读请求排队也十分严重；磁盘繁忙度已到100%；

rman备份任务

排查发现存在数据库备份任务在执行，当停止数据库备份任务后，磁盘IO并未下降，排除rman备份任务的原因。

检查当前占用IO较高的后台进程

可以发现，主要IO占用为lisbak实例非本地进程

Actual DISK READ: 2.67 G/s | Actual DISK WRITE: 160.11 K/s
TID PRIO USER DISK READ DISK WRITE SWAPIN IO> COMMAND
12732 be/4 oracle 629.71 K/s 0.00 B/s 0.00 % 98.10 % oraclexxxdb2 (LOCAL=NO)
48005 be/4 oracle 608.24 K/s 0.00 B/s 0.00 % 96.91 % oraclexxxdb2 (LOCAL=NO)
19714 be/4 oracle 1017.02 K/s 0.00 B/s 0.00 % 81.42 % oraclexxxdb2 (LOCAL=NO)
11377 be/4 oracle 5.60 M/s 0.00 B/s 0.00 % 80.09 % oraclexxxdb2 (LOCAL=NO)
61632 be/4 oracle 407.88 K/s 0.00 B/s 0.00 % 61.45 % oraclexxxdb1 (LOCAL=NO)
8594 be/4 oracle 236.14 K/s 0.00 B/s 0.00 % 39.70 % oraclexxxdb1 (LOCAL=NO)
33026 be/4 oracle 26.56 M/s 7.16 K/s 0.00 % 39.18 % oraclexxxdb2 (LOCAL=NO)
62297 be/4 oracle 386.41 K/s 0.00 B/s 0.00 % 33.14 % oraclexxxdb2 (LOCAL=NO)
46164 be/4 oracle 30.04 M/s 0.00 B/s 0.00 % 32.71 % oraclexxxdb2 (LOCAL=NO)
58388 be/4 oracle 43.16 M/s 7.16 K/s 0.00 % 18.05 % oraclexxxdb2 (LOCAL=NO)
52474 be/4 oracle 10.07 M/s 0.00 B/s 0.00 % 15.64 % oraclexxxdb2 (LOCAL=NO)
2038 rt/4 root 0.00 B/s 0.00 B/s 0.00 % 12.24 % multipathd
31548 be/4 oracle 6.99 M/s 0.00 B/s 0.00 % 9.40 % oraclexxxdb2 (LOCAL=NO)
8234 be/4 oracle 11.60 M/s 0.00 B/s 0.00 % 7.24 % oraclexxxdb1 (LOCAL=NO)
25890 be/4 oracle 57.25 K/s 42.93 K/s 0.00 % 4.62 % ora_ckpt_xxxdb2
60702 be/4 oracle 42.93 K/s 0.00 B/s 0.00 % 3.37 % ora_lmon_xxxdb3
25846 be/4 oracle 42.93 K/s 0.00 B/s 0.00 % 3.01 % ora_lmon_xxxdb2
53633 be/4 oracle 14.31 K/s 0.00 B/s 0.00 % 2.17 % ora_lmon_xxxdb1
20123 rt/4 grid 915.94 B/s 0.00 B/s 0.00 % 1.89 % ocssd.bin
20127 rt/4 grid 915.94 B/s 0.00 B/s 0.00 % 1.83 % ocssd.bin
20121 rt/4 grid 0.00 B/s 915.94 B/s 0.00 % 1.26 % ocssd.bin
20131 rt/4 grid 915.94 B/s 0.00 B/s 0.00 % 1.20 % ocssd.bin
20125 rt/4 grid 0.00 B/s 915.94 B/s 0.00 % 0.65 % ocssd.bin
20129 rt/4 grid 0.00 B/s 915.94 B/s 0.00 % 0.63 % ocssd.bin
16742 be/4 oracle 46.51 M/s 0.00 B/s 0.00 % 0.00 % oraclexxxdb2 (LOCAL=NO

检查进程在数据库内部的归属

通过OSPID获取到数据库进程的SQL\_ID，检查SQL内容后发现为LOGMINGER日志抽取使用：

SQL> select addr,pid,spid,pname,username,program from v$process where spid=16742;
ADDR PID SPID PNAME USERNAME
---------------- ---------- ------------------------ ----- ---------------
PROGRAM
------------------------------------------------
0000000C70AC0F88 84 16742 grid
oracle@rac-1
SQL> select sql_id,program,machine,event,schemaname from v$session where paddr='0000000C70AC0F88';
SQL_ID PROGRAM
------------- ------------------------------------------------
MACHINE
----------------------------------------------------------------
EVENT
----------------------------------------------------------------
SCHEMANAME
------------------------------
6x6s6490zj2dg JDBC Thin Client
tcs-10-1-76-204
log file sequential read
DAAS_LISBAK

主要等待事件分析与AWR报告发现一致

检查SQL\_ID的文本内容：

select sql_fulltext from v$sql where sql_id='6x6s6490zj2dg';
SELECT SCN, SQL_REDO, OPERATION_CODE, TIMESTAMP, XID, CSF, TABLE_NAME, SEG_OWNER
, OPERATION, USERNAME, ROW_ID, ROLLBACK, RS_ID, STATUS, INFO, SSN, THREAD#, DATA
_OBJ#, DATA_OBJV#, DATA_OBJD# FROM V$LOGMNR_CONTENTS WHERE SCN > :1 AND SCN <=
:2 AND ((OPERATION_CODE IN (6,7,34,36) OR (OPERATION_CODE = 5 AND USERNAME NOT
IN ('SYS','SYSTEM') AND INFO NOT LIKE 'INTERNAL DDL%' AND (TABLE_NAME IS NULL O
R TABLE_NAME NOT LIKE 'ORA_TEMP_%')) ) OR (OPERATION_CODE IN (1,2,3,255) ))

SQL执行情况分析

通过分析SQL执行情况，发现该SQL的执行计划并无改变，但在8月11日后，执行频率降低、扫描行数增高（执行计划为全表扫描，那么仅与挖掘的日志条目数量相关）、平均单次响应时间增高。

执行次数统计：
单次执行的BUFFER GETS统计：
单次执行的平均返回行数统计：
总返回行数变化：
单次执行的平均时间：

归档日志生成量分析

由于logminer解析的日志条目数量和归档日志生产量相关，继续检查归档日志，发现归档日志同比变化不大。

最近14日归档日志生产量：

分析结论及处理建议

分析结论

通过上述分析，IO问题主要由LOGMINER日志挖掘导致，数据库层面分析到的变化时间与硬件层面的IO监控结果基本吻合。

LOGMINER挖掘的性能变化，通过SQL统计看，其执行计划没有改变，但执行频率变低但单次执行扫描的行数、内存块数增加，由于语句查询效率取决于logminer 分析的日志条目数量，推测可能为处理逻辑变化导致。

处理建议

通过上述分析得出，本次IO性能问题主要由于LOGMINER日志挖掘导致，观察执行统计发现其执行频率、效率发生改变，建议联系logminer使用的对应厂商排查当前的抽取逻辑。

墨天轮从乐知乐享的数据库技术社区蓄势出发，全面升级，提供多类型数据库管理服务。墨天轮数据库管理服务旨在为用户构建信赖可托付的数据库环境，并为数据库厂商提供中立的生态支持。
墨天轮数据库服务官网：https://www.modb.pro/service

技术分享 | 一则Oracle数据库IO性能问题分析案例

问题描述

问题分析

分析结论及处理建议

添加新评论

最新文章

最近回复

分类

归档

其它