ITPub博客

首页 > 数据库 > Oracle > 一次数据库响应慢的问题诊断

一次数据库响应慢的问题诊断

原创 Oracle 作者:jeanron100 时间:2015-08-25 22:53:25 0 删除 编辑
今天接到开发一个同事的电话,说前端系统那边反馈有一个查询很慢,初步怀疑是有一些并发或者锁之类的问题导致的。
接到问题之后,自己还是带着一些的紧迫感来处理的。
首先查看资源使用情况,使用top来检查,结果发现CPU使用率也不高,都在90%以上的idle
查看数据库的DB time情况,发现数据库的负载其实不高,但是还是有所提高,需要进一步关注。

查看锁等待情况,也没有任何的事务和锁等待。
查看session的使用情况发现并发量其实很低,TPS的值非常低。

为了进一步验证,抓取了近几个小时的日志归档情况和redo的生成量情况,发现归档基本就是1个小时1次,所以暂时也没有发现异常的活动。
这就有些奇怪了。session使用率不高,并发不高,CPU使用率也不高,没有锁等待,redo生成量也不高,到底是怎么回事呢。
进一步和开发同时进行沟通,他们反馈说在前端的页面查询会触发一个表的查询,那个表其实也不大,而且在查询中还是使用索引列的,所以查询应该不会有什么问题。
但是点击查询的时候就会一直卡在那儿。所以想让我们来看看到底数据库层面发生了什么。
首先肯定告诉她的是,数据库的负载和使用率其实并不高,而且并发事务和session使用率也很低,可以基本排除是并发和数据库负载导致的问题。
过了几分钟之后,开发给我的反馈是查询有结果了,但是又过了几分钟,又反馈说查询又没有反应了。
这种情况下,再次查看资源的使用情况和原来一样,但是他们也想知道可能是什么原因导致的问题,
看来常规的思路还是不够快准狠,我们来试试ash快速查询。
SELECT /* use_hash(sess,proc,undo,tmp) use_nl(s)*/ distinct
        sess.inst_id,
        sess.sid,
        sess.serial#,
        sess.username,
        substr(osuser,1,10) osuser,
        status,
        sess.process,
        proc.spid,
        sess.machine,
        sess.program,
        regexp_substr(NUMTODSINTERVAL(nvl((SYSDATE-SQL_EXEC_START)*24*60*60,last_call_et), 'SECOND'),'+\d{2} \d{2}:\d{2}:\d{2}') running_sec,
        TEMP_MB, UNDO_MB,
        s.sql_id ,
        TSPS.NAME TSPS,
        decode(sess.action,null,'',sess.action||', ')||replace(s.sql_text,chr(13),' ') sql
FROM
        gv$session sess,
        gv$process proc,
        gv$sql s,
        (select ses_addr as saddr,sum(used_ublk/128) UNDO_MB from v\$transaction group by ses_addr) undo,
        (select session_addr as saddr, SESSION_NUM serial#, sum((blocks/128)) TEMP_MB from gv$sort_usage group by  session_addr, SESSION_NUM) tmp,
        (select inst_id,sid,serial#,event,t.name from gv$session ls, sys.file$ f, sys.ts$ t where status='ACTIVE' and ls.p1text in ('file number','file#') and ls.p1=f.file#  and f.ts#=t.ts#) tsps
WHERE sess.inst_id=proc.inst_id (+)  
and   sess.saddr=tmp.saddr (+) and sess.serial#=tmp.serial# (+)
AND   sess.status='ACTIVE' and sess.username is not null
and   sess.sid=tsps.sid (+) and sess.inst_id=tsps.inst_id(+) and sess.serial#=tsps.serial#(+)
AND   sess.paddr=proc.addr (+)
and   sess.sql_id = s.sql_id (+)
and   sess.saddr=undo.saddr (+)
ORDER BY running_sec desc,4,1,2,3

通过这个语句能够查看到当前数据库中的active session的情况,但是有些遗憾的是只发现了两个active session都在进行有些相似的多表关联查询。
当然这个select语句常理是不会阻塞另外一个select语句的,所以也就没有太多的关注,但是和开发人员反反复复排查了几次,发现的规律就是那个查询完成之后,得到的反馈是前端的页面查询马上就正常了。

这个时候不得不怀疑是这个查询语句的影响了。数据库负载很低,也不至于一个查询语句就会这么影响全局吧。我也这个发现和开发同事做了反馈,他们也认为应该没有关系。但是逐步的分析,我发现如果这个查询会阻塞另外一个查询,那么只有一个原因,那就是前端的触发的那个select一定是在等待这个复杂的select完成才会触发。它们应该是在一个类似事务的流程之内。如果说是一个事务还是不严谨的,如果是事务,问题就好办了,我们可以通过闪回事务来印证他们是在一个事务的,这个地方实在是无能为力。
为了验证这个想法,我把复杂查询对应的用户名,os用户,客户端machine等等明细的信息进行了整理,发现和开发反馈的时间点基本是吻合的,而且它们是从同一个客户端触发的,远程的machine名都是同一个,上下文环境很相似,所以通过这个也可以佐证我的想法了,对于这个问题的进一步分析,为什么那个查询会持续那么长时间,抓取了对应的执行计划,发现相关的几个大表都走了全表扫描。
-------------------------------------------------------------------------------
| Id  | Operation                        | Name                | Rows  | Bytes 
-------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                 |                     |       |       
|   1 |  HASH GROUP BY                   |                     |     1 |   332 
|*  2 |   HASH JOIN                      |                     |     1 |   332 
|   3 |    NESTED LOOPS OUTER            |                     |     1 |   300 
|   4 |     NESTED LOOPS                 |                     |     1 |   192 
|   5 |      NESTED LOOPS                |                     |     1 |   174 
|   6 |       TABLE ACCESS FULL          | M_POOL_TEST         |  2420 | 67760 
|*  7 |       TABLE ACCESS BY INDEX ROWID| TES_BASE            |     1 |   146 
|*  8 |        INDEX RANGE SCAN          | IND_TES_BASE_AK     |     1 |       
|*  9 |      TABLE ACCESS BY INDEX ROWID | M_TEST_APP          |     1 |    18 
|* 10 |       INDEX UNIQUE SCAN          | PK_M_TEST_APP       |     1 |       
|* 11 |     TABLE ACCESS BY INDEX ROWID  | TES_EXTEND          |     1 |   108 
|* 12 |      INDEX RANGE SCAN            | IND_TES_EXTEND_RID  |     1 |       
|  13 |    TABLE ACCESS FULL             | M_POOL_TEST_CHANNEL |   398 | 12736 

所以后续的分析就是来看看这个查询是否是新增的需求,为什么之前没有碰到这个问题,这两个全表扫描的表都是大表,所以查询时间自然少不了。
可以进一步来分析为什么走了全表扫描,怎么尝试来优化sql了。
所以数据库负载低,资源使用率低,照样也可能造成响应慢的问题,都需要DBA进行关注。

来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/23718752/viewspace-1782660/,如需转载,请注明出处,否则将追究法律责任。

请登录后发表评论 登录
全部评论
技术文章每天更新,阵地已转移到微信公众号端。 公众号:jianrong-notes

注册时间:2012-05-14

  • 博文量
    1498
  • 访问量
    14395176