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.