sábado, 22 de noviembre de 2008

Hazte la vida más fácil, instrumenta tus aplicaciones

La instrumentación se refiere a la capacidad de supervisar y medir el rendimiento de una aplicación. Si nuestra aplicaciones están instrumentadas, en cualquier momento podremos saber qué rutina es la que consume más recursos, en qué porcentaje de avance está aquel proceso batch que parece no terminar, podríamos hacer trace a un módulo, independientemente del usuario que lo esté ejecutando, etc. Luego de varios años de venir realizando consultorías, he encontrado que muy pocos implementan una instrumentación de sus aplicaciones, quizás sea porque no saben que esto es posible, por ello a continuación les mostraré cómo hacerlo y los beneficios inmediatos que pueden lograrse con muy poco esfuerzo.

La pieza central para lograr la instrumentación de las aplicaciones viene a ser el package dbms_application_info. Empezaremos por conocer los valores que podemos establecer y los métodos principales que usaremos en nuestro proceso de instrumentación.

module_name
Es el nombre del módulo que está actualmente en ejecución. Se trata de una cadena de hasta 48 bytes, si es más larga se trunca silenciosamente.

action_name
Es el nombre de la acción vigente para el módulo vigente. Se trata de unan cadena de hastas 32 bytes, si es más larga se trunca silenciosamente.

set_module
Es el procedimiento que permite establecer el nombre del módulo o aplicación actual.
dbms_application_info.set_module(
   module_name=> 'Facturacion',
   action_name=> 'Obtencion.Numero.Factura' );

set_action
Es el precedimiento que permite establecer el nombre de la acción actual dentro del módulo actual.
dbms_application_info.set_action(
   action_name=> 'Calculo.Impuestos' );

set_session_longops
Es el precedimiento que permite registrar una fila en v$session_longops, como un medio para hacer seguimiento al progreso de las operaciones.
dbms_application_info.set_session_longops(
   rindex => v_rindex, --identificador de la fila en v$session_longops
   slno => v_slno, --para uso interno, no modificar
   op_name => 'Recalculo', --nombre que le asignamos a la tarea
   target_desc => 'Cheque', --descripción del objeto manipulado
   sofar => v_sofar, --indicador de cuanto trabajo ya se ha hecho
   totalwork => v_totalwork, --indicador del total de trabajo por hacer
   context => v_nro_cheque, --cualquier numero que se desee almacenar
   units => 'Cheques'); --unidad en que se representa sofar y totalwork

Veamos ahora un ejemplo en el que se combinan estos tres métodos y luego comentaremos lo que allí se hace.

DECLARE
   v_rindex    PLS_INTEGER;
   v_slno      PLS_INTEGER;
   v_totalwork NUMBER;
   v_sofar     NUMBER;
   v_obj       PLS_INTEGER;
   v_dname     dept.dname%TYPE;
BEGIN
   dbms_application_info.set_module (
      module_name => 'Listado.Empleados',
      action_name=> 'Total.Empleados' );

   v_rindex := dbms_application_info.set_session_longops_nohint;
   v_sofar := 0;

   SELECT count(*)
     INTO v_totalwork
     FROM emp;

   dbms_application_info.set_action (
      action_name=> 'Bucle.Empleados' );

   FOR c_emp IN (
      SELECT empno, ename, deptno
        FROM emp )
   LOOP
      SELECT dname INTO v_dname
        FROM dept
       WHERE deptno = c_emp.deptno;
      dbms_output.put_line(
          c_emp.empno||':'||c_emp.ename||':'||v_dname);

      v_sofar := v_sofar + 1;
      dbms_application_info.set_session_longops(
         rindex => v_rindex,
         slno => v_slno,
         op_name => 'Procesando Empleados',
         target_desc => 'Empleado',
         sofar => v_sofar,
         totalwork => v_totalwork,
         context => c_emp.empno,
         units => 'Empleados');

      dbms_lock.sleep( 2 ); --artificio para hacer lento el bucle
   END LOOP;

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

En esta rutina se empieza por calcular el total de filas a procesar y por cada iteración vamos actualizando la fila creada en v$session_longops, de forma que podemos saber cuánto se ha avanzado y tener una estimación del tiempo restante de proceso.

SYS@orcl > SELECT message, ROUND(sofar/totalwork,2)*100 "%Avance",
  2  time_remaining falta, context empno
  3   from v$session_longops
  4  where time_remaining > 0;
MESSAGE
-----------------------------------------------------------
   %Avance      FALTA    CONTEXT
---------- ---------- ----------
Procesando Empleados: Empleado : 1 out of 14 Empleados done
         7         30       7369

SYS@orcl > /
MESSAGE
-----------------------------------------------------------
   %Avance      FALTA    CONTEXT
---------- ---------- ----------
Procesando Empleados: Empleado : 3 out of 14 Empleados done
        21         11       7521

SYS@orcl > /
MESSAGE
-----------------------------------------------------------
   %Avance      FALTA    CONTEXT
---------- ---------- ----------
Procesando Empleados: Empleado : 13 out of 14 Empleados done
        93          2       7902

SYS@orcl > /

no rows selected

También hemos identificando la rutina en sí (set_module) y las diferentes secciones al interior del mismo (set_action), esta información es visible desde algunas vistas del catálogo, como es el caso de v$sql.

SYS@orcl > SELECT action, executions, sql_text
  2  FROM v$sql
  3* WHERE module = 'Listado.Empleados';
ACTION               EXECUTIONS SQL_TEXT
-------------------- ---------- -----------------------------------------
Bucle.Empleados               1 SELECT EMPNO, ENAME, DEPTNO FROM EMP
Total.Empleados               1 SELECT COUNT(*) FROM EMP
Nombre.Departamento          14 SELECT DNAME FROM DEPT WHERE DEPTNO = :B1

Ahora la labor de hallar el origen de una sentencia SQL se simplifica pues podemos identificar rápidamente el módulo y la acción de la cual proviene, de otra forma tendriamos que enviar la sentencia SQL al equipo de desarrollo para que ellos a su vez identifiquen la aplicación de la cual proviene, labor cuyo grado de dificultad depende del nivel de control que se tenga sobre el código fuente.

Si todas nuestras aplicaciones están debidamente instrumentadas, en todo momento podemos saber cómo los diversos módulos y acciones consumen los recursos, para ellos nos valemos adicionalmente de v$active_session_history.

SYS@orcl > SELECT b.name service, NVL(module,'Sin Nombre') module,
  2  ROUND(100*(COUNT(*)/sum(COUNT(*)) OVER()), 1) pct
  3  FROM v$active_session_history a, v$services b
  4  WHERE a.service_hash = b.name_hash
  5  AND session_type <> 'BACKGROUND'
  6  AND sample_time > systimestamp - 1/288 --ultimos 5 minutos
  7  GROUP BY b.name, module
  8* ORDER BY pct desc;
SERVICE          MODULE               PCT
---------------- ------------------ ------
SYS$USERS        Facturacion           53
SYS$USERS        Almacenes           44.1
orcl.oracle.com  OEM.DefaultPool      1.9
orcl.oracle.com  OEM.Loader            .6
orcl.oracle.com  Sin Nombre            .4

Observamos el detalle a nivel de module pero también es posible obtenerlo a nivel de action.
SYS@orcl > SELECT b.name service, NVL(module,'Sin Nombre') module,
  2  NVL(action,'Sin Nombre') action,
  3  ROUND(100*(COUNT(*)/sum(COUNT(*)) OVER()), 1) pct
  4  FROM v$active_session_history a, v$services b
  5  WHERE a.service_hash = b.name_hash
  6  AND session_type <> 'BACKGROUND'
  7  AND sample_time > systimestamp - 1/288
  8  GROUP BY b.name, module, action
  9* ORDER BY pct desc;
SERVICE          MODULE           ACTION                       PCT
---------------- ---------------- -------------------------- -----
SYS$USERS        Facturacion      Calculo.Impuestos             53
SYS$USERS        Almacenes        Consulta.Inventario         44.1
orcl.oracle.com  OEM.DefaultPool  /database/instance/sitemap   1.2
orcl.oracle.com  OEM.DefaultPool  /logon                        .7
orcl.oracle.com  OEM.Loader       XMLLoader0                    .6
orcl.oracle.com  Sin Nombre       Sin Nombre                    .4

Esta información también la podemos encontrar en Enterprise Manager, pero esta vez mostrada en forma gráfica (Performance > Top Consumers).


Hasta aquí llegaremos por el momento, pero ya hemos hecho un gran avance. Usando dbms_application_info se simplifica la identificación de la aplicación a la cual pertenecen las sentencias SQL, también se posibilita saber el avance de los procesos de larga duración, de una forma muy precisa. Pero ésta no es toda la utilidad, en un próximo Post veremos beneficios adicionales de la instrumentación de 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!

1 comentario, agrega el tuyo!

Fernando Garcia dijo...

Excelente articulo. Claro, instructivo y util.