查找运行超过5秒的查询

Question

我的朋友要求我在他的oracle数据库上找到长时间运行的查询(超过5秒).他希望在定期间隔之后进行某种轮询,并希望向自己发送警报,以便他知道哪个查询花了这么长的时间来执行并向他发送查询和相应的会话.

我写了这个Oracle查询:

    select    sess.sid,
    sess.username,
    sess.paddr,
    sess.machine,
    optimizer_mode,
    sess.schemaname,
    hash_value,
    address,
    sess.sql_address,
    cpu_time,
    elapsed_time,
    sql_text
from    v$sql sql, v$session sess
where 
        sess.sql_hash_value = sql.hash_value
    and     sess.sql_address = sql.address
    and     sess.username is not null
    and     elapsed_time > 1000000  * 5
order by    
    cpu_time desc

但是他说,当他手动运行查询并计算时间时,执行它所花费的时间只是他从这个特定查询生成的表中得到的结果的一小部分.

我想知道我的查询是否错误,我做了一些搜索,但似乎查询仍然没问题.

数据库是Oracle 10g

建议???

Answer 1

ELAPSED_TIME是SQL语句运行的所有时间的累计时间.因此,频繁执行的查询会很高.

考虑这是一个快速查询(HINT样式的注释是为了在V $ SQLAREA中获取SQL_ID):

select /*+ fast_running_query */ id
from big_table
where id = 1
/

运行需要多长时间？这个长:

SQL> select elapsed_time
  2         , executions
  3         , elapsed_time / executions as avg_ela_time
  4  from v$sqlarea
  5  where sql_id = '73c1zqkpp23f0'
  6  /

ELAPSED_TIME EXECUTIONS AVG_ELA_TIME
------------ ---------- ------------
      235774          1       235774

SQL> 

由于解析时间的原因,这是一个相对较大的微块.我们可以看到,运行它几次并不会增加经过的时间,而且平均值要低得多:

SQL> r
  1  select elapsed_time,
  2         executions,
  3         elapsed_time / executions as avg_ela_time
  4  from v$sqlarea
  5* where sql_id = '5v4nm7jtq3p2n'

ELAPSED_TIME EXECUTIONS AVG_ELA_TIME
------------ ---------- ------------
      237570          3        79190

SQL>

再运行100000次......

SQL> r
  1  select elapsed_time,
  2         executions,
  3         elapsed_time / executions as avg_ela_time
  4  from v$sqlarea
  5* where sql_id = '5v4nm7jtq3p2n'

ELAPSED_TIME EXECUTIONS AVG_ELA_TIME
------------ ---------- ------------
     1673900     100003   14.3809724

SQL>

现在,您想要的是找到连续执行超过五秒的活动会话.因此,您需要会话级时序,特别是V $ SESSION上的LAST_CALL_ET,这是会话执行某些操作的秒数(如果其状态为ACTIVE)或自上次操作以来的总耗用时间(如果其状态)是不活跃的).

select sid
       , serial#
       , sql_address
       , last_call_et
from v$session
where status = 'ACTIVE'
and last_call_et > sysdate - (sysdate-(5/86400))
/

所以,请考虑这个查询.这很慢:

SQL> select /*+ slow_running_query */ *
  2  from big_table
  3  where col2 like '%whatever%'
  4  /

no rows selected

Elapsed: 00:00:07.56
SQL>

这足以监视在V $ SESSION上使用查询.这个搜索已运行超过3秒的语句...

SQL> select sid
  2         , serial#
  3         , sql_id
  4         , last_call_et
  5  from v$session
  6  where status = 'ACTIVE'
  7  and last_call_et > sysdate - (sysdate - (3/86400))
  8  and username is not null
  9  /

       SID    SERIAL# SQL_ID        LAST_CALL_ET
---------- ---------- ------------- ------------
       137          7 096rr4hppg636            4
       170          5 ap3xdndsa05tg            7

SQL>

而且!

SQL> select sql_text from v$sqlarea where sql_id = 'ap3xdndsa05tg'
  2  /

SQL_TEXT
--------------------------------------------------------------------------------
select /*+ slow_running_query */ * from big_table where col2 like '%whatever%'

SQL>

"它应该给我当前正在执行或最近完成执行的查询列表,我可以找到查询完成的总时间"

V $ SQLAREA视图上的LAST_ACTIVE_TIME记录了语句执行的最近时间.但是,没有任何视图公开每个单独执行语句的度量标准.如果您需要这种细节,则需要开始跟踪.这是一个单独的问题.