Por que o Oracle está lento?

A V$SYSTEM_EVENT armazena os Wait Events que a Instance sofreu, somados desde que ela foi iniciada.
Por que é totalmente cumulativa, ela é geralmente desprezada mesmo em cenários de problemas de desempenho globais – quando tudo está lento.
Mas ao duplicar seu conteúdo em determinado ponto do tempo, e após certo tempo duplicar novamente e analisar a diferença, chega-se a conclusão dos maiores Wait Events da Instance entre o período da primeira duplicação e da segunda.
No exemplo abaixo, foi óbvio constatar que os maiores gargalos são de I/O, tanto de gravação quanto de leitura. O próximo passo seria então analisar os causadores deste I/O, ou o que está impedindo a vazão das leituras e escritas.

SQL> CREATE TABLE PRE_SYSTEM_EVENT AS SELECT * FROM V$SYSTEM_EVENT;
Tabela criada.
SQL> -- Executei uma duplicação de tabela em outra conexão...
SQL> CREATE TABLE POS_SYSTEM_EVENT AS SELECT * FROM V$SYSTEM_EVENT;
Tabela criada.
SQL> SELECT A.EVENT, A.TIME_WAITED, B.TIME_WAITED, (B.TIME_WAITED-A.TIME_WAITED) DIFF FROM PRE_SYSTEM_EVENT A, POS_SYSTEM_EVENT B WHERE A.EV
ENT = B.EVENT AND A.TIME_WAITED IS NOT NULL AND ((B.TIME_WAITED-A.TIME_WAITED) > 0) AND A.WAIT_CLASS != 'Idle' ORDER BY DIFF;
EVENT                                                                            TIME_WAITED TIME_WAITED       DIFF
-------------------------------------------------------------------------------- ----------- ----------- ----------
direct path write                                                                          4           8          4
os thread startup                                                                        147         154          7
log file single write                                                                      2          47         45
log file sync                                                                             46          92         46
direct path read                                                                           2         192        190
control file parallel write                                                               41        1406       1365
log file sequential read                                                                   0        1477       1477
db file scattered read                                                                   532        7588       7056
Disk file operations I/O                                                                 114        8312       8198
db file sequential read                                                                 3827       14374      10547
db file parallel write                                                                   196       11081      10885
log file parallel write                                                                  170       11133      10963
control file sequential read                                                             297       12967      12670
13 linhas selecionadas.
SQL>

6 comments

  1. Portilho, na documentação da VIEW: V$SESSION_EVENT e V$SYSTEM_EVENT informa que a coluna TIME_WAITED = “Total amount of time waited for the event by the session (in hundredths of a second)” ou seja os valores são em centésimos de segundos.

    Estou considerando essa coluna como milissegundo, estou errado? Se eu fizer um SUM nessa coluna e depois multiplicar o valor retornado por 1000000 eu tenho segundos. Isso está correto?

    Ex: utilizando sua consulta [SELECT EVENT, SUM(TIME_WAITED) FROM V$SESSION_EVENT WHERE WAIT_CLASS != ‘Idle’ GROUP BY EVENT ORDER BY 2;] ela me retorna um valor como 12024758 depois de multiplicado por 1000000 = 12,024758 (12 segundos) certo ou errado?

    1. Olá Yuri.
      Como são centisegundos, você deve dividir por 100, para obter o valor em segundos.

      1. Correto Portilho!
        Estou intrigado com os valores retornados pela SESSION_EVENT e acabei me confundido com os cálculos que realizei para tentar achar um valor “aceitável”.

        1 – Por exemplo, 3 eventos com 5 resultados obtidos em um intervalo (média de 4h):

        “db file async I/O submit” (11914562, 12024758, 12045699, 12049457, 12053277)
        ou seja:
        (33h 1985m 45s, 33h 2004m 7s, 33h 2007m 36s, 33h 2008m 14s, 33h 2008m 52s)

        “control file parallel write” (11377934, 11521515, 11553317, 11555352, 11557849)
        ou seja:
        (31h 1896m 19s, 32h 1920m 15s, 32h 1925m 33s, 32h 1925m 53s, 32h 1926m 18s)

        “log file parallel write” (10878049, 10993773, 11011334, 11014883, 11019233)
        ou seja:
        (30h 1813m 0s, 30h 1832m 17s, 30h 1835m 13s, 30h 1835m 48s, 30h 1836m 32s)

        Não acha esses valores exorbitantes?

        2 – Na SESSION_WAIT coluna SECONDS_IN_WAIT:

        “db file scattered read” (null, 0, null, null, null)
        “asynch descriptor resize” (null, 0, 14, null, null)
        “SQL*Net message from dblink” (2, 9, 18, null, 17-22)

        null = evento não exibido na coleta

        Versão: 11.2.0.1.0

        1. A V$SESSION_EVENT mostra as Waits por SID, acumuladas deste que estes SIDs conectaram-se. Encontrar tempos altos nesta View através de uma soma não é inesperado, pois os SIDs dos processos background (DBWR, LGWR, etc.) também estão contabilizados aí. Seria mais preciso olhar SID a SID.

          Reparei em tempos altos na V$SESSION_WAIT, para as Waits “asynch descriptor resize” (14) e “SQL*Net message from dblink” (18, 17, 22). Este servidor é de produção, ou é um teste?

          1. Produção utilizando o Patchset 11.2.0.1? Não creio que isto seja causa de lentidão, mas cara, esse banco tem que ser atualizado urgentemente… 🙂

Leave a Reply

O seu endereço de e-mail não será publicado. Campos obrigatórios são marcados com *

Esse site utiliza o Akismet para reduzir spam. Aprenda como seus dados de comentários são processados.