查找运行时间超过 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）或自上次操作以来的总运行时间（如果其状态为 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>

---

“它应该给我查询列表
目前正在执行或已经
最近执行完毕，我可以
查找查询花费的总时间
完成”

了语句执行的最近时间。但是，没有视图可以公开语句的每个单独执行的指标。如果您想要此类详细信息，则需要开始这是一个单独的问题。

Answer 2

使用追踪：

# alter session set timed_statistics = true; 
# alter session set sql_trace = true; 
.....
# show parameter user_dump_dest 
$ tkprof <trc-файл> <txt-файл>