2017-06-20

Visualizing slow sql execution

A slow sql execution vanished from sql monitor. Take a look from awr. It was almost six hours of execution time. Which sql plan lines was the execution spending its time?
select sql_plan_line_id
     , cnt
     , mi
     , mx
     , trim(rpad(' ',((aa-sta)/nullif(aa,0))*len,'-'))
     || trim(rpad(' ',((sta-sto)/nullif(aa,0))*len,'*'))
     || trim(rpad(' ',(sto/nullif(aa,0))*len,'-')) t
from (
select 80 len
     , sql_exec_start
     , sql_plan_line_id
     , cnt
     , to_char(mis,'hh24:mi:ss') mi
     , to_char(mxs,'hh24:mi:ss') mx
     , max(mxs)over(partition by sql_exec_start)-min(mis)over(partition by sql_exec_start) dur
     , max(cast(mxs as date))over(partition by sql_exec_start)-min(cast(mis as date))over(partition by sql_exec_start) aa
     , max(cast(mxs as date))over(partition by sql_exec_start)-cast(mis as date) sta
     , max(cast(mxs as date))over(partition by sql_exec_start)-cast(mxs as date) sto
from (
select sql_exec_start
     , sql_plan_line_id
     , count(*) cnt
     , min(sample_time) mis
     , max(sample_time) mxs
  from dba_hist_active_sess_history 
 where sql_plan_hash_value = 917708421
   and sql_id = 'cnf5jz56h4swp'
   and trunc(sample_time) = date'2017-01-20'
 group by sql_exec_start,sql_plan_line_id 
)
)
order by sql_exec_start,sql_plan_line_id
;
PLANLINEID CNT    MI          MX          T      
1          2      16:21:42    16:23:02    ----------------------------------------------------------------------------
3          155    09:18:25    16:22:52    --**************************************************************************
4          8      11:37:38    16:11:21    ---------------------------************************************************-
5          1      13:03:45    13:03:45    ----------------------------------------------------------------------------
8          16     09:00:34    14:38:03    ***********************************************************-----------------
11         2      09:00:24    09:00:54    ----------------------------------------------------------------------------
12         4      09:01:04    09:01:34    ----------------------------------------------------------------------------
13         1      10:03:09    10:03:09    ----------------------------------------------------------------------------
14         36     09:11:15    14:47:54    ***********************************************************-----------------
15         697    09:02:54    14:48:24    *************************************************************---------------
16         469    09:01:44    14:48:44    *************************************************************---------------
17         2      12:43:53    14:40:23    ---------------------------------------********************-----------------
18         27     09:50:58    14:37:53    --------**************************************************------------------
19         557    09:04:24    14:48:34    *************************************************************---------------
20         235    09:02:14    14:45:54    *************************************************************---------------
21         29     09:45:38    14:42:23    -------****************************************************-----------------
22         345    14:50:24    16:20:32    --------------------------------------------------------------**************
24         10     14:48:54    14:50:44    ----------------------------------------------------------------------------
25         1      14:49:44    14:49:44    ----------------------------------------------------------------------------
26         15     14:57:55    15:05:25    ----------------------------------------------------------------------------
27         2      14:50:54    14:51:04    ----------------------------------------------------------------------------
28         1      14:57:35    14:57:35    ----------------------------------------------------------------------------
29         1      14:54:04    14:54:04    ----------------------------------------------------------------------------
30         12     14:51:54    14:53:54    ----------------------------------------------------------------------------
31         5      14:51:14    14:52:14    ----------------------------------------------------------------------------
32         11     14:55:35    14:57:25    ----------------------------------------------------------------------------
34         7      14:54:35    14:55:45    ----------------------------------------------------------------------------
35         1      14:54:14    14:54:14    ----------------------------------------------------------------------------
36         1      14:54:25    14:54:25    ----------------------------------------------------------------------------

No comments:

Post a Comment

About Me

My photo
I am Timo Raitalaakso. I have been working since 2001 at Solita Oy as a Senior Database Specialist. I have received Oracle ACE nomination. My main focus is on projects involving Oracle database. In this Rafu on db blog I write some interesting issues that evolves from my interaction with databases. Mainly Oracle.