由一条sql语句导致的系统IO问题

简介: 早上来到公司,照例进行了简单的检查,发现系统负载不高,就开始计划一些sql tuning的工作,但是过了一会,在通过shell命令查找一些sql信息的时候,发现系统的反应有些慢,当时也没在意,当我查看v$session都开始慢的时候,感觉哪里出了什么问题了,最直观的感受就是一些命令的运行都很缓慢了。
早上来到公司,照例进行了简单的检查,发现系统负载不高,就开始计划一些sql tuning的工作,但是过了一会,在通过shell命令查找一些sql信息的时候,发现系统的反应有些慢,当时也没在意,当我查看v$session都开始慢的时候,感觉哪里出了什么问题了,最直观的感受就是一些命令的运行都很缓慢了。
首先查看了一下数据库的负载,发现在最近的一个多小时内负载高了很多。几乎是几十倍的速度。


BEGIN_TIME------------------------- END_TIME--------------------------- ELAPSED_TIME- BTIME----- WORKLOAD_PER--------
----------------------------------- ----------------------------------- ------------- ---------- --------------------
15599 ** 20-OCT-14 01.00.05.479 AM  15600 ** 20-OCT-14 02.00.07.824 AM         60.039     266.29 443%
15600 ** 20-OCT-14 02.00.07.824 AM  15601 ** 20-OCT-14 03.00.10.947 AM         60.052     215.22 358%
15601 ** 20-OCT-14 03.00.10.947 AM  15602 ** 20-OCT-14 04.00.14.461 AM         60.059     214.85 357%
15602 ** 20-OCT-14 04.00.14.461 AM  15603 ** 20-OCT-14 05.00.18.115 AM         60.061     209.35 348%
15603 ** 20-OCT-14 05.00.18.115 AM  15604 ** 20-OCT-14 06.00.21.252 AM         60.052     962.13 1602%
15604 ** 20-OCT-14 06.00.21.252 AM  15605 ** 20-OCT-14 07.00.24.555 AM         60.055     599.99 999%
15605 ** 20-OCT-14 07.00.24.555 AM  15606 ** 20-OCT-14 08.00.26.581 AM         60.034     549.54 915%
15606 ** 20-OCT-14 08.00.26.581 AM  15607 ** 20-OCT-14 09.00.29.611 AM         60.051    1391.88 2317%
15607 ** 20-OCT-14 09.00.29.611 AM  15608 ** 20-OCT-14 10.00.32.189 AM         60.043    1213.72 2021%
15608 ** 20-OCT-14 10.00.32.189 AM  15610 ** 20-OCT-14 11.38.00.930 AM         97.479   24637.09 25274 %
15609 ** 20-OCT-14 11.00.39.281 AM  15610 ** 20-OCT-14 11.38.00.930 AM         37.361    18493.3 49499%

然后查看一些性能视图都开始变得极为缓慢, 最后连生成awr报告的时候每一个步骤都得反应十多秒了。

首先 排除了数据库中的锁问题的可能性,然后开始排查倒底是存储的IO问题还是数据库级的?
先从系统级来看,系统级的IO情况。
查看dd命令的效果时,发现系统的IO出现了严重的问题。使用dd命令在正常的情况下每秒差不多有500~700M/s的速度。现在IO基本是瘫痪的感觉。
1000+0 records out
1048576000 bytes (1.0 GB) copied, 94.1975 seconds, 11.1 MB/s
------------------------------
1000+0 records in
1000+0 records out
1048576000 bytes (1.0 GB) copied, 334.724 seconds, 3.1 MB/s
------------------------------
1000+0 records in
1000+0 records out
1048576000 bytes (1.0 GB) copied, 33.5012 seconds, 31.3 MB/s
------------------------------

通过如上的dd结果还不能确定。在数据库级的IO出现呢严重等待的时候也是会导致系统级的问题。
从这个思路来看,这个问题和cpu的问题关联不是很大.
通过sar来查看io的情况。IOwait也是突然增高的。
10:40:02 AM       CPU     %user     %nice   %system   %iowait    %steal     %idle
10:50:01 AM       all     21.60      0.00      4.40      0.37      0.00     73.63
11:00:01 AM       all     13.94      0.00      3.55      4.57      0.00     77.94
11:10:01 AM       all      8.55      0.00      2.66      5.78      0.00     83.01
11:20:02 AM       all     12.06      0.00      3.22      8.71      0.00     76.01
11:30:01 AM       all      9.51      0.00      2.45     10.82      0.00     77.23
11:40:01 AM       all      9.75      0.00      2.55     11.51      0.00     76.19
11:50:02 AM       all      7.00      0.00      2.40     12.02      0.00     78.57


有了这些思路,可以感觉可能是在特定的一个时间点里数据库里有什么动作才导致的系统的负载极具提高。
查看了top命令的结果再次得到了一些印证。
因为通过top命令,可以看到不少ora_P0xxx的进程,这个进程就是数据库中存在并行的操作。看到并行进程达到了90多个。
这个时候看到那么到的进程,如果想知道到底是哪些session在做并行的操作,可以根据如下的sql来简单查询到一些有用的信息。
select pxsess.sid||','||pxsess.serial# sess_id,sess.username,sess.osuser,sess.machine,sess.program,pxsess.qcsid,pxsess.qcserial#,pxsess.degree,pxsess.server#,pxsess.req_degree from v$px_session pxsess,v$session sess where pxsess.sid=sess.sid ; 

得到的结果类似下面的样子。其实得到的session结果比这个多很多,我选了几个列举说明情况。
可以看到并行度为4,有很大一部分都是从客户端 scanner@client1发过来的。这样的session有10多个。
SESS_ID         USERNAME        OSUSER          MACHINE              PROGRAM                        QCSID  QCSERIAL#     DEGREE    SERVER# REQ_DEGREE
--------------- --------------- --------------- -------------------- ------------------------- ---------- ---------- ---------- ---------- ----------
3060,19215      PRDUSER         prdwrk01        client1             oracle@dbmachine (P000)          6912      12521          4          1          4
5903,31549      PRDUSER         prdwrk01        client1             oracle@dbmachine (P001)          6912      12521          4          2          4
6338,17097      PRDUSER         prdwrk01        client1             oracle@dbmachine (P002)          6912      12521          4          3          4
3670,37601      PRDUSER         prdwrk01        client1             oracle@dbmachine (P003)          6912      12521          4          4          4
5963,10235      PRDUSER         prdwrk01        client1             oracle@dbmachine (P004)          6912      12521          4          1          4
6289,37919      PRDUSER         prdwrk01        client1             oracle@dbmachine (P005)          6912      12521          4          2          4
432,51019       PRDUSER         prdwrk01        client1             oracle@dbmachine (P006)          6912      12521          4          3          4
3299,17439      PRDUSER         prdwrk01        client1             oracle@dbmachine (P007)          6912      12521          4          4          4
3894,9907       PRDUSER         prdwrk01        client1             oracle@dbmachine (P008)           497      18425          2          1          2
4403,13615      PRDUSER         prdwrk01        client1             oracle@dbmachine (P009)           497      18425          2          2          2
400,25915       PRDUSER         prdwrk01        client1             oracle@dbmachine (P010)           497      18425          2          1          2
6509,61063      PRDUSER         prdwrk01        client1             oracle@dbmachine (P011)           497      18425          2          2          2
6912,12521      PRDUSER         prdwrk01        client1             scanner@client1 (TNS V1-V3)       6912                                                                     
497,18425       PRDUSER         prdwrk01        client2             JDBC Thin Client                  497


通过session来查找对应的sql语句,发现是一个比较大的查询,这个查询中使用了Hint来做几个大表的全表扫描,大表都是千万级的表,所以同时十多个session做并行,而且都是做几个大表的全表扫描,数据库级就是严重的io等待,反应到系统级,又使用了并行,会消耗极高的系统IO.
而且根据我的了解,这个查询时产品线中使用的,目前是最快的执行就是需要走全表扫描,但是只需要在个别的client中部署即可,这一下子运行了这么多,确实有点异常。和客户那边协调过之后,他们马上从package里面停掉了多余的进程。IO速度一下子好了起来。
在这个过程中,awr报告终于生成了。就来再次印证一下这个问题吧。
首先系统的负载很高,这个没有问题。
Elapsed:   60.12 (mins)    
DB Time:   6,143.79 (mins)    
从整体的Profile来看

系统的物理读很高。每秒达到了 105,583.8,确实是一个很高的值了。
Physical reads: 105,583.8 2,166.4    
在来看看等待事件,就很清楚了。全是Io相关的。
Event Waits Time(s) Avg wait (ms) % DB time Wait Class
db file sequential read 21,816,629 178,657 8 48.47 User I/O
direct path read 1,786,153 60,763 34 16.48 User I/O
read by other session 1,830,998 31,137 17 8.45 User I/O
log file sync 216,111 25,437 118 6.90 Commit
DB CPU   21,645   5.87  
查看time model的时候,可以看到绝大部分的时间都在sql语句的执行上了。
Statistic Name Time (s) % of DB Time
sql execute elapsed time 339,415.91 92.08
DB CPU 21,644.80 5.87

而且这个过程中IO部分占到了70%以上的消耗。
Wait Class Waits %Time -outs Total Wait Time (s) Avg wait (ms) %DB time
User I/O 26,965,785 0 285,901 11 77.56
从上面可以得到,是有一些高IO wait的sql导致了系统极高的物理读,出现了严重的IO等待。
所以在查看sql details的时候直接查看IO wait就可以了。

最后看到前3个都是和那个scanner相关的sql语句。
User I/O Time (s) Executions UIO per Exec (s) %Total Elapsed Time (s) %CPU %IO SQL Id SQL Module SQL Text
19,045.53 42 453.47 6.66 20,884.74 5.34 91.19 4gz51fphuarsw JDBC Thin Client /* scanner.....
16,439.97 43 382.32 5.75 17,683.92 3.00 92.97 6fu3z8pqd2y9g JDBC Thin Client /* scanner.....
16,346.01 43 380.14 5.72 16,687.58 2.76 97.95 fg5mc598u799u JDBC Thin Client select /*+ leading (xxxxbpm...

在停掉了额外消耗的客户端进程后,系统的负载就恢复了正常。
通过这个案例也可以得出,并行的使用也是需要考量的,而且需要平衡系统的资源使用情况。可能看似很小的一个问题放大就是一个很严重的问题。
目录
相关文章
|
2天前
|
SQL 存储 测试技术
SQL在构建系统中的应用:关键步骤与技巧
在构建基于数据库的应用系统时,SQL(Structured Query Language)作为与数据库交互的核心语言,扮演着至关重要的角色
|
19天前
|
SQL 存储 UED
系统里这个同时查冷热表的sql,动动手指,从8s降到3s
系统将交易数据按交易时间分为热表(最近3个月)和冷表(3个月前)。为保证用户体验,当企业门户端查询跨越冷热表时,尤其针对大客户,查询性能优化至关重要。以下是程序的SQL查询语句及其优化版本。
27 1
|
2天前
|
SQL 监控 数据库
管理系统VS SQL:高效集成的关键技巧与方法
在现代企业信息化建设中,管理系统(如ERP、CRM等)与SQL数据库之间的紧密集成是确保数据流动顺畅、业务逻辑高效执行的关键
|
2月前
|
SQL 安全 API
PHP代码审计示例(一)——淡然点图标系统SQL注入漏洞审计
PHP代码审计示例(一)——淡然点图标系统SQL注入漏洞审计
66 4
|
1月前
crash —— 获取系统的磁盘IO统计数据
crash —— 获取系统的磁盘IO统计数据
|
2月前
|
前端开发 Java JSON
Struts 2携手AngularJS与React:探索企业级后端与现代前端框架的完美融合之道
【8月更文挑战第31天】随着Web应用复杂性的提升,前端技术日新月异。AngularJS和React作为主流前端框架,凭借强大的数据绑定和组件化能力,显著提升了开发动态及交互式Web应用的效率。同时,Struts 2 以其出色的性能和丰富的功能,成为众多Java开发者构建企业级应用的首选后端框架。本文探讨了如何将 Struts 2 与 AngularJS 和 React 整合,以充分发挥前后端各自优势,构建更强大、灵活的 Web 应用。
42 0
|
2月前
|
SQL 数据采集 算法
【电商数据分析利器】SQL实战项目大揭秘:手把手教你构建用户行为分析系统,从数据建模到精准营销的全方位指南!
【8月更文挑战第31天】随着电商行业的快速发展,用户行为分析的重要性日益凸显。本实战项目将指导你使用 SQL 构建电商平台用户行为分析系统,涵盖数据建模、采集、处理与分析等环节。文章详细介绍了数据库设计、测试数据插入及多种行为分析方法,如购买频次统计、商品销售排名、用户活跃时间段分析和留存率计算,帮助电商企业深入了解用户行为并优化业务策略。通过这些步骤,你将掌握利用 SQL 进行大数据分析的关键技术。
68 0
|
2月前
|
SQL DataWorks 数据可视化
DataWorks操作报错合集之使用sql查询报错:系统异常,是什么原因
DataWorks是阿里云提供的一站式大数据开发与治理平台,支持数据集成、数据开发、数据服务、数据质量管理、数据安全管理等全流程数据处理。在使用DataWorks过程中,可能会遇到各种操作报错。以下是一些常见的报错情况及其可能的原因和解决方法。
|
3月前
|
Linux 数据处理 C语言
【Linux】基础IO----系统文件IO & 文件描述符fd & 重定向(下)
【Linux】基础IO----系统文件IO & 文件描述符fd & 重定向(下)
62 0
|
3月前
|
缓存 网络协议 算法
【Linux系统编程】深入剖析:四大IO模型机制与应用(阻塞、非阻塞、多路复用、信号驱动IO 全解读)
在Linux环境下,主要存在四种IO模型,它们分别是阻塞IO(Blocking IO)、非阻塞IO(Non-blocking IO)、IO多路复用(I/O Multiplexing)和异步IO(Asynchronous IO)。下面我将逐一介绍这些模型的定义:
149 1