由一条sql语句导致的系统IO问题(r3笔记第31天)
早上来到公司,照例进行了简单的检查,发现系统负载不高,就开始计划一些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多个。
通过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... |
在停掉了额外消耗的客户端进程后,系统的负载就恢复了正常。 通过这个案例也可以得出,并行的使用也是需要考量的,而且需要平衡系统的资源使用情况。可能看似很小的一个问题放大就是一个很严重的问题。
- VList data structures in C#
- 编程思想 之「语言导论」
- 编程思想 之「对象漫谈」
- Github 项目推荐 | TensorFlow 概率推理工具集 —— probability
- Github 项目推荐 | 用于 C/C++、Java、Matlab/Octave 的特征选择工具箱
- Mercari Price 比赛分享 —— 语言不仅是算法和公式而已
- Github 项目推荐 | GAN 的 Keras 实现案例集合 —— Keras-GAN
- Github 项目推荐 | 微软开源 MMdnn,模型可在多框架间转换
- 半自动化运维之动态添加数据文件(一) (r5笔记第55天)
- 半自动化运维之动态添加数据文件(二) (r5笔记第56天)
- 11g Active DataGuard初探(r5笔记第54天)
- Github 项目推荐 | 用于构建端对端对话系统和训练聊天机器人的开源库 —— DeepPavlov
- 我身边的一些数据库事故 (r5笔记第52天)
- 一个清理脚本的改进思路(r5笔记第51天)
- JavaScript 教程
- JavaScript 编辑工具
- JavaScript 与HTML
- JavaScript 与Java
- JavaScript 数据结构
- JavaScript 基本数据类型
- JavaScript 特殊数据类型
- JavaScript 运算符
- JavaScript typeof 运算符
- JavaScript 表达式
- JavaScript 类型转换
- JavaScript 基本语法
- JavaScript 注释
- Javascript 基本处理流程
- Javascript 选择结构
- Javascript if 语句
- Javascript if 语句的嵌套
- Javascript switch 语句
- Javascript 循环结构
- Javascript 循环结构实例
- Javascript 跳转语句
- Javascript 控制语句总结
- Javascript 函数介绍
- Javascript 函数的定义
- Javascript 函数调用
- Javascript 几种特殊的函数
- JavaScript 内置函数简介
- Javascript eval() 函数
- Javascript isFinite() 函数
- Javascript isNaN() 函数
- parseInt() 与 parseFloat()
- escape() 与 unescape()
- Javascript 字符串介绍
- Javascript length属性
- javascript 字符串函数
- Javascript 日期对象简介
- Javascript 日期对象用途
- Date 对象属性和方法
- Javascript 数组是什么
- Javascript 创建数组
- Javascript 数组赋值与取值
- Javascript 数组属性和方法
- 机器学习Tips:关于Scikit-Learn的 10 个小秘密
- R语言ggmap空间可视化机动车碰撞–街道地图热力图
- R语言ggmap空间可视化机动车交通事故地图
- 基于matlab的Lorenz系统仿真可视化
- 使用R语言对进行空间数据可视化
- R语言中基于混合数据抽样(MIDAS)回归的HAR-RV模型预测GDP增长
- R语言马尔可夫体制转换模型Markov regime switching
- Python中的ARIMA模型、SARIMA模型和SARIMAX模型对时间序列预测
- python3用ARIMA模型进行时间序列预测
- R语言马尔可夫转换模型研究交通伤亡人数事故预测
- scrapy爬虫框架和selenium的使用:对优惠券推荐网站数据LDA文本挖掘
- 使用R语言进行Metroplis-in-Gibbs采样和MCMC运行分析
- R语言中的马尔科夫机制转换(Markov regime switching)模型
- R语言ARMA-EGARCH模型、集成预测算法对SPX实际波动率进行预测
- nginx快速入门