一次监控系统进程影响的业务响应的问题及解决

sjk2013

浏览: 2182695 次

最近访客更多访客>>

BDQN磊

w11h22j33

devcang

hedgehog12

博主相关

博客

微博

相册

留言

关于我

文章分类

全部博客 (3465)

社区版块

存档分类

2014-05 ( 13)
2014-04 ( 74)
2014-03 ( 72)
更多存档...

也是十一期间，业务反应出帐过程中某程序执行特别慢，怀疑是oracle数据库有问题，需要尽快处理，根据业务提供的相关信息，相关业务从wwzg3主机发起，业务主要使用了账本通知表www_BOOK_CHG_NOTIFY和短信表WWW.www_busi_sms。
提供了一个sql语句
select *
from WWW.www_book_scheme_fee_0104 a,
WWW.www_book_scheme_rec_0104 b,
WWW.crm_user c
where a.so_nbr = b.so_nbr
and a.wwwt_id = c.wwwt_id
and a.after_month <= to_char(sysdate, 'yyyymm')
and c.phone_id = b.phone_id
and b.sts = 0

and a.sts = 0;

1，登录数据库主机，发现主机资源充足，系统资源不存在瓶颈，CPU利用率只有40%
SQL> !sar -u 3 5

HP-UX wbdb1 B.11.31 U ia64 10/04/12

12:24:01 %usr %sys %wio %idle
12:24:04 27 4 8 60
12:24:07 30 3 7 60
12:24:10 28 2 8 62
12:24:13 30 4 10 56
12:24:16 30 3 10 57

Average 29 3 9 59
2，开发提供的sql执行速度特别快，相关业务表唯一有点异常的sql执行计划如下,基本上都是全表扫描，但目前数据库中没有发现该语句正在运行
因此排除

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------

---------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                         | Name                     | Rows  | Bytes |TempSpc| Cost (%CPU)| Pstart| Pstop |
---------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                  |                          |     1 |   430 |       | 87768   (1)|       |       |
|   1 |  TABLE wwwESS BY LOCAL INDEX ROWID| CRM_USER                 |     1 |    20 |       |    21   (0)|       |       |
|   2 |   NESTED LOOPS                    |                          |     1 |   430 |       | 87768   (1)|       |       |
|   3 |    HASH JOIN                      |                          |   385 |   154K|  2832K| 79678   (1)|       |       |
|   4 |     HASH JOIN                     |                          | 10999 |  2696K|   343M| 75513   (1)|       |       |
|   5 |      MERGE JOIN CARTESIAN         |                          |  5634K|   279M|       | 20348   (1)|       |       |
|   6 |       TABLE wwwESS FULL           | www_BOOK_SCHEME_COND     |  2189 | 32835 |       |    39   (0)|       |       |
|   7 |       BUFFER SORT                 |                          |  2574 | 95238 |       | 20309   (1)|       |       |
|   8 |        TABLE wwwESS FULL          | www_BOOK_SCHEME_SAP_MAP  |  2574 | 95238 |       |     9   (0)|       |       |
|   9 |      TABLE wwwESS FULL            | www_BOOK_SCHEME_REC_0104 |  2306K|   437M|       | 14986   (2)|       |       |
|  10 |     TABLE wwwESS FULL             | www_BOOK_SCHEME_FEE_0104 | 80636 |    12M|       |  3373   (2)|       |       |
|  11 |    PARTITION RANGE ALL            |                          |     1 |       |       |    20   (0)|     1 |    10 |
|  12 |     INDEX RANGE SCAN              | IDX_USER_PHONE           |     1 |       |       |    20   (0)|     1 |    10 |
---------------------------------------------------------------------------------------------------------------------------

3，数据库中的top 10 sql看，没有发现来自wwzg3主机的异常sql，基本上都来自wbzc4

awr本处省略
4，通过以上推断，数据库没有任何问题，于是转向查看运行相关进程的主机是否异常，果然问题不在数据库，在wwzg3主机资源利用率过高，系统利用率100%
CPU利用率100%，被%sys消耗，
root@wwzg3[/]#sar -u 3 5

HP-UX wwzg3 B.11.31 U ia64 10/04/12

13:47:38 %usr %sys %wio %idle
13:47:41 30 70 0 0
13:47:44 30 70 0 0
13:47:47 30 69 0 0
13:47:50 31 69 0 0
13:47:53 30 69 0 1

Average 30 69 0 0

5，262个idcp.sh进程正在运行
root@wwzg3[/]#ps -ef|grep idcp.sh|wc -l
262

root 20282 10168 1 13:55:30 pts/17 0:00 grep 7675
root@wwzg3[/]#ps -ef|grep idcp.sh
root 10315 10146 0 13:55:40 ? 0:00 /usr/bin/sh /home/patrol/IDCPCM/main/idcp.sh
root 9848 9803 253 20:40:00 ? 25:36 /usr/bin/sh /home/patrol/IDCPCM/main/idcp.sh
root 29251 29179 251 19:10:00 ? 30:05 /usr/bin/sh /home/patrol/IDCPCM/main/idcp.sh
root 19055 3432 0 16:40:00 ? 0:00 sh -c /home/patrol/IDCPCM/main/idcp.sh 1>/dev/null 2>/dev/null
root 13603 3432 0 15:50:00 ? 0:00 sh -c /home/patrol/IDCPCM/main/idcp.sh 1>/dev/null 2>/dev/null
root 13384 3432 0 18:20:00 ? 0:00 sh -c /home/patrol/IDCPCM/main/idcp.sh 1>/dev/null 2>/dev/null
root 26541 3432 0 15:20:00 ? 0:00 sh -c /home/patrol/IDCPCM/main/idcp.sh 1>/dev/null 2>/dev/null
root 29340 29289 252 21:10:00 ? 24:36 /usr/bin/sh /home/patrol/IDCPCM/main/idcp.sh
root 22296 22236 251 18:00:00 ? 34:44 /usr/bin/sh /home/patrol/IDCPCM/main/idcp.sh
root 10677 10653 252 21:00:00 ? 23:38 /usr/bin/sh /home/patrol/IDCPCM/main/idcp.sh
root 20122 3432 0 21:20:00 ? 0:00 sh -c /home/patrol/IDCPCM/main/idcp.sh 1>/dev/null 2>/dev/null
root 25174 25034 250 07:00:00 ? 6:48 /usr/bin/sh /home/patrol/IDCPCM/main/idcp.sh
root 6585 6499 251 03:20:00 ? 11:50 /usr/bin/sh /home/patrol/IDCPCM/main/idcp.sh
root 10206 10177 0 13:55:39 ? 0:00 /usr/bin/sh /home/patrol/IDCPCM/main/idcp.sh
root 25419 25344 253 21:40:00 ? 21:52 /usr/bin/sh /home/patrol/IDCPCM/main/idcp.sh
root 27135 3432 0 17:00:01 ? 0:00 sh -c /home/patrol/IDCPCM/main/idcp.sh 1>/dev/null 2>/dev/null
root 10347 944 0 13:55:40 ? 0:00 /usr/bin/sh /home/patrol/IDCPCM/main/idcp.sh
root 10167 10166 0 13:55:39 ? 0:00 /usr/bin/sh /home/patrol/IDCPCM/main/idcp.sh
root 25569 3432 0 18:30:00 ? 0:00 sh -c /home/patrol/IDCPCM/main/idcp.sh 1>/dev/null 2>/dev/null
root 10256 2025 0 13:55:40 ? 0:00 /usr/bin/sh /home/patrol/IDCPCM/main/idcp.sh
root 29111 29082 252 20:50:00 ? 24:08 /usr/bin/sh /home/patrol/IDCPCM/main/idcp.sh
6，该进程每隔10分钟会起一个定时任务，但从上面的进程看，昨天开始运行的进程都还没有执行结束，异常原因未知
#BOMC
30 2 * * * /home/patrol/CM/up_bin/get_cm.sh 1>/dev/null 2>&1
0,10,20,30,40,50 * * * * /home/patrol/IDCPCM/main/idcp.sh 1>/dev/null 2>/dev/null

7，kill 相关异常进程，为了防止问题再次发生，手工注释掉了该job的自动运行，系统恢复了正常
#BOMC
30 2 * * * /home/patrol/CM/up_bin/get_cm.sh 1>/dev/null 2>&1
#0,10,20,30,40,50 * * * * /home/patrol/IDCPCM/main/idcp.sh 1>/dev/null 2>/dev/null

改进措施
自动运行的监控脚本一直处于正常运行状态，很难定位具体异常的原因了。因此为了防止类似问题发生，对脚本程序进行了修改，增加了判断语句
前一个调度如果还没有执行完，则强制退出脚本，重新执行，并添加了日志记录
IDCPNUM=`ps -ef|grep idcp.sh|grep -v grep|wc -l|awk '{ print $1 }'`
if [ $IDCPNUM -ge 1 ]; then
ps -ef |grep idcp.sh |awk '{system("kill -9 "$2)}'
sleep 10
cd $TMDR
rm PM*.txt
fi

总结：业务反应数据库慢，其实可能根本不是数据库的问题，要综合分析判断，本次问题其实就出在访问数据库的客户端所在的主机太忙。

分享到：