Oracle Internals: Outros Eventos

O Oracle Database não é um produto aberto, mas tem várias janelas para observarmos seu funcionamento.

Eventos são formas de se alterar o comportamento padrão do Oracle. E um bom motivo para se alterar o comporamento padrão dele é para estudar suas características internas.

O Oracle Database não tem apenas os conhecidos eventos 10046 (Extended SQL Trace) e 10053 (Optimizer Stats). Ele tem muitos outros, e praticamente todos devem ser utilizados apenas via instrução explícita do suporte do produto (ou seja, não faça isso em Produção, e blábláblá).

E como saber quais são os outros eventos (sem trabalhar no suporte da Oracle)?

O arquivo oraus.msg, localizado em $ORACLE_HOME/rdbms/mesg, não contém apenas as mensagens de erros do produto, contém também os Eventos.

Veja como são exibidos os Eventos 10046 e 10053.

10046, 00000, "enable SQL statement timing"
// *Cause:
// *Action:
10053, 00000, "CBO Enable optimizer trace"
// *Cause:
// *Action:

Veja outros interessantes que encontrei.

10246, 00000, "print trace of PMON actions to trace file"
// *Cause:
// *Action:
10394, 00000, "generate a fake load to test adaptive and load balancing"
// *Cause:
// *Action:  set this event only under the supervision of Oracle development
// *Comment: generates a fake load for testing purposes
10668, 00000, "Inject Evil Identifiers"
// *Cause:  event 10668 is set to some number > 0, causing 1/(value-1) of all
//          identifiers to be replaced by a maximum amount of x's.  It is
//          common for an identifier to be parsed once with a max of 30 bytes,
//          then reparsed later with a max of 4000, so it may not be possible
//          to inject such an identifier without the aid of this event.  A
//          value of 1 causes no identifiers to be corrupted.
// *Action: never set this event
10665, 00000, "Inject Evil Literals"
// *Cause:  Event 10665 is set to some number > 0, causing 1/(value-1) of all
//          literals to be replaced by 2000 letter 'A's.  A value of 1 does
//          not corrupt anything.
// *Action: never set this event

Escolhi este Evento abaixo para testar primeiro.

10287, 00000, "Simulate archiver error"
// *Cause:
// *Action: If set, next archive log will generate error

Para ativa-lo, como com outros Eventos, é utilizado o programa oradebug.
E não sei se este Evento tem diversos níveis, então tentei primeiro o nível 1, e gerei alguns Archives.

SQL> oradebug SETMYPID
Statement processed.
SQL> oradebug UNLIMIT
SQL> oradebug EVENT 10287 TRACE NAME CONTEXT FOREVER, LEVEL 1;
Statement processed.
SQL> ALTER SYSTEM SWITCH LOGFILE;

System altered.

SQL> /

System altered.

SQL> /

System altered.

SQL>

E realmente o diretório de DUMP passou a gerar um Trace para cada Archive gerado.

[oracle@Oracle11gR2 ~]$ ls -lhtr /u01/app/oracle/diag/rdbms/orcl/ORCL/trace/*arc*
-rw-r-----. 1 oracle oinstall   71 Jan  7 11:30 /u01/app/oracle/diag/rdbms/orcl/ORCL/trace/ORCL_arc0_6000.trm
-rw-r-----. 1 oracle oinstall 1.1K Jan  7 11:30 /u01/app/oracle/diag/rdbms/orcl/ORCL/trace/ORCL_arc0_6000.trc
-rw-r-----. 1 oracle oinstall   71 Jan  7 11:30 /u01/app/oracle/diag/rdbms/orcl/ORCL/trace/ORCL_arc1_6002.trm
-rw-r-----. 1 oracle oinstall 1.1K Jan  7 11:30 /u01/app/oracle/diag/rdbms/orcl/ORCL/trace/ORCL_arc1_6002.trc
-rw-r-----. 1 oracle oinstall   71 Jan  7 11:32 /u01/app/oracle/diag/rdbms/orcl/ORCL/trace/ORCL_arc3_6006.trm
-rw-r-----. 1 oracle oinstall 1.1K Jan  7 11:32 /u01/app/oracle/diag/rdbms/orcl/ORCL/trace/ORCL_arc3_6006.trc
[oracle@Oracle11gR2 ~]$

E cada um destes Taces tinha a mesma mensagem de erro.

Initial buffer sizes: read 1024K, overflow 832K, change 805K
Log read is SYNCHRONOUS though disk_asynch_io is enabled!

*** 2014-01-07 11:32:47.160
Log read is SYNCHRONOUS though disk_asynch_io is enabled!

Ou seja, este Evento deve ser utilizado pelo suporte da Oracle apenas para verificar se os processos ARC conseguem gerar uma mensagem de erro.

Este é um Evento bem chato. Vamos pocurar um mais legal.

Veja este evento abaixo, que inclui a descrição de seus níveis.

10319, 00000, "Trace PGA statistics maintenance"
// *Cause:
// *Action:  set this event only under the supervision of Oracle development
//
//  LEVEL        ACTION
//---------------------------------------------------------------------------
//  0x0001       dump message in trace file when PGA stats are diverging
//  0x0002       trace top-level PGA allocation and deallocation
//  0x0004       always check if full/incremental stats are in sync
//

Vamos ativa-lo no nível 2, e fazer algo que utilize a PGA.

SQL> oradebug SETMYPID
Statement processed.
SQL> oradebug EVENT 10319 TRACE NAME CONTEXT FOREVER, LEVEL 2;
Statement processed.
SQL> oradebug TRACEFILE_NAME
/u01/app/oracle/diag/rdbms/orcl/ORCL/trace/ORCL_ora_10622.trc
SQL> create table t as select * from all_objects;

Table created.

SQL>

Desta forma, dentro do arquivo Trace criado, vemos a alocação dinâmica da PGA, com o tamanho de memória utilizada, liberada, assim como a função que fez isso.

*** 2014-01-07 12:01:06.702
PGA ALLOC used=823K alloc=953K sz=0001112 typ=FRE name='callheap'
PGA ALLOC used=828K alloc=953K sz=0004224 typ=FRE name='callheap'
PGA ALLOC used=832K alloc=953K sz=0004224 typ=FRE name='callheap'
PGA ALLOC used=836K alloc=953K sz=0004224 typ=FRE name='callheap'
PGA ALLOC used=840K alloc=953K sz=0004224 typ=FRE name='callheap'
PGA ALLOC used=844K alloc=953K sz=0004224 typ=FRE name='callheap'
PGA ALLOC used=848K alloc=953K sz=0004224 typ=FRE name='callheap'
PGA ALLOC used=852K alloc=953K sz=0004224 typ=FRE name='callheap'
PGA ALLOC used=856K alloc=953K sz=0004224 typ=FRE name='callheap'
PGA ALLOC used=861K alloc=953K sz=0004224 typ=FRE name='callheap'
PGA ALLOC used=862K alloc=953K sz=0001112 typ=FRE name='callheap'
PGA ALLOC used=863K alloc=953K sz=0001112 typ=FRE name='callheap'
PGA ALLOC used=864K alloc=953K sz=0001112 typ=FRE name='callheap'
PGA ALLOC used=865K alloc=953K sz=0001192 typ=FRE name='callheap'
PGA ALLOC used=866K alloc=953K sz=0001152 typ=FRE name='callheap'
PGA ALLOC used=867K alloc=953K sz=0001192 typ=FRE name='callheap'
PGA ALLOC used=869K alloc=953K sz=0002216 typ=FRE name='callheap'
PGA ALLOC used=871K alloc=953K sz=0001112 typ=FRE name='callheap'
PGA ALLOC used=935K alloc=1017K sz=0065512 typ=FRE name='session heap'
PGA FREE  used=871K alloc=1017K sz=0065512 typ=FRE name='session heap'
PGA ALLOC used=935K alloc=1017K sz=0065512 typ=FRE name='session heap'
PGA FREE  used=930K alloc=1017K sz=0004224 typ=FRE name='callheap'
PGA FREE  used=926K alloc=1017K sz=0004224 typ=FRE name='callheap'
PGA FREE  used=922K alloc=1017K sz=0004224 typ=FRE name='callheap'
PGA FREE  used=918K alloc=1017K sz=0004224 typ=FRE name='callheap'
PGA FREE  used=914K alloc=1017K sz=0004224 typ=FRE name='callheap'
PGA FREE  used=910K alloc=1017K sz=0004224 typ=FRE name='callheap'
PGA FREE  used=906K alloc=1017K sz=0004224 typ=FRE name='callheap'
PGA FREE  used=902K alloc=1017K sz=0004224 typ=FRE name='callheap'
PGA FREE  used=897K alloc=1017K sz=0004224 typ=FRE name='callheap'
...
PGA ALLOC used=1069K alloc=1657K sz=0004224 typ=FRE name='callheap'
PGA ALLOC used=1069K alloc=1657K sz=0000328 typ=FRE name='kxs-heap-c'
PGA ALLOC used=1085K alloc=1657K sz=0016408 typ=RCR name='kxs-heap-c'
PGA ALLOC used=1086K alloc=1657K sz=0001032 typ=RCR name='callheap'
PGA ALLOC used=1090K alloc=1657K sz=0004224 typ=FRE name='callheap'
PGA ALLOC used=1095K alloc=1657K sz=0004224 typ=FRE name='callheap'
PGA ALLOC used=1099K alloc=1657K sz=0004224 typ=FRE name='callheap'
PGA ALLOC used=1103K alloc=1657K sz=0004224 typ=FRE name='callheap'
PGA ALLOC used=1107K alloc=1657K sz=0004232 typ=FRE name='callheap'
PGA ALLOC used=1111K alloc=1657K sz=0004224 typ=FRE name='callheap'
PGA ALLOC used=1115K alloc=1657K sz=0004224 typ=FRE name='callheap'
PGA ALLOC used=1119K alloc=1657K sz=0004224 typ=FRE name='callheap'
PGA ALLOC used=1123K alloc=1657K sz=0004224 typ=FRE name='callheap'
PGA ALLOC used=1128K alloc=1657K sz=0004224 typ=FRE name='callheap'
PGA ALLOC used=1132K alloc=1657K sz=0004392 typ=PRM name='kprball hst'
PGA ALLOC used=1132K alloc=1657K sz=0000208 typ=FRE name='rec call heap'
PGA FREE  used=1132K alloc=1657K sz=0000208 typ=FRE name='rec call heap ds'
PGA ALLOC used=1132K alloc=1657K sz=0000208 typ=FRE name='rec call heap'
PGA FREE  used=1132K alloc=1657K sz=0000208 typ=FRE name='rec call heap ds'
PGA ALLOC used=1132K alloc=1657K sz=0000208 typ=FRE name='rec call heap'
PGA FREE  used=1132K alloc=1657K sz=0000208 typ=FRE name='rec call heap ds'
PGA ALLOC used=1132K alloc=1657K sz=0000208 typ=FRE name='rec call heap'
PGA FREE  used=1132K alloc=1657K sz=0000208 typ=FRE name='rec call heap ds'
PGA ALLOC used=1132K alloc=1657K sz=0000208 typ=FRE name='rec call heap'
PGA ALLOC used=1132K alloc=1657K sz=0000328 typ=FRE name='kxs-heap-c'
PGA ALLOC used=1148K alloc=1657K sz=0016408 typ=RCR name='kxs-heap-c'
...
PGA FREE  used=7065K alloc=14248K sz=0020440 typ=FRE name='callheap'
PGA FREE  used=7064K alloc=14248K sz=0001112 typ=FRE name='callheap'
PGA FREE  used=7062K alloc=14248K sz=0002216 typ=FRE name='callheap'
PGA FREE  used=7061K alloc=14248K sz=0001192 typ=FRE name='callheap'
PGA FREE  used=7060K alloc=14248K sz=0001152 typ=FRE name='callheap'
PGA FREE  used=7059K alloc=14248K sz=0001192 typ=FRE name='callheap'
PGA FREE  used=7058K alloc=14248K sz=0001112 typ=FRE name='callheap'
PGA FREE  used=7056K alloc=14248K sz=0001112 typ=FRE name='callheap'
PGA FREE  used=7055K alloc=14248K sz=0001112 typ=FRE name='callheap'
PGA FREE  used=7054K alloc=14248K sz=0001112 typ=FRE name='callheap'
PGA FREE  used=6998K alloc=14248K sz=0058032 typ=FRE name='session heap'
PGA FREE  used=6877K alloc=14248K sz=0123536 typ=FRE name='session heap'
PGA FREE  used=6779K alloc=14248K sz=0100504 typ=FRE name='session heap'
PGA FREE  used=6715K alloc=14248K sz=0065504 typ=FRE name='session heap'
PGA FREE  used=6651K alloc=14248K sz=0065512 typ=FRE name='session heap'
PGA FREE  used=6587K alloc=14248K sz=0065512 typ=FRE name='session heap'
PGA FREE  used=6579K alloc=14248K sz=0008256 typ=FRE name='PLS PGA hp'
PGA FREE  used=5551K alloc=14248K sz=1052736 typ=FRE name='KSFQ heap'
PGA FREE  used=4523K alloc=14248K sz=1052736 typ=FRE name='KSFQ heap'
PGA FREE  used=3495K alloc=14248K sz=1052736 typ=FRE name='KSFQ heap'
PGA FREE  used=2467K alloc=14248K sz=1052736 typ=FRE name='KSFQ heap'
PGA FREE  used=2461K alloc=14248K sz=0006088 typ=FRE name='KSFQ heap'

Agora sim tivemos uma informação útil, acompanhando passo a passo o quanto uma simples (mas não tão pequena) operação utilizou de memória, além da utilizada pela SGA, e como a sessão rapidamente liberou grande parte da memória utilizada, mas não toda.

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.