Montando Matriz com Histórico de Execuções de um SQL ID no AWR

Quando estou analisando um incidente de performance envolvendo algum processo específico, ou até mesmo após identificar um TOP SQL em um relatório AWR, uma das abordagens que costumo utilizar para identificar rapidamente se o comando SQL teve algum desvio de comportamento nos últimos dias, é gerar algumas matrizes com os valores de quantidade de execuções por hora, assim como o tempo médio de execuções em cada hora do dia. Neste modelo, eu consigo ter uma visão global do histórico do SQL sem precisar ficar gerando vários relatórios AWR e compará-los individualmente.

Neste post, compartlho duas queries que montam uma matriz com as métricas de um SQL armazenadas no AWR (DBA_HIST_SQLSTAT) e que podem ser úteis para fazer esse comparativo inicial, antes de partir para uma análise mais detalhada sobre outros fatores que possam influenciar no comportamento de uma query.

1) Matriz com número de execuções por data e hora

script: execs.sql

/*
 Script para gerar uma matriz com a contagem de execucoes do SQL ID por dia e hora
 Sintaxe: SQL>@execs <SQL_ID> <Qtd. Dias> <Inst ID> (Onde Inst ID = 0 soma todas as instancias do cluster)
 Exemplo: SQL>@execs @execs c3bpu9sapxhpw 10 1 
 
 Maicon Carneiro | Salvador-BA, 11/11/2022
*/

set verify off
set feedback off
alter session set nls_date_format='dd/mm Dy';
set sqlformat 
set pages 999 lines 400
col snap_date heading "Date" format a10
col h0  format 999,999
col h1  format 999,999
col h2  format 999,999
col h3  format 999,999
col h4  format 999,999
col h5  format 999,999
col h6  format 999,999
col h7  format 999,999
col h8  format 999,999
col h9  format 999,999
col h10 format 999,999
col h11 format 999,999
col h12 format 999,999
col h13 format 999,999
col h14 format 999,999
col h15 format 999,999
col h16 format 999,999
col h17 format 999,999
col h18 format 999,999
col h19 format 999,999
col h20 format 999,999
col h21 format 999,999
col h22 format 999,999
col h23 format 999,999
set feedback ON

-- obtem o nome da instancia
column NODE new_value VNODE 
SET termout off
SELECT CASE WHEN &3 = 0 THEN 'Cluster' ELSE instance_name || ' / ' || host_name END AS NODE FROM GV$INSTANCE WHERE (&3 = 0 or inst_id = &3);
SET termout ON

-- resumo do relatorio
PROMP
PROMP Metrica...: Executions
PROMP SQL ID....: &1
PROMP Qt. Dias..: &2 
PROMP Instance..: &VNODE
PROMP

-- query
with awr as (
  select a.sql_id, a.snap_id, b.begin_interval_time as begin_snap,
	     sum(executions_delta)                                            as execs,
	     sum(elapsed_time_delta/1000) / greatest(sum(executions_delta),1) as Elapsed_Time
	from dba_hist_sqlstat a
	join dba_hist_snapshot b on (a.snap_id = b.snap_id and a.instance_number = b.instance_number)
	where 1=1
	and sql_id in ('&1')
	--and executions_delta > 0
	and (&3 = 0 or b.instance_number = &3)
	and b.begin_interval_time >= trunc(sysdate) - &2
	group by a.sql_id, a.snap_id, b.begin_interval_time
)
SELECT TRUNC(begin_snap) snap_date,
 SUM (DECODE (TO_CHAR (begin_snap, 'hh24'), '00', execs, null)) "h0",
 SUM (DECODE (TO_CHAR (begin_snap, 'hh24'), '01', execs, null)) "h1",
 SUM (DECODE (TO_CHAR (begin_snap, 'hh24'), '02', execs, null)) "h2",
 SUM (DECODE (TO_CHAR (begin_snap, 'hh24'), '03', execs, null)) "h3",
 SUM (DECODE (TO_CHAR (begin_snap, 'hh24'), '04', execs, null)) "h4",
 SUM (DECODE (TO_CHAR (begin_snap, 'hh24'), '05', execs, null)) "h5",
 SUM (DECODE (TO_CHAR (begin_snap, 'hh24'), '06', execs, null)) "h6",
 SUM (DECODE (TO_CHAR (begin_snap, 'hh24'), '07', execs, null)) "h7",
 SUM (DECODE (TO_CHAR (begin_snap, 'hh24'), '08', execs, null)) "h8",
 SUM (DECODE (TO_CHAR (begin_snap, 'hh24'), '09', execs, null)) "h9",
 SUM (DECODE (TO_CHAR (begin_snap, 'hh24'), '10', execs, null)) "h10",
 SUM (DECODE (TO_CHAR (begin_snap, 'hh24'), '11', execs, null)) "h11",
 SUM (DECODE (TO_CHAR (begin_snap, 'hh24'), '12', execs, null)) "h12",
 SUM (DECODE (TO_CHAR (begin_snap, 'hh24'), '13', execs, null)) "h13",
 SUM (DECODE (TO_CHAR (begin_snap, 'hh24'), '14', execs, null)) "h14",
 SUM (DECODE (TO_CHAR (begin_snap, 'hh24'), '15', execs, null)) "h15",
 SUM (DECODE (TO_CHAR (begin_snap, 'hh24'), '16', execs, null)) "h16",
 SUM (DECODE (TO_CHAR (begin_snap, 'hh24'), '17', execs, null)) "h17",
 SUM (DECODE (TO_CHAR (begin_snap, 'hh24'), '18', execs, null)) "h18",
 SUM (DECODE (TO_CHAR (begin_snap, 'hh24'), '19', execs, null)) "h19",
 SUM (DECODE (TO_CHAR (begin_snap, 'hh24'), '20', execs, null)) "h20",
 SUM (DECODE (TO_CHAR (begin_snap, 'hh24'), '21', execs, null)) "h21",
 SUM (DECODE (TO_CHAR (begin_snap, 'hh24'), '22', execs, null)) "h22",
 SUM (DECODE (TO_CHAR (begin_snap, 'hh24'), '23', execs, null)) "h23"
FROM awr
GROUP BY TRUNC(begin_snap)
order by 1;

Exemplo de uso:

SQL> @execs <SQL ID> <days> <inst_id>

Em inst_id, deve ser informando um número de instância do RAC (1,2,3,4, etc). Para considerar todas as instâncias do cluster (equivalente a um AWR Global), informe o valor 0.

Demonstração abaixo com imagem cortada para melhorar visualização no blog:

Neste exemplo, estou gerando uma matriz para o SQL ID 2a5z3x7187rxz com os últimos 30 dias de AWR, considerando as métricas globais do RAC (inst_id = 0)

Com a visão acima, é possível observar rapidamente que o SQL_ID é executado praticamente durante todas as 24h do dia, mas tem um volume muito maior a partir das 7h da manhã, e aumento ainda mais a partir das 10h.

2) Matriz com o tempo médio de execução do SQL por Data e Hora

script: elap.sql

/*
 Script para gerar uma matriz com o tempo medio de execucoes do SQL ID por dia e hora
 Sintaxe: SQL>@elap <SQL_ID> <Qtd. Dias> <Inst ID> <medida> (Onde Inst ID = 0 soma todas as instancias do cluster)
 "medida" pode ser 'ms' para Milisegundos, 'sec' para segundos ou 'min' para minutos
 Exemplo: SQL>@execs c3bpu9sapxhpw 10 1 ms
 
 Maicon Carneiro | Salvador-BA, 11/11/2022
*/

set feedback off
alter session set nls_date_format='dd/mm Dy';
set sqlformat 
set pages 999 lines 400
col snap_date heading "Date" format a10
col h0  format 999.99
col h1  format 999.99
col h2  format 999.99
col h3  format 999.99
col h4  format 999.99
col h5  format 999.99
col h6  format 999.99
col h7  format 999.99
col h8  format 999.99
col h9  format 999.99
col h10 format 999.99
col h11 format 999.99
col h12 format 999.99
col h13 format 999.99
col h14 format 999.99
col h15 format 999.99
col h16 format 999.99
col h17 format 999.99
col h18 format 999.99
col h19 format 999.99
col h20 format 999.99
col h21 format 999.99
col h22 format 999.99
col h23 format 999.99
set feedback ON

-- obtem o nome da instancia
column NODE new_value VNODE 
SET termout off
SELECT CASE WHEN &3 = 0 THEN 'Cluster' ELSE instance_name || ' / ' || host_name END AS NODE FROM GV$INSTANCE WHERE (&3 = 0 or inst_id = &3);
SET termout ON

DEFINE vMedida = "'&4'";

-- resumo do relatorio
PROMP
PROMP Metrica...: Average Elapsed Time (&vMedida)
PROMP SQL ID....: &1
PROMP Qt. Dias..: &2 
PROMP Instance..: &VNODE
PROMP

-- query
with awr as (
 select sql_id,
        snap_id,
        begin_snap,
        hora,
        sum(elapsed_time)/greatest(sum(executions),1) as elapsed_time_avg		
 from (
   select a.sql_id,
          a.snap_id,         
          trunc(b.begin_interval_time)           as begin_snap,
          to_char(b.begin_interval_time, 'hh24') as hora,
 	      sum(executions_delta)                  as executions,
		  sum(case when  &vMedida = 'ms'  then elapsed_time_delta/1000 
		           when  &vMedida = 'sec' then elapsed_time_delta/1000000 
			       when  &vMedida = 'min' then elapsed_time_delta/1000000/60
			       else elapsed_time_delta
		      end
		    ) as elapsed_time
 	 from dba_hist_sqlstat a
 	 join dba_hist_snapshot b on (a.snap_id = b.snap_id and a.dbid = b.dbid and a.instance_number = b.instance_number)
 	where 1=1
 	  and sql_id in ('&1')
 	  and executions_delta > 0
 	  and (&3 = 0 or b.instance_number = &3)
 	  and b.begin_interval_time >= trunc(sysdate) - &2
 group by a.sql_id,
          a.snap_id,         
          trunc(b.begin_interval_time),
          TO_CHAR (b.begin_interval_time, 'hh24')
 )
 group by sql_id,
          snap_id,
          begin_snap,
          hora
)
SELECT TRUNC(begin_snap) snap_date,
       max (DECODE (hora, '00', elapsed_time_avg, null)) "h0",
       max (DECODE (hora, '01', elapsed_time_avg, null)) "h1",
       max (DECODE (hora, '02', elapsed_time_avg, null)) "h2",
       max (DECODE (hora, '03', elapsed_time_avg, null)) "h3",
       max (DECODE (hora, '04', elapsed_time_avg, null)) "h4",
       max (DECODE (hora, '05', elapsed_time_avg, null)) "h5",
       max (DECODE (hora, '06', elapsed_time_avg, null)) "h6",
       max (DECODE (hora, '07', elapsed_time_avg, null)) "h7",
       max (DECODE (hora, '08', elapsed_time_avg, null)) "h8",
       max (DECODE (hora, '09', elapsed_time_avg, null)) "h9",
       max (DECODE (hora, '10', elapsed_time_avg, null)) "h10",
       max (DECODE (hora, '11', elapsed_time_avg, null)) "h11",
       max (DECODE (hora, '12', elapsed_time_avg, null)) "h12",
       max (DECODE (hora, '13', elapsed_time_avg, null)) "h13",
       max (DECODE (hora, '14', elapsed_time_avg, null)) "h14",
       max (DECODE (hora, '15', elapsed_time_avg, null)) "h15",
       max (DECODE (hora, '16', elapsed_time_avg, null)) "h16",
       max (DECODE (hora, '17', elapsed_time_avg, null)) "h17",
       max (DECODE (hora, '18', elapsed_time_avg, null)) "h18",
       max (DECODE (hora, '19', elapsed_time_avg, null)) "h19",
       max (DECODE (hora, '20', elapsed_time_avg, null)) "h20",
       max (DECODE (hora, '21', elapsed_time_avg, null)) "h21",
       max (DECODE (hora, '22', elapsed_time_avg, null)) "h22",
       max (DECODE (hora, '23', elapsed_time_avg, null)) "h23"
 FROM awr
GROUP BY TRUNC(begin_snap)
order by 1;

Para simplificar o uso do script “elap.sql”, criei mais 3 scripts auxiliares para usar separatemente quando preciso de uma visualização em milisegundos, segundos ou minutos.

elapms.sql

-- executa o script elap.sql com os parametros <SQL_ID> <DIAS> <INST_ID> ms
@elap &1 &2 &3 ms

elapsec.sql

-- executa o script elap.sql com os parametros <SQL_ID> <DIAS> <INST_ID> sec
@elap &1 &2 &3 sec

elapmin.sql

-- executa o script elap.sql com os parametros <SQL_ID> <DIAS> <INST_ID> min
@elap &1 &2 &3 min

Exemplos de uso.

Em Milisegundos (ms):

SQL> @elapms <SQL_ID> <days> <inst_id>

Em segundos:

SQL> @elapsec <SQL_ID> <days> <inst_id>

Em minutos:

SQL> @elapmin <SQL_ID> <days> <inst_id>

O exemplo abaixo é uma demonstração da visualização para o SQL ID 2a5z3x7187rxz em segundos, com 30 dias de AWR, considerando todas as instâncias do cluster (inst_id = 0):

Com a visão acima, é possivel observar rapidamente que o SQL_ID teve um tempo médio de execução menor a partir das 7h da manhã nos últimos dias, e que este comportamento começou a partir do dia 25/02/2023.

Tendo identificado um padrão como este não explica o que aconteceu em si, mas dá uma direção sobre quais períodos eu precisaria analisar com mais detalhes, por exemplo: Comparar um AWR do dia 03/03/2023 de 07 à 08h com um AWR do dia 24/02/2023 no mesmo periodo.