案例背景

环境:hp unix + WAS 6.1 + oracle 问题描述: 现场人员反馈,开启A服务后,B服务挂了,B业务无法正常开展。

分析过程

跟开发了解得知,出问题的系统请求链是这样的,app->A中间服务->B服务。

因此,初步断定,A服务只是请求中介,问题应该不在它身上,而更可能是在B服务本身。

由于现场WAS服务已重启,并未保存当时的快照,因此无法知悉出现问题的时候线程都处于什么状态。

查看native_stderr文件,发现B服务并没有出现内容溢出问题。

查看AWR报告,也未发现跟B业务有关的SQL,但是数据库服务器的负载偏高,TOP 5事件显示,存在一定的缓冲池争用问题。

TOP SQL里面并没有跟B业务有关的。

不过AWR的TOP SQL是按照总时间排序的,因此不排除B业务的慢SQL由于总时间较少,而没有在AWR报告里面体现出来。

第二天,现场再次开启A服务,告知B服务虽然还没死,但是B业务的操作速度都很慢。

查看WAS监控,发现B服务所在Server的线程数已经达到180多个,数据源连接池也到180多个,说明WAS这边都卡住了,而且即将挂起。

查看数据库服务器的资源使用情况,发现CPU使用率已经90%多,而且队列有20多个,负载极高,都是oracle的进程。

查看ORACLE当前正在执行的SQL

SELECT z.SPID AS 操作系统PID
,x.SID
, x.SERIAL#
, x.USERNAME
, x.LOCKWAIT
, x.STATUS
, x.SCHEMANAME
, x.OSUSER
, x.PROCESS
, x.MACHINE
, x.PROGRAM
, x.SQL_ID
, x.SQL_CHILD_NUMBER
, x.PREV_SQL_ID
, CASE x.ROW_WAIT_OBJ# WHEN - 1 THEN NULL ELSE (dbms_rowid.rowid_create (1, ROW_WAIT_OBJ#, ROW_WAIT_FILE#, ROW_WAIT_BLOCK#, ROW_WAIT_ROW#)) END AS rowinfo
, x.LAST_CALL_ET
, x.BLOCKING_SESSION_STATUS
, x.BLOCKING_SESSION
, x.EVENT
, x.WAIT_CLASS
, x.SECONDS_IN_WAIT
, x.STATE
, y.SQL_TEXT
, y.EXECUTIONS
, CASE EXECUTIONS WHEN 0 THEN y.BUFFER_GETS ELSE y.BUFFER_GETS / EXECUTIONS END AS AVG_BUFFER_GETS
, CASE EXECUTIONS WHEN 0 THEN y.DISK_READS ELSE y.DISK_READS / EXECUTIONS END AS AVG_DISK_READS         
, y.ELAPSED_TIME / 1000000 AS AVG_ELAPSED_TIME
, y.CPU_TIME / 1000000 AS AVG_CPU_TIME
FROM v$session x
, v$process z
, v$sql y
WHERE x.PADDR = z.ADDR AND x.SQL_ID = y.SQL_ID 
--AND Z.SPID = 'XXXX' 
AND x.USERNAME='AAAA'
AND x.STATUS = 'ACTIVE'
ORDER BY x.SECONDS_IN_WAIT DESC;

发现绝大多数会话都在执行以下2条SQL,且第2条最多。

update BU_RESERVATION_SALE_MAS set IS_CONFIRM='1', MODIFY_TIME=to_date('2017-08-24 09:17:11', 'yyyy-mm-dd hh24:mi:ss') where BUSINESS_YEAR='2017' and ORG_CD='53032211L' and RS_OPERATOR_CD='8a1190ee43c782db01440a683f2055d7' and IS_CONFIRM='0' and DATA_STATE='0'

select bureservat0_.LEAF_LEVEL_CD as col_0_0_, bureservat0_.LEAF_LEVEL_NO as col_1_0_, bureservat0_.LEAF_LEVEL_NAME as col_2_0_ from BU_RESERVATION_SALE_DETAIL bureservat0_ where bureservat0_.RESERVATION_SALE_MAS_ID='8a1190ee5e0ac797015e0c3cf62e04e3' and bureservat0_.DATA_STATE='0'

查看这2条SQL的执行计划,发行存在全表扫描问题,其中 主表有6万行记录,从表则有34万行记录。

查看AWR报告,发现此时数据库负载极高,而且TOP 5事件显示,系统的瓶颈可能出现在缓冲池上面。

TOP SQL中有大量Executions=0的SQL,说明这些SQL还在执行中,但是这些SQL跟B业务也没什么关系。

以上综合分析,怀疑可能是B业务的SQL没有索引,导致全表扫描,在较大量并发请求的压力下,出现缓冲池紧张,进而导致整个数据库响应缓慢。

解决问题

尝试在现场库上加上B业务主从表的2个索引,数据库服务器的CPU很快降了下来,降到20%左右。

现场反馈,B业务也能正常开展了。

总结

1.数据库表不要忘了建索引,尤其是主从表的连接键; 2.oracle AWR报告体现的TOP SQL是按照总资源耗用倒序排序的,对于一些执行次数还不够多,总资源消耗不够多的SQL,可能并没有展示出来,这一点要注意; 3.AWR报告看不出来的问题,可以通过查当前进程会话的方式,检查oracle当前正在忙着做什么;