一次监控系统进程影响的业务响应的问题及解决也是十一期间,业务反应出帐过程中某程序执行特别慢,怀疑是oracle数据库有问题,需要尽快处理,根据业务提供的相关信息,相关业务从wwzg3主机发起,业务主要使用了账...SyntaxHighlighter.all();
一次监控系统进程影响的业务响应的问题及解决
也是十一期间,业务反应出帐过程中某程序执行特别慢,怀疑是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, &#39;yyyymm&#39;)
and c.phone_id = b.phone_id
and b.sts = 0
and a.sts = 0;
www.2cto.com
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执行计划如下,基本上都是全表扫描,但目前数据库中没有发现该语句正在运行 www.2cto.com
因此排除
[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 |
---------------------------------------------------------------------
www.2cto.com
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
www.2cto.com
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
www.2cto.com
改进措施
自动运行的监控脚本一直处于正常运行状态,很难定位具体异常的原因了。因此为了防止类似问题发生,对脚本程序进行了修改,增加了判断语句
前一个调度如果还没有执行完,则强制退出脚本,重新执行,并添加了日志记录
IDCPNUM=`ps -ef|grep idcp.sh|grep -v grep|wc -l|awk &#39;{ print $1 }&#39;`
if [ $IDCPNUM -ge 1 ]; then
ps -ef |grep idcp.sh |awk &#39;{system("kill -9 "$2)}&#39;
sleep 10
cd $TMDR
rm PM*.txt
fi
总结:业务反应
数据库慢,其实可能根本不是数据库的问题,要综合分析判断,本次问题其实就出在访问数据库的客户端所在的主机太忙。