martes, 2 de diciembre de 2008

Nuevas formas de rastrear el código

Una de las tareas habituales del DBA es hacer seguimiento al código, para ello normalmente se identificaba la sesión deseada y se habilitaba el trace para la misma, pero ahora que prevalecen las aplicaciones web, ¿cómo hacer seguimiento cuando existe un pool de conexiones que es compartido por todos los usuarios? Pues si hemos tomado la precaución de instrumentar nuestro código, tal como les recomendara en un Post previo, la tarea aún es posible y nada complicada, como veremos a continuación.

Primero estableceremos el escenario que nos servirá para demostrar cómo hacer seguimiento, para ellos asumiremos la existencia de un usuario de base de datos llamado "appweb", tendremos 2 sesiones en sql*plus desde las cuales ejecutaremos un par de scripts que contienen el código que nos interesa capturar.

script1.sql
declare
   v_dummy number;
begin
   dbms_session.set_identifier( client_id => 'juan.perez' );
   dbms_application_info.set_module(
      module_name => 'Agregacion',
      action_name => 'Empleados');

   select count(*)
     into v_dummy
     from emp;

   dbms_application_info.set_module(
      module_name => 'Agregacion',
      action_name => 'Departamentos');

   select count(*)
     into v_dummy
     from dept;

   dbms_application_info.set_module(
      module_name => NULL,
      action_name => NULL );
   dbms_session.set_identifier( client_id => NULL );
end;
/

script2.sql
declare
   v_dummy varchar2(20);
begin
   dbms_session.set_identifier( client_id => 'john.doe' );
   dbms_application_info.set_module(
      module_name => 'Primeros',
      action_name => 'Empleados');

   select ename
     into v_dummy
     from emp
    where rownum < 2;

   dbms_application_info.set_module(
      module_name => 'Primeros',
      action_name => 'Departamentos');

   select dname
     into v_dummy
     from dept
    where rownum < 2;

   dbms_application_info.set_module(
      module_name => NULL,
      action_name => NULL );
   dbms_session.set_identifier( client_id => NULL );
end;
/

El uso de dbms_application_info ya nos es conocido, si no es así te recomiendo leer primero este Post en el cual lo detallo; la novedad viene a ser el uso de dbms_session.set_identifier, que sirve para asignar una cadena de hasta 64 caracteres y que es visible en v$session bajo la columna client_identifier.

SYS@orcl > execute dbms_session.set_identifier( 'Juan.Perez' )

PL/SQL procedure successfully completed.

SYS@orcl > select username, client_identifier 
  2  from v$session where client_identifier is not null;

USERNAME CLIENT_IDENTIFIER
-------- -----------------
SYS      Juan.Perez

En una aplicación web, cada vez que un usuario desea interactuar con la base de datos, se solicita una conexión disponible del pool de conexiones y una vez obtenida se ejecuta el código SQL, pues bien, para poder identificar al usuario, es necesario agregar una llamada a dbms_session.client_identifier, tal como pueden ver en el código de script1 y script2.

Si deseamos hacer trace al usuario 'juan.perez', que es un usuario de aplicación, no un usuario de la base de datos, podemos hacer uso del package dbms_monitor. Este package aparece con 10g y ha venido a reemplazar a dbms_system y dbms_support, por lo que si aún los usan les recomiendo dejar de hacerlo.

SYS@orcl > execute dbms_monitor.client_id_trace_enable( 'juan.perez' )

PL/SQL procedure successfully completed.

Ahora simularemos la interacción de una aplicación web, ejecutando los scripts desde dos sesiones establecidas con el usuario appweb, que vendría a ser el usuario del pool de conexiones.

APPWEB(1)@orcl > @script1

PL/SQL procedure successfully completed.

APPWEB(2)@orcl > @script2

PL/SQL procedure successfully completed.

Ya que Oracle ha recibido la instrucción de hacer seguimiento al código que sea ejecutado por 'juan.perez', conforme esto ocurra se iran generando trace files en el directorio señalado en user_dump_dest. Aquí no podemos usar directamente tkprof, debemos ejecutar un paso previo que consiste en llamar a trcsess.

[udump]$ trcsess
oracle.ss.tools.trcsess.SessTrcException: SessTrc-00002: Session Trace Usage error: Wrong parameters passed.
trcsess [output=<output file name>]  [session=<session ID>] [clientid=<clientid>] [service=<service name>] [action=<action name>] [module=<module name>] <trace file names>

output=<output file name> output destination default being standard output.
session=<session Id> session to be traced.
Session id is a combination of session Index & session serial number e.g. 8.13.
clientid=<clientid> clientid to be traced.
service=<service name> service to be traced.
action=<action name> action to be traced.
module=<module name> module to be traced.
<trace_file_names> Space separated list of trace files with wild card '*' supported.

Vemos que trcess nos permite separar de entre muchos trace files las sentencias que vamos filtrando con los parámetros disponibles. Empezaremos por filtrar las sentencias ejecutadas por 'juan.perez'.

[udump]$ ls *trc
orcl_ora_6839.trc  orcl_ora_6901.trc
[udump]$ trcsess output=juan.perez.trc clientid='juan.perez' *trc
[udump]$ tkprof juan.perez.trc juan.perez.txt sys=no

TKPROF: Release 10.2.0.4.0 - Production on Mon Dec 1 08:10:21 2008

Copyright (c) 1982, 2007, Oracle.  All rights reserved.

juan.perez.txt
SELECT COUNT(*)
FROM
 EMP
SELECT COUNT(*)
FROM
 DEPT

El objetivo se ha cumplido, hemos logrado aislar las sentencias que corresponden a 'juan.perez', procedamos ahora a solicitar el seguimiento de las sentencias generadas por el módulo 'Primeros'.

SYS@orcl > execute dbms_monitor.serv_mod_act_trace_enable(-
> service_name => 'orcl.oracle.com',-
> module_name => 'Primeros' );

PL/SQL procedure successfully completed.

Ahora simularemos nuevamente la interacción con la base de datos y obtendremos de los trace files aquellas sentencias que nos interesan por corresponder a dicho módulo.

APPWEB(1)@orcl > @script1

PL/SQL procedure successfully completed.

APPWEB(2)@orcl > @script2

PL/SQL procedure successfully completed.

[udump]$ trcsess output=Primeros.trc module='Primeros' *trc
[udump]$ tkprof Primeros.trc Primeros.txt sys=no

TKPROF: Release 10.2.0.4.0 - Production on Mon Dec 1 08:37:37 2008

Copyright (c) 1982, 2007, Oracle.  All rights reserved.

Primeros.txt
SELECT ENAME
FROM
 EMP WHERE ROWNUM < 2

SELECT DNAME
FROM
 DEPT WHERE ROWNUM < 2

Las cosas marchan como se esperaba, trcess logró separar las sentencias que corresponden al módulo 'Primeros'. De manera similar lo podemos solicitar a nivel de acción, veamos el ejemplo para 'Departamentos'.

[udump]$ trcsess output=Departamentos.trc action='Departamentos' *trc
[udump]$ tkprof Departamentos.trc Departamentos.txt sys=no

TKPROF: Release 10.2.0.4.0 - Production on Mon Dec 1 08:41:19 2008

Copyright (c) 1982, 2007, Oracle.  All rights reserved.

Departamentos.txt
SELECT DNAME
FROM
 DEPT WHERE ROWNUM < 2

SELECT COUNT(*)
FROM
 DEPT

Hasta ahora todo bien y muy simple, veamos ahora un ejemplo final en el que se combinan varios criterios de filtrado.

[udump]$ trcsess output=john.doe.Empleados.trc clientid='john.doe' action='Empleados' *trc

[udump]$ tkprof john.doe.Empleados.trc john.doe.Empleados.txt sys=no

TKPROF: Release 10.2.0.4.0 - Production on Mon Dec 1 08:44:07 2008

Copyright (c) 1982, 2007, Oracle.  All rights reserved.

john.doe.Empleados.txt
SELECT ENAME
FROM
 EMP WHERE ROWNUM < 2

A estas alturas ya habrán notado la enorme ventaja que nos representa haber instrumentado las aplicaciones, así como el poder de dbms_monitor complementado con trcess. Ahora bien, conforme vamos agregando criterios de seguimiento, estos se van registrando en la base de datos y están disponibles con la vista dba_enabled_traces.

SYS@orcl > select trace_type, primary_id, qualifier_id1
  2  from dba_enabled_traces;

TRACE_TYPE       PRIMARY_ID        QUALIFIER_ID1
---------------- ----------------- -------------
CLIENT_ID        juan.perez
SERVICE_MODULE   orcl.oracle.com   Primeros

Recuerden que hacer seguimiento consume recursos, por lo que es conveniente que consulten dba_enabled_traces regularmente para ver que no esté activo algún seguimiento que ya no necesitan y de ser así procedan a desactivarlo.

SYS@orcl > execute dbms_monitor.client_id_trace_disable('juan.perez')

PL/SQL procedure successfully completed.

SYS@orcl > execute dbms_monitor.serv_mod_act_trace_disable(-
> service_name => 'orcl.oracle.com',-
> module_name => 'Primeros' );

PL/SQL procedure successfully completed.

En conclusión, para estos tiempos en que las aplicaciones web con sus pools de conexiones son la regla, la labor de seguimiento del código se puede complicar si no hemos tomado la previsión de instrumentar nuestras aplicaciones, de forma que sea fácil identificar el origen y ejecutante de las sentencias. Cuesta un poco de trabajo, pero deben planteárselo como un estándar a seguir para todo nuevo desarrollo. Aún me sorprende encontrar muchas instalaciones donde esta medida no se ha tomado y hacer segumiento resulta más complicado de lo que debiera.

No olviden tampoco que deben usar dbms_monitor, sencillamente no tiene reemplazo y junto con trcsess y tkprof son nuestros aliados en el seguimiento del código. Pero esto no es todo, en un siguiente Post veremos otros beneficios que podemos obtener si instrumentamos las aplicaciones, estén atentos.

Posts Relacionados:

¿Te pareció interesante este artículo?, ¿te quedaron algunas dudas?, ¿quieres sugerirme un tema a tratar?, pues déjame tus comentarios o envíame un email y para que NO te pierdas ningún Post, suscríbete por email ahora mismo!

Agrega tu comentario