Embora introduzido no Oracle 7, o Oracle Wait Interface (OWI) continua sendo hoje uma ferramenta inestimável para os DBAs, através dela é possível obter informações que ajudam na solução de problemas e na busca de melhorias na performance de todo o ambiente de banco de dados.
O Oracle Wait Interface nada mais é que uma coleção de visões dinâmicas de performance e arquivo de rastreamento SQL(SQL trace file) que promovem estatísticas de desempenho sobre gargalos de um processo mais conhecidas como eventos de espera(wait events) ou sintomas.
Utilizando o OWI podemos identificar todos os gargalos de espera que incidiram desde o inicio ao termino de um processo, incluindo esperas por operações de I/O, locks, network, dentre outros. Proporcionando um direcionamento para a solução ou redução do impacto causado pelo gargalo de espera.
Atualmente na versão 12.1.0.1 contamos com 1.567 eventos de espera(wait events), diferentemente de seus antecessores. O Oracle 11.2.0.3 por exemplo, conta com 1.152 eventos de espera, na versão 10g pouco mais de 800 enquanto na versão 7.3 contava com apenas 104 eventos de espera. (A quantidade de eventos de espera depende da versão, configuração e opções instaladas no RDBMS).
Wait Events são as condições em que uma sessão está esperando que algo aconteça. Elas podem ser a nível de sistema, onde afeta todo o banco de dados ou a nível de sessão em que afeta uma única atividade de usuário no banco de dados.
Conforme documentação Oracle, os wait events são elencados em três visões dinâmicas de performance:
V$SESSION_WAIT exibe os eventos para os quais as sessões acabaram de concluir ou estão esperando.
V$SYSTEM_EVENT exibe o número total de tempo que todas as sessões tem aguardado por eventos de espera.
V$SESSION_EVENT é semelhante ao V$SYSTEM_EVENT, mas mostra todas as esperas para cada sessão.
Todo evento de espera pertence a uma classe de espera(Wait Class). Através da visão V$EVENT_NAME podemos identificar os tipos de classe de espera e os tipos de eventos bem como o que representam os parâmetros(PARAMETER) P1,P2 e P3 da V$SESSION_WAIT igualmente como as colunas P1TEXT, P2TEXT e P3TEXT desta mesma view.
-- Lista das classes de espera
SQL> select distinct wait_class from v$event_name;
WAIT_CLASS
----------------------------------------------------------------
User I/O
Application
Network
Concurrency
Administrative
Configuration
Scheduler
Cluster
Other
Idle
System I/O
Commit
12 rows selected.
-- Detalhes de um evento:
SQL> set lines 190
SQL> col NAME for a40
SQL> col WAIT_CLASS for a20
SQL> col PARAMETER1 for a10
SQL> col PARAMETER2 for a15
SQL> col PARAMETER3 for a15
SQL> select * from v$event_name where name='db file scattered read';
EVENT# EVENT_ID NAME PARAMETER1 PARAMETER2 PARAMETER3 WAIT_CLASS_ID WAIT_CLASS# WAIT_CLASS
---------- ---------- ---------------------------------------- ---------- --------------- --------------- ------------- ----------- --------------------
118 506183215 db file scattered read file# block# blocks 1740759767 8 User I/O
A lista abaixo descreve brevemente cada classe:
Administrative
Espera resultante de comandos administrativos (DBA). Por exemplo, um rebuild de índice.
Application
Espera resultante do código da aplicação do usuário. Por exemplo, lock a nível de linha ou comando explícito de lock.
Cluster
Espera relacionada aos recursos do Real Application Clusters (RAC). Por exemplo, ‘gc cr block busy’.
Commit
Esta classe cotém apenas um evento de espera. ‘log file sync’ – espera para o redolog confirmar um commit.
Concurrency
Espera por recursos internos do banco de dados. Por exemplo, latches.
Configuration
Espera causada por uma configuração inadequada do banco de dados ou recursos da instance. Por exemplo, mal dimensionamento do tamanho dos
log file, shared pool size.
Idle
Indica que a sessão está inativa, esperando para trabalhar. Por exemplo, ‘SQL*Net message from client’.
Network
Espera relacionada a eventos de rede. Por exemplo, ‘SQL*Net more data to dblink’.
Other
Esperas que normalmente não devem ocorrem em um sistema. Por exemplo, ‘wait for EMON to spawn’)
Scheduler
Espera relacionada ao gerenciamento de recursos. Por exemplo, ‘resmgr: become active’.
System I/O
Espera por background process I/O. Por exemplo, DBWR wait for ‘db file parallel write’)
User I/O
Espera por user I/O. Por exemplo ‘db file sequential read’.
Ao longo das versões, o Oracle database ganhou outras visões de desempenho que oferecem novas informações de espera por várias perspectivas incluindo features de apoio para atender limitações do OWI como:
- ASH (Active Session History), coleta a todo segundo informações correntes de cada sessão. Seria um join da V$SESSION com a V$SESSION_WAIT porem com dados históricos das sessões ativas.
- AWR (Automatic Workload Repository), oferece o histórico de todas as atividades das sessões. Seu tempo de retenção default é 8 dias mas pode ser ajustado conforme necessidade. Os dados capturados podem ser acessados através de views (DBA_HIST_*) e pelo AWR report facilmente acessado utilizando o Oracle Enterprise Manager.
- ADDM (Automatic Database Diagnostic Monitor), faz uma análise automática dos dados capturados(snapshots) dentro do AWR e oferece recomendações de melhorias.
Algumas outras views que complementam o OWI:
V$SYSTEM_WAIT_CLASS
V$SESSION_WAIT_CLASS
V$SESSION_WAIT_HISTORY
V$EVENT_HISTOGRAM
V$EVENTMETRIC
V$SERVICE_EVENT
V$SERVICE_WAIT_CLASS
V$ACTIVE_SESSION_HISTORY
V$WAITCLASSMETRIC | V$SESSTAT
V$STATNAME
V$SYSSTAT
V$SESS_TIME_MODEL
V$SYS_TIME_MODEL
DBA_HIST_EVENT_NAME
DBA_HIST_ACTIVE_SESS_HISTORY
DBA_HIST_BG_EVENT_SUMMARY
DBA_HIST_WAITCLASSMET_SUMMARY |
Outro componente que faz parte do OWI (citado anteriormente) é o extended SQL Trace:
De forma simplificada, o rastreamento SQL (trace) é um “monitoramento” que pode ser habilitado sobre uma sessão/processo para identificarmos os comandos executados, tempos e gargalos para cada SQL, o que permite diagnosticar problemas de performance.
É possível habilitar um trace de diversas formas e com diferentes níveis de coleta:
Nível 0 Trace desabilitado. Igual ao SQL_TRACE = FALSE.
Nível 1 Informações de rastreamento SQL padrão (SQL_TRACE = TRUE). Este é o nível default.
Nível 4 Informações de rastreamento SQL + valores das bind variables.
Nível 8 Informações de rastreamento SQL + informações de wait events.
Nível 12 Informações de rastreamento SQL + informações de wait events + valores das bind variables.
Alguns métodos para se habilitar um trace na sua sessão:
--ativa trace nível 1
alter session set sql_trace=true;
--desativa trace
alter session set sql_trace=false;
--ativa o trace nível 8
alter session set events ‘10046 trace name context forever, level 8’;
--desativa o trace
alter session set events ‘10046 trace name context off’;
--Para quem possui o pacote DBMS_SUPPORT instalado:
--ativa trace nível 1
exec sys.dbms_support.start_trace;
--para incluir wait events e bind variables
exec sys.dbms_support.start_trace(waits => TRUE, binds=> TRUE);
--desativa o trace
exec sys.dbms_support.stop_trace;
Alguns métodos para se habilitar um trace em outra sessão:
--ativa o trace nível 8
execute sys.dbms_system.set_ev(SID,SERIAL#,10046,8,'');
--desativa o trace
execute sys.dbms_system.set_ev(SID,SERIAL#,10046,0,'');
--Para quem possui o pacote DBMS_SUPPORT instalado:
--ativa o trace nível 12
exec dbms_support.start_trace_in_session(
sid => sid,
serial# => serial,
waits => true,
binds => true);
--desativa o trace
exec dbms_support.stop_trace_in_session(
sid => sid,
serial# => serial);
--Utilizando o pacote DBMS_MONITOR:
--ativa o trace nível 12
exec dbms_monitor.session_trace_enable(
session_id => sid,
serial_num => serial,
waits => true,
binds => true);
--desativa o trace
exec dbms_monitor.session_trace_disable(
session_id => sid,
serial_num => serial);
Os arquivos de trace recebem a extensão .trc e podem ser encontrados na versão 10g em 2 diretórios dependendo da sessão em que o trace foi habilitado:
Sessão de usuário = USER_DUMP_DEST
SQL> show parameter USER_DUMP_DEST
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
user_dump_dest string /oratst01/app/oracle/admin/tes
te/udump
Processos background = BACKGROUND_DUMP_DEST
SQL> show parameter BACKGROUND_DUMP_DEST
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
background_dump_dest string /oratst01/app/oracle/admin/tes
te/bdump
Nas versões 11g e 12c os traces (.trc) podem ser encontrados abaixo do ADR (Automatic Diagnostic Repository) tanto para processos background como de usuários: (Diag Trace)
SQL> show parameter diagnostic_dest
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
diagnostic_dest string /oratst02/app/oracle
SQL> col name for a20
SQL> col value for a70
SQL> select * from v$diag_info;
INST_ID NAME VALUE
---------- -------------------- ----------------------------------------------------------------------
1 Diag Enabled TRUE
1 ADR Base /oratst02/app/oracle
1 ADR Home /oratst02/app/oracle/diag/rdbms/teste2/teste2
1 Diag Trace /oratst02/app/oracle/diag/rdbms/teste2/teste2/trace
1 Diag Alert /oratst02/app/oracle/diag/rdbms/teste2/teste2/alert
1 Diag Incident /oratst02/app/oracle/diag/rdbms/teste2/teste2/incident
1 Diag Cdump /oratst02/app/oracle/admin/teste2/cdump
1 Health Monitor /oratst02/app/oracle/diag/rdbms/teste2/teste2/hm
1 Default Trace File /oratst02/app/oracle/diag/rdbms/teste2/teste2/trace/teste2_ora_263.trc
1 Active Problem Count 0
1 Active IncidentCount 0
O nome do arquivo será:
[ ORACLE_SID ]_ora_[ SPID ].trc
SQL> select spid
2 from v$process p, v$session s
3 where p.addr = s.paddr
4 and sid = 2371;
SPID
------------
12603
..
srvtst:oracle:oratst2> ls -lrt *12603*
-rw-r--r-- 1 oracle dba 6032 Aug 8 17:02 oratst2_ora_12603.trc
Uma facilidade presente desde a versão 8.1.7 foi o TRACEFILE_IDENTIFIER que permite atribuir um “NOME” ao arquivo trace. Quando você esta realizando um trace da sua sessão:
SQL> alter session set tracefile_identifier=anderson;
Session altered.
agora:
srvtst:oracle:oratst2> ls -lrt *ANDERSON*
-rw-r--r-- 1 oracle dba 73 Aug 8 17:08 oratst2_ora_4796_ANDERSON.trc
Após identificar o seu arquivo trace você executa o utilitário TKPROF (Transient Kernel Profiler) para gerar e sumarizar todos os dados coletados no arquivo .trc
srvtst:oracle:oratst2> tkprof oratst2_ora_4796_ANDERSON.trc trace.txt
TKPROF: Release 10.2.0.5.0 - Production on Thu Aug 8 17:13:35 2013
Copyright (c) 1982, 2007, Oracle. All rights reserved.
Agora é só visualizar o arquivo analizado (trace.txt)
SELECT COUNT(*)
FROM
TESTE WHERE TIMESTAMP < (SYSDATE - 365)
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.03 0.03 1 30 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 47.08 289.13 1118319 1138160 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 47.11 289.16 1118320 1138190 0 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 20844
Rows Row Source Operation
------- ---------------------------------------------------
1 SORT AGGREGATE (cr=1138160 pr=1118319 pw=0 time=289132678 us)
0 TABLE ACCESS FULL TESTE (cr=1138160 pr=1118319 pw=0 time=289132666 us)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 2 0.00 0.00
db file scattered read 35022 0.63 249.26
latch: object queue header operation 20 0.00 0.00
db file sequential read 1 0.00 0.00
SQL*Net message from client 2 0.00 0.00
********************************************************************************
Identificando um evento de espera a nível de sessão:
SQL> set lines 190
SQL> col EVENT for a40
SQL> col P1TEXT for a10
SQL> col P2TEXT for a10
SQL> col P3TEXT for a10
SQL> col WAIT_CLASS for a20
SQL> select sw.event,
2 sw.state,
3 sw.p1text,
4 sw.p1,
5 sw.p2text,
6 sw.p2,
7 sw.p3text,
8 sw.p3,
9 sw.wait_class
10 from v$session_wait sw
11 where sid = 255
12 /
EVENT STATE P1TEXT P1 P2TEXT P2 P3TEXT P3 WAIT_CLASS
---------------------------------------- ------------------- ---------- ---------- ---------- ---------- ---------- ---------- --------------------
db file scattered read WAITING file# 448 block# 52425 blocks 16 User I/O
Conhecendo o evento(sintoma) de espera da sessão você pode agir sobre o mesmo. Neste exemplo, o evento ‘db file scattered read’ representa que a sessão esta realizando um acesso FULL sobre uma tabela – FTS (FULL TABLE SCAN) ou sobre um índice – FFS (FAST FULL SCAN).
Identificando o comando SQL da sessão 255:
SQL> SELECT A.SQL_TEXT
2 FROM V$SQLTEXT A, V$SESSION B
3 WHERE A.ADDRESS = B.SQL_ADDRESS
4 AND A.HASH_VALUE = B.SQL_HASH_VALUE
5 AND B.SID = 255
6 ORDER BY PIECE;
SQL_TEXT
----------------------------------------------------------------
select * from lancamentos where cd_empresa=5
Plano de execução do SQL. Observe o TABLE ACCESS FULL na coluna Operation. (representa um acesso full sobre uma tabela)
SQL> explain plan for
2 select * from lancamentos where cd_empresa=5;
Explained.
SQL> SELECT * FROM TABLE(dbms_xplan.display);
PLAN_TABLE_OUTPUT
---------------------------------------------------------------------------------
Plan hash value: 2518875852
---------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
---------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 9759K| 1237M| 1108K (2)| 03:41:40 |
|* 1 | TABLE ACCESS FULL| LANCAMENTOS | 9759K| 1237M| 1108K (2)| 03:41:40 |
---------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter("CD_EMPRESA"=5)
13 rows selected.
Agora é só agir sobre o problema! sintoma, evento de espera…
Identificando os TOP wait events do sistema:
Se você já gerou algum report do AWR(Automatic Workload Repository) deve conhecer a imagem abaixo dos “Top 5 Timed Events”.
Este report mostra os wait events que mais afetaram o banco de dados no intervalo de snapshot selecionado, mas não é preciso gerar um AWR para coletá-los, posso pegar as informações utilizando as próprias views do AWR. Exemplo:
Selecionando o horário desejado: ( snap_id = 21138 )
SQL> select a.snap_id,
2 to_char(a.begin_interval_time, 'dd/mm/yyyy hh24:mi:ss') begin_interval_time,
3 to_char(a.end_interval_time, 'dd/mm/yyyy hh24:mi:ss') end_interval_time
4 from dba_hist_snapshot a
5 order by 1 desc;
SNAP_ID BEGIN_INTERVAL_TIME END_INTERVAL_TIME
---------- ------------------- -------------------
21145 23/07/2013 18:00:53 23/07/2013 19:00:05
21144 23/07/2013 17:01:11 23/07/2013 18:00:53
21143 23/07/2013 16:00:27 23/07/2013 17:01:11
21142 23/07/2013 15:00:15 23/07/2013 16:00:27
21141 23/07/2013 14:00:02 23/07/2013 15:00:15
21140 23/07/2013 13:00:50 23/07/2013 14:00:02
21139 23/07/2013 12:00:37 23/07/2013 13:00:50
21138 23/07/2013 11:00:24 23/07/2013 12:00:37
21137 23/07/2013 10:00:11 23/07/2013 11:00:24
21136 23/07/2013 09:00:59 23/07/2013 10:00:11
21135 23/07/2013 08:00:46 23/07/2013 09:00:59
21134 23/07/2013 07:00:33 23/07/2013 08:00:46
21133 23/07/2013 06:01:09 23/07/2013 07:00:33
21132 23/07/2013 05:00:08 23/07/2013 06:01:09
Executando a query para coletar os TOP events:
SQL> select snap_id,
2 begin_time,
3 end_time,
4 (select i.instance_name
5 from gv$instance i
6 where i.INSTANCE_NUMBER = a.instance_number) as "INSTANCE",
7 event_name,
8 total_waits as "WAITS",
9 event_time_waited as "TIME(s)",
10 avg_wait as "AVG_WAIT(ms)",
11 pct as "%PCT",
12 wait_class
13 from (select to_char(s.begin_interval_time, 'DD-MM-YYYY HH24:MI') as BEGIN_TIME,
14 to_char(s.end_interval_time, 'DD-MM-YYYY HH24:MI') as END_TIME,
15 m.*
16 from (select ee.instance_number,
17 ee.snap_id,
18 ee.event_name,
19 round(ee.event_time_waited / 1000000) event_time_waited,
20 ee.total_waits,
21 round((ee.event_time_waited * 100) /
22 et.total_time_waited,
23 1) pct,
24 round((ee.event_time_waited / ee.total_waits) / 1000) avg_wait,
25 ee.wait_class
26 from (select ee1.instance_number,
27 ee1.snap_id,
28 ee1.event_name,
29 ee1.time_waited_micro - ee2.time_waited_micro event_time_waited,
30 ee1.total_waits - ee2.total_waits total_waits,
31 ee1.wait_class
32 from dba_hist_system_event ee1
33 join dba_hist_system_event ee2 on ee1.snap_id =
34 ee2.snap_id + 1
35 and ee1.instance_number =
36 ee2.instance_number
37 and ee1.event_id =
38 ee2.event_id
39 and ee1.wait_class_id <>
40 2723168908
41 and ee1.time_waited_micro -
42 ee2.time_waited_micro > 0
43 union
44 select st1.instance_number,
45 st1.snap_id,
46 st1.stat_name event_name,
47 st1.value - st2.value event_time_waited,
48 null total_waits,
49 null wait_class
50 from dba_hist_sys_time_model st1
51 join dba_hist_sys_time_model st2 on st1.instance_number =
52 st2.instance_number
53 and st1.snap_id =
54 st2.snap_id + 1
55 and st1.stat_id =
56 st2.stat_id
57 and st1.stat_name =
58 'DB CPU'
59 and st1.value -
60 st2.value > 0) ee
61 join (select et1.instance_number,
62 et1.snap_id,
63 et1.value - et2.value total_time_waited,
64 null wait_class
65 from dba_hist_sys_time_model et1
66 join dba_hist_sys_time_model et2 on et1.snap_id =
67 et2.snap_id + 1
68 and et1.instance_number =
69 et2.instance_number
70 and et1.stat_id =
71 et2.stat_id
72 and et1.stat_name =
73 'DB time'
74 and et1.value -
75 et2.value > 0) et on ee.instance_number =
76 et.instance_number
77 and ee.snap_id =
78 et.snap_id) m
79 join dba_hist_snapshot s on m.snap_id = s.snap_id
80 where m.instance_number = 1
81 and m.snap_id = 21138 --SNAP_ID capturado na query acima
82 order by PCT desc) a
83 where rownum <= 5 --Quantidade de linhas retornadas, especifique 10 para ter um TOP 10
84 /
SNAP_ID BEGIN_TIME END_TIME INSTANCE EVENT_NAME WAITS TIME(s) AVG_WAIT(ms) %PCT WAIT_CLASS
---------- ---------------- ---------------- ---------------- ------------------------------ ------------ ------------ ------------ ---------- --------------------
21138 23-07-2013 11:00 23-07-2013 12:00 c0090prd DB CPU 66,705 44.6
21138 23-07-2013 11:00 23-07-2013 12:00 c0090prd log file sync 868,610 15,564 18 10.4 Commit
21138 23-07-2013 11:00 23-07-2013 12:00 c0090prd db file sequential read 7,663,832 15,562 2 10.4 User I/O
21138 23-07-2013 11:00 23-07-2013 12:00 c0090prd SQL*Net message from dblink 813,766 14,805 18 9.9 Network
21138 23-07-2013 11:00 23-07-2013 12:00 c0090prd SQL*Net break/reset to client 174,240 7,015 40 4.7 Application
Referências:
http://docs.oracle.com/cd/B28359_01/server.111/b28320/waitevents.htm
http://it.toolbox.com/blogs/living-happy-oracle/oracle-a-query-to-get-the-wait-events-part-of-the-awr-report-33420
http://vapvarun.com/study/oracle/mcgraw.hill.osborne.oracle.wait.interface.a.practical.guide.to.performance.d
