Browse By

Oracle STATSPACK: Cuidados na análise.

Hoje escreverei sobre um assunto um pouco antigo mas nem por isso deixa de ser importante, pois já presenciei alguns momentos onde uma informação errônea causou um certo desconforto além de que, as informações apresentadas aqui servem para alertar algumas pessoas que desconheciam essa particularidade pois é como dizem,  nunca é tarde para se aprender algo, tenho esse lema comigo.

NOTA: Esse post não tem por objetivo criar um passo a passo de instalação do Oracle STATSPACK pois já existem centenas de sites/blogs que já ensinam como por exemplo: aqui, além de que, as informações aqui citadas bem como os testes, foram realizados sobre a configuração/parametrização default do STATSPACK sobre um banco de dados 11.2.0.4 no OEL 6.4

 Sabemos que não são em todos os ambientes que encontramos uma combinação de Oracle Enterprise Edition + Tuning Pack/Diagnostic Pack habilitados CORRETAMENTE onde poderíamos utilizar várias ferramentas de análise de performance como AWR, ASH, SQL TUNING SETS e assim por diante. Sendo assim, o melhor que podemos fazer é instalar e configurar o velho e bom STATSPACK, para analisar e monitorar o ambiente com base no histórico.

Sabemos que existem grandes diferenças entre o AWR e o STATSPACK mas como diz o ditado popular: “Melhor com ele do que sem ele…”.rs
Brincadeiras a parte, hoje escreverei rapidamente sobre o cuidado que precisamos ter quando analisamos uma parte do relatório de performance (o TOP SQL’s) criado com base nas informações do STATSPACK, o $?/rdbms/admin/spreport.sql ou seus derivados.

Falando especificamente sobre o STATSPACK/TOP SQL’s a primeira coisa que precisamos entender é como acontece a captura das top querys.
Como sabemos, o STATSPACK grava somente valores cumulativos (sem deltas) e não captura todas as querys que executam em seu ambiente, tanto porque, ficaria bem dificil a navegação para análise sobre as tabelas que guardam as informações. (Desenvolvi a algumas semanas atrás um procedimento que dá a mesma(ou bem aproximada) visão que a view dba_hist_sqlstat criada com base nas tabelas do AWR proporciona, MAS com a pequena diferença, ele gravava tudo que era possível. Em um mês de dados, minha tabela já possuia mais de 30GB, então tive que mudar a lógica. Escreverei outro post sobre isso futuramente.)
Abaixo especificarei quais os threshold’s que precisam ser ultrapassados para que o STATSPACK reconheça a instrução como uma top consumidora e a capture.

Existem vários níveis de captura do snapshot e aqui são eles:

Connected to:
Oracle Database 11g
SQL> select * from stats$level_description;
SNAP_LEVEL DESCRIPTION
---------- ----------------------------------------------------------------------------------------------------------------
0          This level captures general statistics, including rollback segment, row cache, SGA, system
           events, background events, session events, system statistics, wait statistics, lock statistics
           ,and Latch information

5          This level includes capturing high resource usage SQL Statements, along with all data capt ured by lower levels

6          This level includes capturing SQL plan and SQL plan usage information for high resource usage SQL Statements, 
           along with all data captured by lower levels

7          This level captures segment level statistics, including logical and physical reads, row lock, itl and buffer busy 
           waits, along with all data captured by lower levels

10         This level includes capturing Child Latch statistics, along with all data captured by lower levels.

O nível que já inicia a coleta das informações pertinentes ao nosso teste, seria a partir do level 5 (Configurado por default na instalação do STATSPACK.) que captura as informações das TOP SQL’S.

Dica: Caso não queira alterar a configuração padrão, você pode especificar o level desejado no momento da execução do snapshot, ex:

-- Coletando snapshot com o level 6:
SQL> EXECUTE STATSPACK.SNAP(i_snap_level=>6);

Para alterar o valor padrão, execute o seguinte comando:

SQL> EXECUTE STATSPACK.SNAP(i_snap_level=>10, i_modify_parameter=>'true');

A parte interessante inicia aqui.
Para que o sql seja visto como um top consumidor, ele precisa ultrapassar um dos threshold’s já pré-configurados na instalação, onde você poderá alterá-los posteriormente para valores maiores caso ache interessante.

Os principais seriam:

 * Number of executions of the SQL statement (default 100)
 * Number of disk reads performed by the SQL statement (default 1,000)
 * Number of parse calls performed by the SQL statement (default 1,000)
 * Number of buffer gets performed by the SQL statement (default 10,000)
 * Size of sharable memory used by the SQL statement (default 1 Mb)
 * Version count for the SQL statement (default 20).

Para obter a lista de todos os threshold’s configurados, consulte a tabela: STATS$STATSPACK_PARAMETER

Para maiores informações: http://docs.oracle.com/cd/B10500_01/server.920/a96533/statspac.htm

Ok, com essas informações em mãos, vamos iniciar a análise.
Vou explicar passo a passo do porque temos que nos preocupar quando estamos analisando os dados criados pelo relatório de performance spreport.sql e seus derivados.
Gosto de explicar ao mesmo tempo que faço os testes pois acho que fica mais dinâmico e com melhor fixação da informação, então para isso vamos configurar o ambiente de análise.

Criando tabela usada para o teste:

SQL> CREATE TABLE TB_BG AS SELECT A.* FROM DBA_TABLES A,DBA_TABLES B WHERE ROWNUM < 2500;
Table created.

Coletando estatísticas:

SQL> EXEC DBMS_STATS.GATHER_TABLE_STATS('WMON','TB_BG', ESTIMATE_PERCENT=>100);
Table created.

Query usada para checar o tamanho do segmento TABLE criado acima:

SQL> COL SEGMENT_NAME FOR A10
SQL> COL OWNER FOR A10
SQL> SELECT OWNER, SEGMENT_NAME,SEGMENT_TYPE,BLOCKS,BYTES/1024/1024 MB
FROM DBA_SEGMENTS
WHERE SEGMENT_NAME = 'TB_BG'
AND OWNER = 'WMON';

OWNER      SEGMENT_NAME  SEGMENT_TYPE        BLOCKS        MB
---------- ----------   ------------------ ---------- ----------
WMON         TB_BG1        TABLE               96         .75

Flush na memória:

SQL> ALTER SYSTEM FLUSH SHARED_POOL;
System altered.

SQL> ALTER SYSTEM FLUSH BUFFER_CACHE;
System altered.

 

Shell SCRIPT Utilizado como Workload 1:

#################################################
[oracle@oelgg ~]$ cat exec.sh
#!/bin/bash
# Set variable
n=1
ex=${1}
# Loop
while [ $n -le $ex ]
do
sqlplus -S ” wmon/oracle” <<EOF >> /dev/null
set lines 1000
set feed off
set echo off
SELECT /*QUERY_BG001*/ * FROM TB_BG;
exit;
EOF

echo ” Executando… $n”
n=$(( n+1 ))
done
#################################################

Por exemplo, para executar a query 20 vezes eu utilizo o script acima da seguinte forma:

sh exec.sh 20
Para iniciar a análise, vamos criar uma snapshot inicial:

SESSION 1:

SQL> exec statspack.snap;
PL/SQL procedure successfully completed.

Consultando a snapshot mais recente criada como marco zero para o nosso teste:
Vou referenciar a query abaixo nas próximas execuções como maxsnap.sql

SQL> select to_char(snap_time,'dd/mm/yyyy hh24:mi') snap_time, snap_id
 from stats$snapshot
 where snap_id = (select max(snap_id) from stats$snapshot)
 ;

SNAP_TIME           SNAP_ID
-----------------  ---------
 29/05/2014 15:30     53

Dica: (Não se preocupe se o snap_id possuir gaps (existir buracos na sequencia) em seus números pois o que alimenta esse ID é uma sequence chamada STATS$SNAPSHOT_ID que possui um cache default de 10, na qual você perde os valores não usados e que ainda estão em memória em caso de restart da instance ou flush da shared_pool)
Utilizarei o script abaixo para não usar PL/SQL, assim executo de uma maneira mais dinâmica e consumindo o maior número de BG possíveis com poucas execuções. Dentro do bloco PL/SQL eu teria que executar muitas vezes para alcançar os valores que preciso para o meu teste pois existe uma otimização de compartilhamento-reutilização/memória/execução que eu não preciso utilizar agora nesse post.

Vamos consultar a VIEW v$sql para evidenciarmos que o cursor ainda não foi executado:

( Vou referenciar a query abaixo como sqlcheck.sql nas próximas execuções)

SQL> SELECT SQL_ID, OLD_HASH_VALUE, EXECUTIONS,DISK_READS,BUFFER_GETS,CPU_TIME, IS_OBSOLETE
 FROM V$SQL
 WHERE SQL_TEXT LIKE '%QUERY_BG%'
 AND SQL_TEXT NOT LIKE '%V$SQL%';

no rows selected

Ok… Vamos executar o script do workload na sessão do S.O:

[oracle@oelgg ~]$ sh exec.sh 20
 Executando... 1
 Executando... 2
 Executando... 3
 Executando... 4
 Executando... 5
 Executando... 6
 Executando... 7
 Executando... 8
 Executando... 9
 Executando... 10
 Executando... 11
 Executando... 12
 Executando... 13
 Executando... 14
 Executando... 15
 Executando... 16
 Executando... 17
 Executando... 18
 Executando... 19
 Executando... 20

De volta a SESSÃO 1, vamos analisar a execução:

SQL> @sqlcheck.sql
 SQL_ID        OLD_HASH_VALUE  EXECUTIONS DISK_READS BUFFER_GETS  CPU_TIME  IS_OBSOLETE
 ------------- --------------  ---------- ---------- ----------- ---------- ---------------
 cdhrz7rx73tsu  1064022172          20        91        5242      112978     N

A query foi executada 20 vezes e consumiu 5.242 Buffer Gets.

Vamos criar um snapshot para finalizar o procedimento.

SQL> exec statspack.snap;
PL/SQL procedure successfully completed.

Analisando a snapshot criada:

SQL> @maxsnap.sql
SNAP_TIME          SNAP_ID
----------------  ----------
 29/05/2014 15:33    54

Ótimo. Conforme explicado no inicio do POST, existem alguns thresholds que devem ser ultrapassados para que a query seja capturada pelas snapshots, mas como somos curiosos (ou deveríamos ser), vamos checar.

Nesse primeiro momento, vou checar diretamente nas tabelas do statspack para analisar se a mesma foi ou não capturada. (Não deveria pois não ultrapassou nenhum threshold …)

( Vou referenciar a query abaixo como spsqlcheck.sql nas próximas vezes )

SQL> SELECT to_char(SP_SNAP.SNAP_TIME,'dd/mm/yyyy hh24:mi') SNAP_TIME
 , SP_SNAP.SNAP_ID
 , SP_SUMM.SQL_ID
 , SP_SUMM.EXECUTIONS
 , SP_SUMM.DISK_READS
 , SP_SUMM.BUFFER_GETS
 ,to_char(SP_SUMM.LAST_ACTIVE_TIME,'dd/mm/yyyy hh24:mi') lastact
 FROM STATS$SQL_SUMMARY SP_SUMM, stats$snapshot SP_SNAP
 where SP_SNAP.SNAP_ID = SP_SUMM.SNAP_ID
 and SP_SNAP.DBID = SP_SUMM.DBID
 and SP_SNAP.INSTANCE_NUMBER = SP_SUMM.INSTANCE_NUMBER
 and SP_SUMM.sql_id = 'cdhrz7rx73tsu'
 order by 1;

no rows selected

OK! NADA, como esperado.

Nesse momento vamos ultrapassar o threshold de BG (BUFFER_GETS > 10000) para que a query seja capturada e inserida nas tabelas do statspack.

Retornemos a sessão do S.O para executar o script novamente, mas agora, executaremos 500 vezes. (Quero gerar um número consideravel de BG para outro teste mais a frente.) Lembre-se que o objetivo do POST é a análise do statspack report e não shell script, pl/sql performance e etc.

[oracle@oelgg ~]$ sh exec.sh 500
 Executando... 1
 Executando... 2
 Executando... 3
 Executando... 4
 Executando... 5
 ...
 Executando... 498
 Executando... 499
 Executando... 500

Checando as informações da execução na VIEW V$SQL:

SQL> @sqlcheck.sql
 SQL_ID         OLD_HASH_VALUE  EXECUTIONS DISK_READS BUFFER_GETS   CPU_TIME   IS_OBSOLETE
 -------------  --------------  ----------  ---------- -----------  ---------- ---------------
 cdhrz7rx73tsu    1064022172       520          91       131242      4945240    N

Coletando o snapshot:

SQL> exec statspack.snap;
PL/SQL procedure successfully completed.

Confirmando o snapshot criado:

SQL> @maxsnap.sql
SNAP_TIME          SNAP_ID
----------------  ----------
 29/05/2014 15:38    55

Agora que o threshold de BG foi ultrapassado, essa query deveria ser capturada e inserida nas tabelas do STATSPACK.

Vamos confirmar se a query foi capturada. (Deveria ser…)

SQL> @spsqlcheck.sql
 SNAP_TIME          SNAP_ID     SQL_ID     EXECUTIONS DISK_READS BUFFER_GETS LASTACT
 ---------------- ---------- ------------- ---------- ---------- ----------- ----------------
 29/05/2014 15:38     55      cdhrz7rx73tsu    520         91      131242    29/05/2014 15:37

Ótimo, foi capturada e tudo funcionando como o esperado.
Daqui pra frente começa o real objetivo do post…
Vamos executar o script $ORACLE_HOME/rdbms/admin/spreport.sql para criar o relatório de performance do período entre a snap 54 e 55.
Abaixo, colocarei somente as partes interessantes do report.

Informações do snapshot:

Snapshot  Snap Id    Snap Time         Sessions Curs/Sess Comment
~~~~~~~~ ---------- ------------------ -------- --------- ------------------
Begin Snap: 54      29-May-14 15:33:06   19       1.3
End Snap:   55      29-May-14 15:38:28   21       1.3
Elapsed:    5.37 (mins) Av Act Sess:   0.2
DB time:    0.90 (mins) DB CPU: 0.84 (mins)

Usarei como amostra nesse momento, o título do relatório chamada “SQL ordered by GetsMAS lembrando, a metodologia passada nesse post serve para qualquer tipo de TOP SQL’s como disk reads, parse calls, cpu time, elapse time e etc…

Como podemos ver abaixo, o top consumidor do intervalo escolhido foi a query do nosso workload com o old_hash_value de 1064022172 que seria o sql_id = cdhrz7rx73tsu

 Como o banco de dados que estou usando para o teste não tem muita movimentação além da minha sessão, as outras top querys são internas/recursive do Oracle mas isso não interfere nos testes.

TOP SQL:

SQL ordered by Gets DB/Inst: DB11GG/DB11G Snaps: 54-55
 -> End Buffer Gets Threshold: 10000 Total Buffer Gets: 145,791
 -> Captured SQL accounts for 102.0% of Total Buffer Gets
 -> SQL reported below exceeded 1.0% of Total Buffer Gets
                                                      CPU     Elapsd      Old
 Buffer Gets      Executions   Gets per Exec %Total  Time (s) Time (s)  Hash Value
 --------------- ------------ -------------- -----  ------   -------   ----------
 131,242              520          252.4      90.0   4.95     10.91    1064022172
 Module: SQL*Plus
 SELECT /*QUERY_BG001*/ * FROM TB_BG
5,722                 520          11.0        3.9   0.33      0.49    2275360153
 select /*+ connect_by_filtering */ privilege#,level from sysauth
 $ connect by grantee#=prior privilege# and privilege#>0 start wi
 th grantee#=:1 and privilege#>0
2,648                 520           5.1        1.8   0.73      1.17    3840591838
select privilege# from sysauth$ where (grantee#=:1 or grantee#=1
) and privilege#>0
1,989                   1        1,989.0       1.4   1.16      1.84    2522684317
Module: sqlplus@oelgg (TNS V1-V3)
BEGIN statspack.snap; END;

Agora imagine por um instante que você esta no meio de uma análise de performance e esta analisando um aumento de processamento no período analisado acima.
Logo, a principal query top consumidora do report acima seria a query do nosso workload. Você daria continuidade a analise do procedimento analisando plano de execução (se fosse uma query mais complexa) ,sistema que esta executando, comparação do histórico para analisar possíveis mudanças, motivos da execução e assim por diante.

Digamos que o banco de dados volte ao seu consumo normal após algum tempo.
Vou criar mais um snapshot para “marcar” esse período “NORMAL“,  sem a execução desse workload e com o banco bem tranquilo.

SESSÃO 1:

SQL> exec statspack.snap;
PL/SQL procedure successfully completed.

Verificando a snapshot criada:

SQL> @maxsnap.sql
SNAP_TIME          SNAP_ID
----------------   ----------
 29/05/2014 15:52    56

Vamos verificar nas tabelas do STATSPACK se a query do workload foi capturada.

SQL> @spsqlcheck.sql
SNAP_ID       SNAP_TIME          SQL_ID        OLD_HV   EXECUTIONS BUFFER_GETS CPU_TIME  DISK_READS
---------- ------------------- ------------- ---------- ---------- ----------- ---------- ----------
 55         29/05/2014 15:38:28 cdhrz7rx73tsu 1064022172    520       131242     4945240      91
 56         29/05/2014 15:52:16 cdhrz7rx73tsu 1064022172    520       131242     4945240      91

Vejam que mesmo sem a query ter sido executada nesse intervalo, ela ainda foi captura pelo snapshot, pois seu cursor ainda persiste em memória com um ou mais threshold’s alcançados conforme explicado no início do post.

Vamos mais a fundo, imagine que o banco de dados ainda continua dentro da normalidade quando outro snapshot é criado (ainda sem a execução de nosso workload).

 SQL> exec statspack.snap;
 PL/SQL procedure successfully completed.

Verificando snap criada:

SQL> @maxsnap.sql
SNAP_TIME         SNAP_ID
---------------- ----------
 29/05/2014 15:54    57

Verificando nas tabelas do statspack se a query do workload 1 continua sendo capturada mesmo sem ocorrido uma única execução:

SQL> spsqlcheckd.sql
SNAP_ID          SNAP_TIME        SQL_ID       OLD_HV   EXECUTIONS BUFFER_GETS  CPU_TIME  DISK_READS
---------- ------------------- ------------- ---------- ---------- ----------- ---------- ----------
 55        29/05/2014 15:38:28 cdhrz7rx73tsu 1064022172     520       131242    4945240       91
 56        29/05/2014 15:52:16 cdhrz7rx73tsu 1064022172     520       131242    4945240       91
 57        29/05/2014 15:54:14 cdhrz7rx73tsu 1064022172     520       131242    4945240       91

Como visto, as informações da execução do workload 1 continuam sendo capturadas pois as informações do cursor ainda permanecem na memória, mas será que no momento da execução do relatório de análise de performance (spreport.sql) entre os intervalos “bons” do nosso ambiente, o script que cria o report será “inteligente” o bastante para excluir as informações antigas que realmente não pertencem ao intervalo desejado, colocando somente o que foi executado/consumido no período escolhido ?
Vamos executar novamente o spreport.sql para criar o relatorio de performance desse período “BOM“, sem carga.

Informações do intervalo utilizado:

Snapshot   Snap Id       Snap Time     Sessions Curs/Sess    Comment
~~~~~~~~ ---------- ------------------ -------- --------- ------------------
Begin Snap: 56      29-May-14 15:52:16    22       1.3
End Snap:   57      29-May-14 15:54:14    22       1.3
Elapsed:    1.97 (mins) Av Act Sess: 0.0
DB time:    0.03 (mins) DB CPU: 0.02 (mins)

Vamos seguir para o TOP SQL by GETs novamente:

 SQL ordered by Gets DB/Inst: DB11GG/DB11G Snaps: 56-57
 -> End Buffer Gets Threshold: 10000 Total Buffer Gets: 1,943
 -> Captured SQL accounts for 0.0% of Total Buffer Gets
 -> SQL reported below exceeded 1.0% of Total Buffer Gets
                                                      CPU    Elapsd     Old
 Buffer Gets      Executions   Gets per Exec %Total Time (s) Time (s)  Hash Value
 --------------- ------------ -------------- ------ -------- --------- ----------
 131,242             520           252.4     ######  4.95     10.91    1064022172
 Module: SQL*Plus
 SELECT /*QUERY_BG001*/ * FROM TB_BG
 5,722               520           11.0       294.5  0.33     0.49     2275360153
 select /*+ connect_by_filtering */ privilege#,level from sysauth
 $ connect by grantee#=prior privilege# and privilege#>0 start wi
 th grantee#=:1 and privilege#>0
 2,648               520            5.1       136.3 0.73       1.17    3840591838
 select privilege# from sysauth$ where (grantee#=:1 or grantee#=1
 ) and privilege#>0
1,989                 1           1,989.0     102.4 1.16       1.84    2522684317
 Module: sqlplus@oelgg (TNS V1-V3)
 BEGIN statspack.snap; END;
 1,924                1           1,924.0     99.0 1.20        1.65    2522684317
 Module: sqlplus@oelgg (TNS V1-V3)
 BEGIN statspack.snap; END;

Olhem só quem é a nossa TOP query ainda, mesmo sem ter sido executada no intervalo utilizado para análise.

Vamos mais a frente, vou executar outras 3 querys “NOVAS” que não consomem os mesmos recursos iguais do workload 1, mas seriam querys responsáveis pela lentidão do ambiente no intervalo atual.

Vamos Criar um snapshot para distanciar ainda mais do tempo que o workload 1 foi executado no início do post.

SQL> exec statspack.snap;
PL/SQL procedure successfully completed.

Informações do snap criado:

SQL> @maxsnap.sql
SNAP_TIME         SNAP_ID
---------------- ----------
29/05/2014 16:00    58

Ok!!!!

Agora, executando em diferentes sessões as novas 3 top querys para o intervalo atual: (Vou utilizar o mesmo processo do script exec.sh modificando as querys )

Query1:
SELECT /*QUERY_BG_OTHER1*/ * FROM TB_BG;

Query2:
SELECT /*QUERY_BG_OTHER2*/ * FROM TB_BG;

Query3:
SELECT /*QUERY_BG_OTHER3*/ * FROM TB_BG;

Checando na view V$SQL antes da execução das novas querys:

SQL> @sqlcheck.sql
SQL_ID        EXECUTIONS DISK_READS BUFFER_GETS  CPU_TIME    IS_OBSOLETE
------------- ---------- ---------- ----------- ----------  ---------------
cdhrz7rx73tsu    520         91       131242     4945240    N

Somente a query do workload aparece, as outras ainda não foram executadas.

(No S.O. executando os scripts…)

Conferindo a execução:

SQL> @sqlcheck.sql
SQL_ID         EXECUTIONS  DISK_READS  BUFFER_GETS  CPU_TIME  IS_OBSOLETE
-------------  ----------  ---------- ----------- ---------- ---------------
g2cq0cbauxws7    100          0         25391       592903     N
gdp39c16jfa56    100          0         25200       1079833    N
b2tbqn6u4bh1w    100          0         25200       984844     N
cdhrz7rx73tsu    520         91         131242      4945240    N

Criando a snapshot para o intervalo das novas execuções…

SQL> exec statspack.snap;
PL/SQL procedure successfully completed.

Verificando a snap criada:

SQL> @maxsnap.sql
SNAP_TIME          SNAP_ID
----------------  ----------
29/05/2014 16:08    59

Executando o spreport.sql para análise:

Informações do intervalo escolhido para relatório:

 Snapshot   Snap Id      Snap Time      Sessions Curs/Sess  Comment
 ~~~~~~~~ ---------- ------------------ -------- --------- ------------------
 Begin Snap: 58      29-May-14 16:00:55    21       1.3
 End Snap:   59      29-May-14 16:08:01    21       1.3
 Elapsed: 7.10 (mins) Av Act Sess: 0.1
 DB time: 0.70 (mins) DB CPU: 0.57 (mins)

Adivinhem quem é a nossa top query novamente ? :(

 SQL ordered by Gets DB/Inst: DB11GG/DB11G Snaps: 58-59
 -> End Buffer Gets Threshold: 10000 Total Buffer Gets: 90,083
 -> Captured SQL accounts for 97.0% of Total Buffer Gets
 -> SQL reported below exceeded 1.0% of Total Buffer Gets
                                                      CPU    Elapsd      Old
 Buffer Gets      Executions   Gets per Exec %Total Time (s) Time (s)  Hash Value
 --------------- ------------ -------------- ------ -------- --------- ----------
 131,242             520           252.4      145.7   4.95     10.91   1064022172
 Module: SQL*Plus
 SELECT /*QUERY_BG001*/ * FROM TB_BG
 25,391              100           253.9       28.2   0.59      1.50    1069844640
 Module: SQL*Plus
 SELECT /*QUERY_BG_OTHER1*/ * FROM TB_BG
25,200               100           252.0       28.0   1.08      2.27    1172826369
 Module: SQL*Plus
 SELECT /*QUERY_BG_OTHER2*/ * FROM TB_BG
25,200               100           252.0       28.0   0.98      1.63    3581366766
 Module: SQL*Plus
 SELECT /*QUERY_BG_OTHER3*/ * FROM TB_BG
5,722                520           11.0         6.4   0.33       0.49   2275360153
 select /*+ connect_by_filtering */ privilege#,level from sysauth
 $ connect by grantee#=prior privilege# and privilege#>0 start wi
 th grantee#=:1 and privilege#>0
 3,300               300           11.0         3.7   0.15       0.21   2275360153
 select /*+ connect_by_filtering */ privilege#,level from sysauth
 $ connect by grantee#=prior privilege# and privilege#>0 start wi
 th grantee#=:1 and privilege#>0

Agora, pare por 10 segundos e imagine esse comportamento em um ambiente de produção, com milhares de querys onde algumas delas consomem altos recursos e executam em alguns determinados períodos como de manhã por exemplo, some isso com uma SGA com um tamanho considerável e “agora” no início da tarde, você precisa fazer uma análise utilizando o spreport.sql para identificar qual é a query que esta com maior consumo nesse início de tarde e Boommm!!!!

Eu criei o teste somente com uma query que contribuiu para “sujar” a análise, onde as outras que realmente executaram no intervalo escolhido vieram logo abaixo da “antiga“, mas imagine esse comportamento em uma ambiente real, com várias querys. As verdadeiras querys consumidoras do intervalo escolhido “podem” nem aparecer no report se outras antigas que consumiram mais recursos comparado com as atuais ainda persistem em memória.

A pergunta que fica é, até quando a query do primeiro workload aparecerá no relatório de análise do ambiente (spreport.sql) ?

A resposta é: Até quando o cursor for reciclado/re-criado/age-out da shared pool.

Simulando o age-out do cursor:

Utilizarei o cursor criado pelo workload 1 de sql_id = cdhrz7rx73tsu nesse exemplo:

set serveroutput on
 SQL> DECLARE
 cursor c1 is
 select address, hash_value,sql_text from v$sqlarea where sql_id ='cdhrz7rx73tsu';
 BEGIN
 for r1 in c1 loop
 dbms_output.put_line('exec dbms_shared_pool.purge ('||''''||r1.address||','||r1.hash_value||''''||','||''''||'C'||''''||');');
 END LOOP;
 END;
 /

exec dbms_shared_pool.purge ('0000000089C56B70,4201768730','C');

Execute a saída do comando acima.

SQL> exec dbms_shared_pool.purge ('0000000089C56B70,4201768730','C');
PL/SQL procedure successfully completed.

Confirmando o age-out do cursor:

SQL> @sqlcheck.sql
SQL_ID        OLD_HASH_VALUE EXECUTIONS DISK_READS BUFFER_GETS CPU_TIME   I
------------- -------------- ---------- ---------- ----------- ---------- -
g2cq0cbauxws7 1069844640        100         0         25200     791878    N
gdp39c16jfa56 1172826369        100         0         25200     652906    N
b2tbqn6u4bh1w 3581366766        100         0         25200     788878    N

Repare acima que o cursor cdhrz7rx73tsu não existe mais na shared_pool..

Execute a coleta do snapshot novamente:

SQL> exec statspack.snap;
PL/SQL procedure successfully completed.

Verificando snapshot criada:

SQL> @maxsnap.sql
SNAP_TIME         SNAP_ID
---------------- ----------
 30/05/2014 12:08   67

Checando se a query antiga ainda foi capturada: (Resposta óbvia)

SQL> spsqlcheckd.sql
SNAP_ID         SNAP_TIME         SQL_ID       OLD_HV   EXECUTIONS BUFFER_GETS CPU_TIME   DISK_READS
---------- ------------------- ------------- ---------- ---------- ----------- ---------- ----------
 55        29/05/2014 15:38:28 cdhrz7rx73tsu 1064022172     520       131242    4945240      91
 56        29/05/2014 15:52:16 cdhrz7rx73tsu 1064022172     520       131242    4945240      91
 57        29/05/2014 15:54:14 cdhrz7rx73tsu 1064022172     520       131242    4945240      91
 58        29/05/2014 16:00:55 cdhrz7rx73tsu 1064022172     520       131242    4945240      91
 63        30/05/2014 11:41:50 cdhrz7rx73tsu 1064022172     520       131242    5852112      0
 64        30/05/2014 11:45:32 cdhrz7rx73tsu 1064022172     520       131242    5852112      0
 65        30/05/2014 11:55:41 cdhrz7rx73tsu 1064022172     520       131242    5852112      0
 66        30/05/2014 12:00:00 cdhrz7rx73tsu 1064022172     520       131242    5852112      0

Vejam acima que ela não foi mais capturada e certamente não aparecerá no report.

Analisando relatório spreport.sql do intervalo do snap_id 66 ao 67

Snapshot       Snap Id     Snap Time      Sessions Curs/Sess Comment
~~~~~~~~    ---------- ------------------ -------- --------- ------------------
Begin Snap:         66 30-May-14 12:00:00       21       1.1
  End Snap:         67 30-May-14 12:08:58       23       1.1
   Elapsed:       8.97 (mins) Av Act Sess:       0.0
   DB time:       0.41 (mins)      DB CPU:       0.31 (mins)

Analisando o SQL:

SQL ordered by Gets  DB/Inst: DB11GG/DB11G  Snaps: 66-67
-> End Buffer Gets Threshold:     10000 Total Buffer Gets:          
-> Captured SQL accounts for   76.5% of Total Buffer Gets
-> SQL reported below exceeded  1.0% of Total Buffer Gets

                                                     CPU      Elapsd     Old
  Buffer Gets    Executions  Gets per Exec  %Total Time (s)  Time (s) Hash Value
--------------- ------------ -------------- ------ -------- --------- ----------
         25,231          100          252.3   43.4     1.42      2.07  926199419
Module: SQL*Plus
SELECT /*QUERY_BG_AFTER_INV1*/ *  FROM  TB_BG

         11,790        3,448            3.4   20.3     0.46      0.69 3665763022
update sys.col_usage$ set   equality_preds    = equality_preds
  + decode(bitand(:flag,1),0,0,1),   equijoin_preds    = equijoi
n_preds    + decode(bitand(:flag,2),0,0,1),   nonequijoin_preds
= nonequijoin_preds + decode(bitand(:flag,4),0,0,1),   range_pre

          7,415            1        7,415.0   12.8     0.79      1.21 1745153189
begin prvt_hdm.auto_execute( :dbid, :inst_num , :end_snap_id );
end;

Como esperado, a query não aparece mais como top consumidora. A atual seria uma outra que eu executei para outro teste.

2- Invalidando o cursor:
Nesse passo, nada mais é que invalidar o cursor, dessa forma vamos realizar um comment na tabela (Lembre-se que isso invalida todos os cursores relacionados a tabela, não faça em produção!).

Primeiramente,  vamos averiguar o cursor existente: (Nesse exemplo utilizarei um outro cursor que também serve para o nosso teste, já que invalidei o cursor do primeiro workload. Utilizarei o cursor.sql_id = ctxdzvnh3k8x2 que também ultrapassou um dos threshold’s do statspack e esta como top GET’s do relatório spreport.sql , mas nesse teste você pode utilizar qualquer outro cursor que tenha sido executado em snapshot’s anteriores do seu ambiente na qual tenha ultrapassado consideravelmente qualquer threshold do STATSPACK e que estejam aparecendo como top consumidor, pois a lógica é a mesma.)

Verificando informações do cursor na V$SQL:

SQL> SELECT SQL_ID, EXECUTIONS,DISK_READS,BUFFER_GETS,CPU_TIME,IS_OBSOLETE
 FROM V$SQL
 WHERE sql_id = 'ctxdzvnh3k8x2';
SQL_ID         EXECUTIONS DISK_READS BUFFER_GETS CPU_TIME  I
------------- ---------- ---------- ----------- ---------- -
ctxdzvnh3k8x2     150         0        37800     683888    N

Coletando snapshot

SQL> exec statspack.snap;
PL/SQL procedure successfully completed.

Analisando snapshot criada:

SQL> @maxsnap.sql
SNAP_TIME         SNAP_ID
---------------- ----------
 30/05/2014 19:08  76

Averiguando se o sql foi capturado com sucesso:

SQL> SELECT SP_SUMM.snap_id snap_id,
 TO_CHAR(SP_SNAP.SNAP_TIME, 'DD/MM/YYYY HH24:MI:SS') SNAP_TIME,
 SP_SUMM.sql_id,
 SP_SUMM.OLD_HASH_VALUE OLD_HV,
 SP_SUMM.EXECUTIONS,
 SP_SUMM.BUFFER_GETS,
 SP_SUMM.CPU_TIME,
 SP_SUMM.DISK_READS
 FROM STATS$SQL_SUMMARY SP_SUMM,
 stats$snapshot SP_SNAP
 WHERE SP_SUMM.SNAP_ID = SP_SNAP.SNAP_ID
 AND SP_SUMM.DBID = SP_SNAP.DBID
 AND SP_SUMM.INSTANCE_NUMBER = SP_SNAP.INSTANCE_NUMBER
 AND SP_SUMM.SQL_ID = 'ctxdzvnh3k8x2'
 order by 1;

SNAP_ID         SNAP_TIME          SQL_ID      OLD_HV   EXECUTIONS BUFFER_GETS CPU_TIME   DISK_READS
---------- ------------------- ------------- ---------- ---------- ----------- ---------- ----------
 67        30/05/2014 12:08:58 ctxdzvnh3k8x2 926199419    100        25231     1416777      0
 76        30/05/2014 19:08:07 ctxdzvnh3k8x2 926199419    150        37800     683888       0

Ok, foi capturado…
Agora, invalidando o cursor para resetar o valor cumulativo que esta gravado na v$sql na qual ultrapassa alguns threshold’s do statspack (seria praticamente a mesma lógica do age-out porém o cursor invalidado ainda fica em memória por um determinado tempo e o statspack pode como não pode o capturar, tudo depende de algumas características importantes que você também deve levar em consideração).

Invalidando a query:

SQL> COMMENT ON TABLE WMON.TB_BG IS ' ';
Comment created.

Aguardando o sistema (eu no caso.rs) voltar a executar a query novamente (qualquer quantidade de vezes) onde resetará as informações de consumo do cursor CASO CONTRÁRIO,  se a snapshot for criada e o cursor ainda estiver intacto (sem ter ocorrido no mínimo uma execução), as informações do consumo antigo ainda estarão gravadas para esse cursor nas v$ , mesmo o Oracle marcando-o como INVÁLIDO. As informações cumulativas só serão resetadas se o cursor em si for executado novamente. Enquanto isso não ocorrer, o statspack continuará gravando as informações do cursor antigo pois ele ainda é tido como um top consumidor e essa é a diferença do age-out para um cursor inválido. No age-out o cursor desaparece e nada mais é capturado pelo statspack diferente do comportamento do cursor inválido.(Tem mais esse  cuidado que você deve se atentar.)

Executando a query do cursor ctxdzvnh3k8x2 10 vezes…

Verificando o resultado:

SQL> SELECT SQL_ID,child_number,ADDRESS,EXECUTIONS,DISK_READS,BUFFER_GETS,CPU_TIME,IS_OBSOLETE,INVALIDATIONS
 FROM V$SQL
 WHERE sql_id = 'ctxdzvnh3k8x2';
 SQL_ID         EXECUTIONS     DISK_READS    BUFFER_GETS CPU_TIME   IS_OBSOLETE INVALIDATIONS
 ------------- ------------ ---------------- ----------  ---------- ----------- ----------
 ctxdzvnh3k8x2     10              0            2552      50995         N            1

Executando a snapshot novamente:

SQL> exec statspack.snap;
PL/SQL procedure successfully completed.

Analisando snapshot criada:

SQL> @maxsnap.sql
SNAP_TIME         SNAP_ID
---------------- ----------
30/05/2014 19:16    77

Averiguando se a query ainda foi capturada pelo statspack (Claro que não, pois não ultrapassa nenhum threshold):

SQL> SELECT SP_SUMM.snap_id snap_id,
 TO_CHAR(SP_SNAP.SNAP_TIME, 'DD/MM/YYYY HH24:MI:SS') SNAP_TIME,
 SP_SUMM.sql_id,
 SP_SUMM.OLD_HASH_VALUE OLD_HV,
 SP_SUMM.EXECUTIONS,
 SP_SUMM.BUFFER_GETS,
 SP_SUMM.CPU_TIME,
 SP_SUMM.DISK_READS
 FROM STATS$SQL_SUMMARY SP_SUMM,
 stats$snapshot SP_SNAP
 WHERE SP_SUMM.SNAP_ID = SP_SNAP.SNAP_ID
 AND SP_SUMM.DBID = SP_SNAP.DBID
 AND SP_SUMM.INSTANCE_NUMBER = SP_SNAP.INSTANCE_NUMBER
 AND SP_SUMM.SQL_ID ='ctxdzvnh3k8x2'
 order by 1;
SNAP_ID         SNAP_TIME          SQL_ID      OLD_HV   EXECUTIONS BUFFER_GETS  CPU_TIME  DISK_READS
 ---------- ------------------- ------------- ---------- ---------- ----------- ---------- ----------
 67         30/05/2014 12:08:58 ctxdzvnh3k8x2 926199419     100        25231     1416777      0
 76         30/05/2014 19:08:07 ctxdzvnh3k8x2 926199419     150        37800     683888       0

Nada na snap 77.

Quando o relatório ?/rdbms/admin/spreport.sql for executado utilizando a snapshot mais recente, a query não aparecerá.

Averiguando:

Snapshot    Snap Id       Snap Time     Sessions Curs/Sess Comment
~~~~~~~~ ---------- ------------------ -------- --------- ------------------
Begin Snap:  76     30-May-14 19:08:07     26     1.7
End Snap:    77     30-May-14 19:16:31     23     1.9
Elapsed: 8.40 (mins) Av Act Sess: 0.0
DB time: 0.04 (mins) DB CPU: 0.04 (mins)
Analisando as top GET's querys:
SQL ordered by Gets DB/Inst: DB11GG/DB11G Snaps: 76-77
 -> End Buffer Gets Threshold: 10000 Total Buffer Gets: 11,385
 -> Captured SQL accounts for 43.5% of Total Buffer Gets
 -> SQL reported below exceeded 1.0% of Total Buffer Gets
                                                      CPU     Elapsd    Old
 Buffer Gets     Executions    Gets per Exec %Total Time (s) Time (s)  Hash Value
 --------------- ------------ -------------- ------ -------- --------- ----------
 10,301               4          2,575.3      90.5  3.36       3.85    1546624946
 Module: sqlplus@oelgg (TNS V1-V3)
 DECLARE stmt VARCHAR2(31700); currSeq NUMBER; currUserId NUMBER;
 errorMessage VARCHAR2(32767); objstatus VARCHAR2(100); errorVal
 VARCHAR2(10); -- purpose of these is because ora_dict* is orac
 le implicit function and is not l-value (can't be modified) -- w
 2,234                1          2,234.0      19.6  0.43        0.50   2522684317
 Module: sqlplus@oelgg (TNS V1-V3)
 BEGIN statspack.snap; END;
 1,980              110           18.0        17.4  0.00         0.01  2689408724
 Module: sqlplus@oelgg (TNS V1-V3)
 SELECT DATA_TYPE, DATA_TYPE_OWNER, DATA_PRECISION, CHAR_USED, DA
 TA_LENGTH FROM DBA_TAB_COLUMNS WHERE OWNER = :B3 AND TABLE_NAME
 = :B2 AND COLUMN_NAME = :B1

Mas vamos lá, quem em sã consciência ficaria invalidando os cursores da memória (tirando o caso da necessidade de algum plano de execução ter sido criado de uma maneira ruim sendo necessário recarrega-lo em memória e entre outras ocasiões é claro. ) só para o STATSPACK não ficar cometendo enganos ?

A lição passada aqui seria para que tomem cuidado quando forem analisar os ambientes de banco de dados com o STATSPACK, principalmente consultores que analisam bancos de dados diferentes diariamente, onde não tem o conhecimento do dia a dia e das top querys.
Se for uma instância que possua um valor considerável de memória, muitos sql’s podem demorar para serem age-out ou invalidados (ou pela app, compilação/alteração de objetos ou por coleta de estatísticas) dessa forma os reais SQL’S que estariam causando os problemas de performance no determinado intervalo escolhido, podem não aparecer no report se outros cursores antigos que tiveram mais consumo ainda estiverem presentes na memória onde você gastaria o seu tempo analisando as querys erradas.
Para ficar mais claro, abaixo mostro a principal sequencia do procedimento de coleta do snapshot do statspack relacionada ao assunto desse POST, para aprofundar nossos conhecimentos. (Não confundam com o processo todo.)
Quando o snap é criado, acontece um insert na principal tabela do STATSPACK no quesito análise de querys ( tabela stats$sql_summary ) que possui as informações dos top consumidores, cumulativo. Segue:

 insert into stats$sql_summary
 ( snap_id
 , dbid
 , instance_number
 , text_subset
 , sql_id
 , sharable_mem
 , sorts
 , module
 , loaded_versions
 , fetches
 , executions
 , px_servers_executions
 , end_of_fetch_count
 , loads
 , invalidations
 , parse_calls
 , disk_reads
 , direct_writes
 , buffer_gets
 , application_wait_time
 , concurrency_wait_time
 , cluster_wait_time
 , user_io_wait_time
 , plsql_exec_time
 , java_exec_time
 , rows_processed
 , command_type
 , address
 , hash_value
 , old_hash_value
 , version_count
 , cpu_time
 , elapsed_time
 , avg_hard_parse_time
 , outline_sid
 , outline_category
 , child_latch
 , sql_profile
 , program_id
 , program_line#
 , exact_matching_signature
 , force_matching_signature
 , last_active_time
 )
 select /*+ index (sql.GV$SQL.X$KGLOB) */
 l_snap_id
 , p_dbid
 , p_instance_number
 , max(substrb(sql_text,1,31)) text_subset
 , max(sql_id) sql_id
 , sum(sharable_mem) sharable_mem
 , sum(sorts) sorts
 , max(module) module
 , sum(loaded_versions) loaded_versions
 , sum(fetches) fetches
 , sum(executions) executions
 , sum(px_servers_executions) px_servers_executions
 , sum(end_of_fetch_count) end_of_fetch_count
 , sum(loads) loads
 , sum(invalidations) invalidations
 , sum(parse_calls) parse_calls
 , sum(disk_reads) disk_reads
 , sum(direct_writes) direct_writes
 , sum(buffer_gets) buffer_gers
 , sum(application_wait_time) application_wait_time
 , sum(concurrency_wait_time) concurrency_wait_time
 , sum(cluster_wait_time) cluster_wait_time
 , sum(user_io_wait_time) user_io_wait_time
 , sum(plsql_exec_time) plsql_exec_time
 , sum(java_exec_time) java_exec_time
 , sum(rows_processed) rows_processed
 , max(command_type) command_type
 , address
 , max(hash_value) hash_value
 , old_hash_value
 , count(1) version_count
 , sum(cpu_time) cpu_time
 , sum(elapsed_time) elapsed_time
 , null avg_hard_parse_time
 , max(outline_sid) outline_sid
 , max(outline_category) outline_category
 , max(child_latch) child_latch
 , max(sql_profile) sql_profile
 , max(program_id) program_id
 , max(program_line#) program_line#
 , max(exact_matching_signature) exact_matching_signature
 , max(force_matching_signature) force_matching_signature
 , max(last_active_time) last_active_time
 from v$sql sql
 where is_obsolete = 'N' -- Aqui é uma das regras
 and sql_id in (select /*+ unnest full (sqlstats) */
 sql_id
 from stats$v$sqlstats_summary sqlstats
 where ( buffer_gets > l_buffer_gets_th -- daqui para baixo é o restante das regras
 or disk_reads > l_disk_reads_th
 or parse_calls > l_parse_calls_th
 or executions > l_executions_th
 or sharable_mem > l_sharable_mem_th
 or version_count > l_version_count_th
 )
 )
 group by old_hash_value, address;

Acima, o objeto chamado stats$v$sqlstats_summary dentro do IN é uma VIEW que esta localizada no schema SYS após a instalação do STATSPACK.

Essa VIEW é referenciada com a query abaixo, na qual é utilizada para somar os recursos consumidos por cada cursor, na qual é utilizado no insert acima para restringir as querys que satisfazem os thresholds informados no início do post.

select sql_id
 , sum(parse_calls) parse_calls
 , sum(disk_reads) disk_reads
 , sum(buffer_gets) buffer_gets
 , sum(executions) executions
 , sum(version_count) version_count
 , sum(cpu_time) cpu_time
 , sum(elapsed_time) elapsed_time
 , sum(sharable_mem) sharable_mem
 from v$sqlstats
 group by sql_id;

O próximo passo seria na execução do relatório de performance SPREPORT.SQL
No momento de execução do relatório de análise (?/rdbms/admin/spreport.sql ) é feito um insert em uma tabela temporária com todos os dados capturados do intervalo desejado que auxiliará na criação do report. Segue:

insert into stats$temp_sqlstats
 ( old_hash_value, text_subset, module
 , delta_buffer_gets, delta_executions, delta_cpu_time
 , delta_elapsed_time, avg_hard_parse_time, delta_disk_reads, delta_parse_calls
 , max_sharable_mem, last_sharable_mem
 , delta_version_count, max_version_count, last_version_count
 , delta_cluster_wait_time, delta_rows_processed
 )
 select old_hash_value, text_subset, module
 , delta_buffer_gets, delta_executions, delta_cpu_time
 , delta_elapsed_time, avg_hard_parse_time, delta_disk_reads, delta_parse_calls
 , max_sharable_mem, last_sharable_mem
 , delta_version_count, max_version_count, last_version_count
 , delta_cluster_wait_time, delta_rows_processed
 from ( select -- sum deltas
 old_hash_value
 , text_subset
 , module
 , sum(case
 when snap_id = &&begin_snap and prev_snap_id = -1
 then 0
 else
 case when (address != prev_address)
 or (buffer_gets < prev_buffer_gets)
 then buffer_gets
 else buffer_gets - prev_buffer_gets
 end
 end) delta_buffer_gets
 , sum(case
 when snap_id = &&begin_snap and prev_snap_id = -1
 then 0
 else
 case when (address != prev_address)
 or (executions < prev_executions)
 then executions
 else executions - prev_executions
 end
 end) delta_executions
 , sum(case
 when snap_id = &&begin_snap and prev_snap_id = -1
 then 0
 else
 case when (address != prev_address)
 or (cpu_time < prev_cpu_time)
 then cpu_time
 else cpu_time - prev_cpu_time
 end
 end) delta_cpu_time
 , sum(case
 when snap_id = &&begin_snap and prev_snap_id = -1
 then 0
 else
 case when (address != prev_address)
 or (elapsed_time < prev_elapsed_time)
 then elapsed_time
 else elapsed_time - prev_elapsed_time
 end
 end) delta_elapsed_time
 , avg(case
 when snap_id = &&begin_snap and prev_snap_id = -1
 then 0
 else avg_hard_parse_time
 end) avg_hard_parse_time
 , sum(case
 when snap_id = &&begin_snap and prev_snap_id = -1
 then 0
 else
 case when (address != prev_address)
 or (disk_reads < prev_disk_reads)
 then disk_reads
 else disk_reads - prev_disk_reads
 end
 end) delta_disk_reads
 , sum(case
 when snap_id = &&begin_snap and prev_snap_id = -1
 then 0
 else
 case when (address != prev_address)
 or (parse_calls < prev_parse_calls)
 then parse_calls
 else parse_calls - prev_parse_calls
 end
 end) delta_parse_calls
 , max(sharable_mem) max_sharable_mem
 , sum(case when snap_id = &&end_snap
 then last_sharable_mem
 else 0
 end) last_sharable_mem
 , sum(case
 when snap_id = &&begin_snap and prev_snap_id = -1
 then 0
 else
 case when (address != prev_address)
 or (version_count < prev_version_count)
 then version_count
 else version_count - prev_version_count
 end
 end) delta_version_count
 , max(version_count) max_version_count
 , sum(case when snap_id = &&end_snap
 then last_version_count
 else 0
 end) last_version_count
 , sum(case
 when snap_id = &&begin_snap and prev_snap_id = -1
 then 0
 else
 case when (address != prev_address)
 or (cluster_wait_time < prev_cluster_wait_time)
 then cluster_wait_time
 else cluster_wait_time - prev_cluster_wait_time
 end
 end) delta_cluster_wait_time
 , sum(case
 when snap_id = &&begin_snap and prev_snap_id = -1
 then 0
 else
 case when (address != prev_address)
 or (rows_processed < prev_rows_processed)
 then rows_processed
 else rows_processed - prev_rows_processed
 end
 end) delta_rows_processed
 from ( select /*+ first_rows */
 -- windowing function
 snap_id
 , old_hash_value
 , text_subset
 , module
 , (lag(snap_id, 1, -1)
 over (partition by old_hash_value
 , dbid
 , instance_number
 order by snap_id)) prev_snap_id
 , (lead(snap_id, 1, -1)
 over (partition by old_hash_value
 , dbid
 , instance_number
 order by snap_id)) next_snap_id
 , address
 ,(lag(address, 1, hextoraw(0))
 over (partition by old_hash_value
 , dbid
 , instance_number
 order by snap_id)) prev_address
 , buffer_gets
 ,(lag(buffer_gets, 1, 0)
 over (partition by old_hash_value
 , dbid
 , instance_number
 order by snap_id)) prev_buffer_gets
 , cpu_time
 ,(lag(cpu_time, 1, 0)
 over (partition by old_hash_value
 , dbid
 , instance_number
 order by snap_id)) prev_cpu_time
 , executions
 ,(lag(executions, 1, 0)
 over (partition by old_hash_value
 , dbid
 , instance_number
 order by snap_id)) prev_executions
 , elapsed_time
 ,(lag(elapsed_time, 1, 0)
 over (partition by old_hash_value
 , dbid
 , instance_number
 order by snap_id)) prev_elapsed_time
 , avg_hard_parse_time
 , disk_reads
 ,(lag(disk_reads, 1, 0)
 over (partition by old_hash_value
 , dbid
 , instance_number
 order by snap_id)) prev_disk_reads
 , parse_calls
 ,(lag(parse_calls, 1, 0)
 over (partition by old_hash_value
 , dbid
 , instance_number
 order by snap_id)) prev_parse_calls
 , sharable_mem
 ,(last_value(sharable_mem)
 over (partition by old_hash_value
 , dbid
 , instance_number
 order by snap_id)) last_sharable_mem
 ,(lag(sharable_mem, 1, 0)
 over (partition by old_hash_value
 , dbid
 , instance_number
 order by snap_id)) prev_sharable_mem
 , version_count
 ,(lag(version_count, 1, 0)
 over (partition by old_hash_value
 , dbid
 , instance_number
 order by snap_id)) prev_version_count
 ,(last_value(version_count)
 over (partition by old_hash_value
 , dbid
 , instance_number
 order by snap_id)) last_version_count
 , cluster_wait_time
 ,(lag(cluster_wait_time, 1, 0)
 over (partition by old_hash_value
 , dbid
 , instance_number
 order by snap_id)) prev_cluster_wait_time
 , rows_processed
 ,(lag(rows_processed, 1, 0)
 over (partition by old_hash_value
 , dbid
 , instance_number
 order by snap_id)) prev_rows_processed
 from stats$sql_summary s
 where s.snap_id between &&begin_snap and &&end_snap
 and s.dbid = &&dbid
 and s.instance_number = &&inst_num
 )
 group by old_hash_value
 , text_subset
 , module
 )
 where delta_buffer_gets > 0
 or delta_executions > 0
 or delta_cpu_time > 0
 or delta_disk_reads > 0
 or delta_parse_calls > 0
 or delta_cluster_wait_time > 0;

Logo após, o próximo passo seria a execução dos scripts de análise de cada estatística como: BUFFER GETS, CPU TIME, DISK READ, ELAPSED… e assim por diante.

Aqui é um exemplo do script utilizado para capturar as principais querys ordenadas por CPU TIME:

BY CPU TIME:

select /*+ orderd use_nl (topn st) */
 decode(st.piece
 ,0
 ,lpad(to_char(delta_cpu_time/&&ustos,'99990.00')
 , 10) || ' ' ||
 lpad(to_char(delta_executions,'999,999,999')
 , 12) || ' ' ||
 lpad(decode(delta_executions
 ,0 , ' '
 ,to_char(delta_cpu_time/&&ustos/delta_executions,'999990.00'))
 , 10) || ' ' ||
 lpad(decode( :dbcpu, 0, ' '
 , to_char(100*delta_cpu_time/:dbcpu,'999.0'))
 , 6) || ' ' ||
 lpad(to_char(delta_elapsed_time/&&ustos,'99990.00')
 , 10) || ' ' ||
 lpad(to_char(delta_buffer_gets,'99,999,999,999')
 , 15) || ' ' ||
 lpad(topn.old_hash_value, 10) || ' ' ||
 decode(topn.module, null, st.sql_text
 ,rpad('Module: '||topn.module,80)||st.sql_text)
 , st.sql_text) aa
 , topn.old_hash_value hv
 from ( select *
 from ( select *
 from perfstat.stats$temp_sqlstats
 where decode(:dbcpu, 0, 2, null, 2, 100*delta_cpu_time/:dbcpu)
 > decode(:dbcpu, 0, 1, null, 2, &&top_pct_sql)
 order by delta_cpu_time desc
 )
 where rownum <= &&top_n_sql
 ) topn
 , stats$sqltext st
 where st.old_hash_value(+) = topn.old_hash_value
 and st.text_subset(+) = topn.text_subset
 and st.piece < &&num_rows_per_hash
 order by topn.delta_cpu_time desc, topn.old_hash_value, st.piece;

E assim por diante. A query continua a mesma, mudando só a estatística e threshold. Como podem notar, o processo acima proporciona algumas chances para que o erro de apresentação da top query aconteça.

Ou seja, precisamos adaptar, criar algumas modificações para que possamos obter os reais consumidores ou no mínimo realizar um duplo check sobre o REPORT com querys diretamente nas tabelas do STATSPACK.

No meu caso, prefiro utilizar o script abaixo na qual pode ser utilizado para tentar chegar o mais próximo possível dos valores reais de cada intervalo. Tentei desenvolver o que foi possível ate agora, na medida que algumas situações ocorriam na qual mostravam as querys “erradas”. Utilizo uma coluna nova chamada LAST_ACTIVE_TIME (creio que foi adicionada a partir da versão 11g, não tenho certeza, preciso checar na versão 10.2.0.4 e 11.2.0.1) juntamente com outras combinações como por exemplo, usando no select interno -24hs do valor que estou procurando para que a primeira linha da função analítica LAG também tenha maior possibilidade de acerto entre outras configurações que notarão na query. Por enquanto esta funcionando perfeitamente. (até uma nova situação ocorrer :( )

SQL> ! cat spsql.sql
------------------------------------------------------------------------------------------------
--
-- Nome :   spsql.sql
-- Objetivo:    Realizar analise de performance sobre histórico, utilizando as tabelas statspack.
--
-- Autor:      Wellington Prado
-- Copyright:   (c) http://www.wellingtonprado.com
--
------------------------------------------------------------------------------------------------
set lines 900
set timing OFF
SET FEED OFF

col c1 heading 'Interval|time'          format a20
col c2 heading 'Exec|Delta'             format 999,999,999,999
col c3 heading 'Buffer|Gets|Delta'      format 999,999,999,999
col c4 heading 'Disk|Reads|Delta'       format 9,999,999,999
col c5 heading 'IO Wait|Delta|Sec'      format 999.999
col c6 heading 'App|Wait|Delta|Sec'     format 999.999
col c7 heading 'Cncr|Wait|Delta|Sec'    format 999.999
col c8 heading 'CPU|Time|Delta|Micro'   format 999,999,999,999
col c12 heading 'CPU|Time|Delta|Sec'    format 999.999
col c9 heading 'Elpsd|Time|Delta|Micro' format 999,999,999,999
col c10 heading 'SCHEMA'                format a14
col c11 heading 'Elpsd|Time|Delta|Sec'  format 999.999
COL c13 heading 'Avg|Elpsd|per|exec'    format 999.999
col c14 heading 'Avg|Buffer|Gets|per|exec'  format 999,999,999,999,999
col c15 heading 'Avg|Disk|Reads|per|exec'   format 9,999,999,999
col c16 heading 'Avg|CPU|Time|Micro|per|exec'   format 999,999,999,999
COL PHY_READ_REQ            format 999,999,999,999999,999
COL PHY_WRITE_REQ            format 999,999,999,999999,999
col rws                  format 999,999,999,999999,999
col AVG_ELAPSED_PER_EXEC        format 99,999,999,999,999
col c0 NOPRINT NEW_VALUE ZETRASH
col c100 NOPRINT NEW_VALUE ZETRASH1
col LAST_ACTIVE for a30
col MODULE for a20

alter session set nls_date_format='DD/MM/YYYY HH24:MI';

set feed on

ACCEPT Psqlid                 prompt 'Enter SQL ID: Default * = '
ACCEPT P_INTERVA default null PROMPT "Inter1 (Formato DD/MM/YYYY HH24:MI): Default 2 hour ago..= "
ACCEPT P_INTERVB default null PROMPT "Inter2 (Formato DD/MM/YYYY HH24:MI): Default Now..= "
ACCEPT PRANK     default null PROMPT "TOP N (Enter Rank NUMBER, default = 10)..= "
ACCEPT P_ORDER   default null PROMPT "N. Ordenacao. 1=BG, 2=DR, 3=CPU, 4=EXEC, 5=ELAPSED_T | Default = 1 ..= "

SELECT snap_id
, c1
, sql_id
, OLD_HV
, module
, c2
, PARSE_CALLS
, AVG_HARD_PARSE_TIME
, FETCHES
, CPU_TIME/1000000 c12
, CPU_TIME c8
, CPU_TIME/decode(nvl(c2,0),0,1,c2) c16
, c11
, c9
, c11/decode(nvl(c2,0),0,1,c2) c13
, c4
, c4/decode(nvl(c2,0),0,1,c2) c15
, c3
, c3/decode(nvl(c2,0),0,1,c2) c14
, SORTS
, ROWS_PROCESSED
, VERSION_COUNT
, c6
, c7
, c5
, SQL_PROFILE
, last_active
FROM (
SELECT snap_id,
  SNAP_TIME c1,
  sql_id,
  HV,
  OLD_HV,
  module,
  EXECUTIONS C2,
  PARSE_CALLS PARSE_CALLS,
  AVG_HARD_PARSE_TIME,
  FETCHES,
  CPU_TIME,
  ELAPSED_TIME c9,
  ELAPSED_TIME/1000000 c11,  
  disk_reads C4,
  buffer_gets C3,
  SORTS,
  ROWS_PROCESSED,
  VERSION_COUNT,
  APPLICATION_WAIT_TIME/1000000 c6,
  CONCURRENCY_WAIT_TIME/1000000 c7,
  USER_IO_WAIT_TIME/1000000 c5,
  SQL_PROFILE,
  last_active,
  lag_last_active,
  rank () over (PARTITION BY SNAP_ID ORDER BY (CASE WHEN NVL(&P_ORDER,1) = 1 THEN  buffer_gets
                              WHEN NVL(&P_ORDER,1) = 2 THEN  disk_reads    
                            WHEN NVL(&P_ORDER,1) = 3 THEN  CPU_TIME
                            WHEN NVL(&P_ORDER,1) = 4 THEN  EXECUTIONS
                            WHEN NVL(&P_ORDER,1) = 5 THEN  ELAPSED_TIME END) DESC ) AS RNK
FROM
  (SELECT SP_SUMM.snap_id snap_id,
    TO_CHAR(SP_SNAP.SNAP_TIME, 'DD/MM/YYYY HH24:MI') SNAP_TIME,
    SP_SUMM.sql_id,
    SP_SUMM.TEXT_SUBSET,
    SP_SUMM.HASH_VALUE HV,
    SP_SUMM.OLD_HASH_VALUE OLD_HV,
    --      SUBSTR(SP_SUMM.SQL_TEXT,1,100) SQL_TEXT,
    SP_SUMM.module,
    NVL(DECODE(greatest(SP_SUMM.EXECUTIONS, NVL(lag(SP_SUMM.EXECUTIONS,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id),0)), SP_SUMM.EXECUTIONS, DECODE(SP_SUMM.EXECUTIONS - lag(SP_SUMM.EXECUTIONS,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id),0,SP_SUMM.EXECUTIONS,SP_SUMM.EXECUTIONS - lag(SP_SUMM.EXECUTIONS,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id)), SP_SUMM.EXECUTIONS), 0) EXECUTIONS,
    NVL(DECODE(greatest(SP_SUMM.PARSE_CALLS, NVL(lag(SP_SUMM.PARSE_CALLS,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id),0)), SP_SUMM.PARSE_CALLS, SP_SUMM.PARSE_CALLS - lag(SP_SUMM.PARSE_CALLS,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id), SP_SUMM.PARSE_CALLS), 0) PARSE_CALLS,
    NVL(DECODE(greatest(SP_SUMM.AVG_HARD_PARSE_TIME, NVL(lag(SP_SUMM.AVG_HARD_PARSE_TIME,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id),0)), SP_SUMM.AVG_HARD_PARSE_TIME, SP_SUMM.AVG_HARD_PARSE_TIME - lag(SP_SUMM.AVG_HARD_PARSE_TIME,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id), SP_SUMM.AVG_HARD_PARSE_TIME), 0) AVG_HARD_PARSE_TIME,
    NVL(DECODE(greatest(SP_SUMM.FETCHES, NVL(lag(SP_SUMM.FETCHES,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id),0)), SP_SUMM.FETCHES, DECODE(SP_SUMM.FETCHES - lag(SP_SUMM.FETCHES,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id),0 ,SP_SUMM.FETCHES ,SP_SUMM.FETCHES - lag(SP_SUMM.FETCHES,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id)), SP_SUMM.FETCHES), 0) FETCHES,      
    NVL(DECODE(greatest(SP_SUMM.CPU_TIME, NVL(lag(SP_SUMM.CPU_TIME,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id),0)), SP_SUMM.CPU_TIME, SP_SUMM.CPU_TIME - lag(SP_SUMM.CPU_TIME,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id), SP_SUMM.CPU_TIME), 0) CPU_TIME,      
    NVL(DECODE(greatest(SP_SUMM.ELAPSED_TIME, NVL(lag(SP_SUMM.ELAPSED_TIME,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id),0)), SP_SUMM.ELAPSED_TIME, SP_SUMM.ELAPSED_TIME - lag(SP_SUMM.ELAPSED_TIME,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id), SP_SUMM.ELAPSED_TIME), 0) ELAPSED_TIME,      
    NVL(DECODE(greatest(SP_SUMM.DISK_READS, NVL(lag(SP_SUMM.DISK_READS,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id),0)), SP_SUMM.DISK_READS, SP_SUMM.DISK_READS - lag(SP_SUMM.DISK_READS,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id), SP_SUMM.DISK_READS), 0) DISK_READS,      
    NVL(DECODE(greatest(SP_SUMM.BUFFER_GETS, NVL(lag(SP_SUMM.BUFFER_GETS,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id),0)), SP_SUMM.BUFFER_GETS, SP_SUMM.BUFFER_GETS - lag(SP_SUMM.BUFFER_GETS,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id), SP_SUMM.BUFFER_GETS), 0) BUFFER_GETS,      
    NVL(DECODE(greatest(SP_SUMM.SORTS, NVL(lag(SP_SUMM.SORTS,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id),0)), SP_SUMM.SORTS, SP_SUMM.SORTS - lag(SP_SUMM.SORTS,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id), SP_SUMM.SORTS), 0) SORTS,      
    NVL(DECODE(greatest(SP_SUMM.ROWS_PROCESSED, NVL(lag(SP_SUMM.ROWS_PROCESSED,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id),0)), SP_SUMM.ROWS_PROCESSED, DECODE(SP_SUMM.ROWS_PROCESSED - lag(SP_SUMM.ROWS_PROCESSED,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id),0 ,SP_SUMM.ROWS_PROCESSED ,SP_SUMM.ROWS_PROCESSED - lag(SP_SUMM.ROWS_PROCESSED,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id)), SP_SUMM.ROWS_PROCESSED), 0) ROWS_PROCESSED,      
    NVL(DECODE(greatest(SP_SUMM.VERSION_COUNT, NVL(lag(SP_SUMM.VERSION_COUNT,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id),0)), SP_SUMM.VERSION_COUNT, DECODE(SP_SUMM.VERSION_COUNT - lag(SP_SUMM.VERSION_COUNT,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id),0 ,SP_SUMM.VERSION_COUNT ,SP_SUMM.VERSION_COUNT - lag(SP_SUMM.VERSION_COUNT,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id)), SP_SUMM.VERSION_COUNT), 0) VERSION_COUNT,      
    NVL(DECODE(greatest(SP_SUMM.APPLICATION_WAIT_TIME, NVL(lag(SP_SUMM.APPLICATION_WAIT_TIME,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id),0)), SP_SUMM.APPLICATION_WAIT_TIME, SP_SUMM.APPLICATION_WAIT_TIME - lag(SP_SUMM.APPLICATION_WAIT_TIME,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id), SP_SUMM.APPLICATION_WAIT_TIME), 0) APPLICATION_WAIT_TIME,      
    NVL(DECODE(greatest(SP_SUMM.CONCURRENCY_WAIT_TIME, NVL(lag(SP_SUMM.CONCURRENCY_WAIT_TIME,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id),0)), SP_SUMM.CONCURRENCY_WAIT_TIME, SP_SUMM.CONCURRENCY_WAIT_TIME - lag(SP_SUMM.CONCURRENCY_WAIT_TIME,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id), SP_SUMM.CONCURRENCY_WAIT_TIME), 0) CONCURRENCY_WAIT_TIME,      
    NVL(DECODE(greatest(SP_SUMM.USER_IO_WAIT_TIME, NVL(lag(SP_SUMM.USER_IO_WAIT_TIME,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id),0)), SP_SUMM.USER_IO_WAIT_TIME, SP_SUMM.USER_IO_WAIT_TIME - lag(SP_SUMM.USER_IO_WAIT_TIME,1,0) over (partition BY SP_SUMM.dbid, SP_SUMM.instance_number, SP_SUMM.hash_value order by SP_SUMM.snap_id), SP_SUMM.USER_IO_WAIT_TIME), 0) USER_IO_WAIT_TIME,      
    SP_SUMM.SQL_PROFILE SQL_PROFILE,
    TO_CHAR(SP_SUMM.last_active_time,'DD/MM/YYYY HH24:MI:SS') last_active,
    NVL(lag(TO_CHAR(SP_SUMM.last_active_time,'DD/MM/YYYY HH24:MI:SS')) over (partition BY SP_SUMM.old_hash_value order by SP_SUMM.snap_id),SP_SUMM.last_active_time-1/1440) lag_last_active    
  FROM  STATS$SQL_SUMMARY SP_SUMM, stats$snapshot SP_SNAP 
  WHERE SP_SUMM.SNAP_ID       = SP_SNAP.SNAP_ID
  AND SP_SUMM.DBID            = SP_SNAP.DBID
  AND SP_SUMM.INSTANCE_NUMBER = SP_SNAP.INSTANCE_NUMBER
  AND SP_SNAP.SNAP_TIME >= nvl(TO_DATE(decode('&P_INTERVA','null',null,'&P_INTERVA'),'DD/MM/YYYY HH24:MI')-24/24 ,TO_DATE(SYSDATE-24/24, 'DD/MM/YYYY HH24:MI'))
  AND SP_SNAP.SNAP_TIME <= nvl(TO_DATE(decode('&P_INTERVB','null',null,'&P_INTERVB'),'DD/MM/YYYY HH24:MI'),TO_DATE(SYSDATE, 'DD/MM/YYYY HH24:MI'))
  AND SP_SUMM.sql_id like nvl('&Psqlid','%')
 )
  WHERE (last_active > lag_last_active 
   AND  EXECUTIONS > 0 )
   AND SNAP_TIME >= nvl(TO_DATE(decode('&P_INTERVA','null',null,'&P_INTERVA'),'DD/MM/YYYY HH24:MI'),TO_DATE(SYSDATE-2/24, 'DD/MM/YYYY HH24:MI'))
   AND SNAP_TIME <= nvl(TO_DATE(decode('&P_INTERVB','null',null,'&P_INTERVB'),'DD/MM/YYYY HH24:MI'),TO_DATE(SYSDATE, 'DD/MM/YYYY HH24:MI'))
)
 WHERE  RNK <= nvl(&PRANK,10)
ORDER BY snap_id;

clear compute

Vamos realizar o teste do script acima executando no mesmo período usado em um dos snapshots usados no post, na qual o relatório spreport.sql trouxe o top consumidor errado. Vamos utilizar o snap_id abaixo (em vermelho. Vejam a query que não deveria estar no relatório em vermelho também).

Snapshot   Snap Id      Snap Time      Sessions Curs/Sess  Comment
 ~~~~~~~~ ---------- ------------------ -------- --------- ------------------
 Begin Snap: 58      29-May-14 16:00:55    21       1.3
 End Snap:   59      29-May-14 16:08:01    21       1.3

SQL ordered by Gets DB/Inst: DB11GG/DB11G Snaps: 58-59
 -> End Buffer Gets Threshold: 10000 Total Buffer Gets: 90,083
 -> Captured SQL accounts for 97.0% of Total Buffer Gets
 -> SQL reported below exceeded 1.0% of Total Buffer Gets

                                                      CPU    Elapsd      Old
 Buffer Gets      Executions   Gets per Exec %Total Time (s) Time (s)  Hash Value
 --------------- ------------ -------------- ------ -------- --------- ----------
 131,242             520           252.4      145.7   4.95     10.91   1064022172
 Module: SQL*Plus
 SELECT /*QUERY_BG001*/ * FROM TB_BG

 25,391              100           253.9       28.2   0.59      1.50    1069844640
 Module: SQL*Plus
 SELECT /*QUERY_BG_OTHER1*/ * FROM TB_BG

25,200               100           252.0       28.0   1.08      2.27    1172826369
 Module: SQL*Plus
 SELECT /*QUERY_BG_OTHER2*/ * FROM TB_BG

25,200               100           252.0       28.0   0.98      1.63    3581366766
 Module: SQL*Plus
 SELECT /*QUERY_BG_OTHER3*/ * FROM TB_BG

5,722                520           11.0         6.4   0.33       0.49   2275360153
 select /*+ connect_by_filtering */ privilege#,level from sysauth
 $ connect by grantee#=prior privilege# and privilege#>0 start wi
 th grantee#=:1 and privilege#>0
 3,300               300           11.0         3.7   0.15       0.21   2275360153
 select /*+ connect_by_filtering */ privilege#,level from sysauth
 $ connect by grantee#=prior privilege# and privilege#>0 start wi
 th grantee#=:1 and privilege#>0

Vou colocar somente algumas colunas que o script utiliza para ficar mais legivel:

SQL> @SPSQL
Enter SQL ID: Default * = 
Inter1 (Formato DD/MM/YYYY HH24:MI): Default 2 hour ago..= 29/05/2014 16:01
Inter2 (Formato DD/MM/YYYY HH24:MI): Default Now..= 29/05/2014 16:09
TOP N (Enter Rank NUMBER, default = 10)..= 
N. Ordenacao. 1=BG, 2=DR, 3=CPU, 4=EXEC, 5=ELAPSED_T | Default = 1 ..=

resultComo evidenciado acima, a query “errada/antiga” não aparece no resultado. Testei o script acima em varias situações e por enquanto esta atendendo, mas sabem como é…

Caso você encontre alguma nova situação, fique a vontade em comentar…

Forte abraço

 

One thought on “Oracle STATSPACK: Cuidados na análise.”

  1. Rommel Campos says:

    Muito bom! Parabéns! Excelente conteúdo.

Leave a Reply to Rommel Campos Cancel reply

Your email address will not be published. Required fields are marked *