miércoles, 8 de junio de 2011

Como hacer un trace con oradebug de otra sesion

Algo muy comun que tenemos que hacer es buscar informacion de otras sesiones, ya que normalmente no son nuestras sesiones las que causan algun problema en nuestra base de datos, si no las sesiones de la aplicacion y para poder determinar que estan haciendo, una muy buena herramienta es hacer un trace de ellas. Vamos a decir que detectamos una sesion que esta haciendo mucho I/O

DBATEST>SELECT s.sid, s.serial#, s.username, s.program,s.client_info,i.block_changes
2 FROM v$session s, v$sess_io i
3 WHERE s.sid = i.sid and username not in ('SYS','SYSTEM')
4 ORDER BY 5 desc, 1, 2, 3, 4;


SID SERIAL# USERNAME PROGRAM CLIENT_INFO BLOCK_CHANGES
---------- ---------- -------------------- -------------------- ------------------------------ -------------
139 2933 HR DBATESTplus@localhost APP DE PRUEBA 1112706
(TNS V1-V3)

Lo primero que tenemos que hacer en SQLPlus es obtener la informacion de la sesion que a la que le vamos a hacer un trace

DBATEST> SELECT '''' || s.sid || ',' || s.serial# || '''' "SID,Serial"
2 ,p.pid "Oracle Process Id (PID)"
3 ,p.spid "OS Oracle Process Id (SPID)"
4 ,s.osuser "OS Client User" --
5 ,s.process "OS Client Process Id(Unix PID)"--
6 ,s.client_info "Client Info"
7 ,command
8 FROM V$SESSION S,
9 V$PROCESS P
10 WHERE (s.paddr = p.addr(+))
11 and (s.USERNAME is not null)
12 and (NVL(s.osuser,'x')<>'SYSTEM')
13 and (s.type<>'BACKGROUND')
14 and (s.sid in ('&SID'))
15 ORDER BY s.process;
Enter value for sid: 139
old 14: and (s.sid in ('&SID'))
new 14: and (s.sid in ('139'))

SID,Serial Oracle Process Id (PID) OS Oracle Process Id OS Client User OS Client Process Id Client Info COMMAND
-------------------- ----------------------- -------------------- -------------------- -------------------- ------------------------------ -------
'139,2933' 69 25963 oracle 25961 APP DE PRUEBA 2

Una vez que localizamos el PID de la sesion , vamos a utilizar la opcion de setorapid de la utileria oradebug para empezar a hacer el trace

DBATEST> oradebug setorapid 69
Oracle pid: 69, Unix process pid: 25963, image: oracle@cihcisddb102 (TNS V1-V3)

Ahora vamos a hacer le trace, con un nivel 12, este nivel te muestra las estadisticas de los eventos de espera y las variables bind


DBATEST> oradebug event 10046 trace name context forever, level 12
Statement processed.

Con este comando puedes ver el nombre del archivo trace que se esta generando

DBATEST> oradebug tracefile_name
/mount/dump01/oracle/DBATEST/diag/rdbms/dbatest/DBATEST/trace/DBATEST_ora_25963.trc

Cuando queramos que termine de hacer el trace, con el siguiente comando lo apagamos


DBATEST> oradebug event 10046 trace name context off
Statement processed.

DBATEST> exit
Disconnected from Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 - 64bit Production
With the OLAP, Data Mining and Real Application Testing options

Por ultimo, usamos la utileria de tkprof para darle formato al archivo trace y ahora si buscar que esta haciendo la sesion y poder atacar el problema, en este caso la espera estaba en la escritura de los redo log files


oracle@localhost [DBATEST] /mount/oracle
oracle $tkprof /mount/dump01/oracle/DBATEST/diag/rdbms/dbatest/DBATEST/trace/DBATEST_ora_25963.trc prueba.txt sys=no

oracle@localhost [DBATEST] /mount/oracle
oracle $ more prueba.txt

TKPROF: Release 11.2.0.2.0 - Development on Thu Jun 9 01:23:50 2011

Copyright (c) 1982, 2009, Oracle and/or its affiliates. All rights reserved.

Trace file: /mount/dump01/oracle/DBATEST/diag/rdbms/dbatest/DBATEST/trace/DBATEST_ora_25963.trc
.
.
.
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
log file switch completion 10 0.10 1.00
log file switch (checkpoint incomplete) 20 3.06 13.13
db file scattered read 2 0.01 0.01
reliable message 28 0.00 0.00
rdbms ipc reply 28 0.00 0.00

Conclusion 
Espero que este manera de hacer un trace te ayude a encontrar esas sesiones que a veces nos causan dolor de cabeza.