martes, 21 de octubre de 2008

Perfiles de desempeño

Recientemente he estado con clientes ayudando a resolver serios problemas de desempeño. Los ambientes, por diversos que sean, son muy similares, es decir, siempre se cuenta con una base de datos que corresponde a una aplicación, y esta aplicación tiene muchas "mini-aplicaciones" relacionadas.

Los clientes generalmente se dan cuenta de que sufren por problemas de desempeño cuando sus usuarios comienzan a quejarse... Y la pregunta es ¿Qué está causando el problema de desmpeño?

La gente suele enfocarse a ver el sistema como "Una Aplicación" e intenta optimizar todos los reportes que se generan dentro de la misma aplicación, pero la realidad, es que sólo se podría estar atacando un porcentaje muy bajo de los problemas en realidad.

Imaginemos que una aplicación es un "E-Business Suite" de oracle; de entrada tenemos carga generada por las sentencias SQL de reportes, SQLs de las formas, SQLs de sesiones en Framework, SQLs de Discoverer, SQLs de interfaces, etc... La probelmática puede venir de muchos lados a la vez.

Dada esta problemática, la forma más sencilla que he encontrado para hacer el monitoreo/análisis es crear un trigger de sesión que registre la actividad de cada sesión a una tabla de auditoria en la base de datos.

Aquí el script de creación de objetos:

trigger_auditoria.sql

/* se crea la tabla que mantendrá
los datos de auditoria. */
CREATE TABLE "SYS"."AUDITORIA_HECG"
( "ENTRADA" DATE,
"SALIDA" DATE,
"USUARIO_SISTEMA" VARCHAR2(30),
"USUARIO_BASE" VARCHAR2(30),
"EQUIPO" VARCHAR2(64),
"PROGRAMA" VARCHAR2(64),
"MODULO" VARCHAR2(48),
"ACCION" VARCHAR2(32),
"CPU" NUMBER,
"LECTURAS_LOGICAS" NUMBER,
"LECTURAS_FISICAS" NUMBER,
"LECTURAS_FISICAS_BYTES" NUMBER,
"ESCRITURAS_FISICAS" NUMBER,
"ESCRITURAS_FISICAS_BYTES" NUMBER,
"PREV_SQL" NUMBER
)
TABLESPACE "SYSAUX" ;

/* ahora se crea el trigger
que llenará los datos de
las sesiones */

CREATE OR REPLACE TRIGGER "SYS"."AUD_LOGGOF" before logoff ON DATABASE
DECLARE mi_sesion NUMBER;
mi_cpu NUMBER;-- stat 12
mi_pr NUMBER;-- stat 54
mi_prb number;--stat 58
mi_pw NUMBER;-- stat 62
mi_pwb number; --stat 66
mi_lr NUMBER;-- stat 9

BEGIN
FOR estadisticas IN
(SELECT name,
my.statistic#,
VALUE,
sid
FROM v$mystat my,
v$statname st
WHERE my.statistic# IN(9, 12, 54, 58, 62, 66)
AND my.statistic# = st.statistic#
)
LOOP
CASE
WHEN estadisticas.statistic# = 9 THEN
mi_lr := estadisticas.VALUE;
WHEN estadisticas.statistic# = 12 THEN
mi_cpu := estadisticas.VALUE;
WHEN estadisticas.statistic# = 54 THEN
mi_pr := estadisticas.VALUE;
WHEN estadisticas.statistic# = 58 THEN
mi_prb := estadisticas.VALUE;
WHEN estadisticas.statistic# = 62 THEN
mi_pw := estadisticas.VALUE;
WHEN estadisticas.statistic# = 66 THEN
mi_pwb := estadisticas.VALUE;
END CASE;
mi_sesion := estadisticas.sid;
END LOOP;
INSERT INTO AUDITORIA_HECG
SELECT logon_time,
sysdate,
osuser,
username,
machine,
program,
MODULE,
ACTION,
mi_cpu,
mi_lr,
mi_pr,
mi_prb,
mi_pw,
mi_pwb,
prev_hash_value
FROM v$session
WHERE sid = mi_sesion;
END;


Los campos que tiene la tabla de auditoría son los siguientes:

ENTRADA Se registra el logontime de la sesión a la base de datos.
SALIDA Es la hora en que la sesión se desconecta de la base de datos.
USUARIO_SISTEMA Usuario a nivel sistema operativo.
USUARIO_BASE Usuario que se utilizó para conectarse a la base de datos.
EQUIPO Máquina desde la cuál se realizó la conexión a oracle
PROGRAMA Programa utilizado para realizar la conexión (SQL Plus, TOAD, etc.).
MODULO Información adicional sobre la conexión.
ACCION Acción que se realiza dentro del módulo.
CPU Tiempo en centésimas de segundo de uso de CPU para la sesión.
LECTURAS_LOGICAS Cantidad de bloques lógicos leídos.
LECTURAS_FISICAS Cantidad de bloqes leídos físicos.
LECTURAS_FISICAS_BYTES Cantidad en bytes de lecturas físicas (en caso de que se tengan múltiples pools)
ESCRITURAS_FISICAS Bloques escritos hacia la base de datos.
ESCRITURAS_FISICAS_BYTES Cantidad en bytes de bloques escritos.
PREV_SQL Última sentencia SQL ejecutadapor la sesión.


Una vez creado el trigger, la información empezará a caer en la tabla a medida que las sesiones van terminando.

Los campos como módulo, acción, prev_sql, están en la tabla ya que me han ayudado a identificar sesiones y crear perfiles asociados con programas o código en específico.

Un pequeño ejemplo de la información:


1 SELECT COUNT(1) Sesiones,
2 programa,
3 SUM(cpu) / 100 "CPU Segs.",
4 SUM(lecturas_logicas) "Lecturas Logicas",
5 SUM(lecturas_fisicas) "Lecturas Físicas"
6 FROM auditoria_rit
7 group by programa
8* order by 5 desc

SESIONES PROGRAMA CPU Segs. Lecturas Logicas Lecturas Físicas
---------- ------------------ ---------- ---------------- ----------------
5259 Monitor.exe 805.03 10181777 161536
42216 SQL*Plus 1689.14 18391422 107703
11 rman.exe 30.57 538894 16157
4 ORACLE.EXE (J001) 34.66 553426 12075
12 oradim.exe 16.35 139138 10178
46 sqlplus.exe 74.2 2465261 6406
26 ORACLE.EXE (J002) 32.91 476683 5634
6 ORACLE.EXE (J003) 12.32 236175 4760
6 SQL Developer 185.47 2059364 3986
32 T.O.A.D. 11.54 30644 2522
1 JDBC Thin Client 1.25 30364 47

11 filas seleccionadas.


Los límites para explotar la información son infinitos, se pueden agrupar por cierta fecha de inicio, por horarios durante el día, por usuarios, una vez que se sabe si el problema es CPU o I/O físico, puedes ir hacia los programas o módulos que más afectan a la base de datos.

Si llegaran a tener muchos valores en Nulo, es decir, un valor de usuario genérico, un application server como equipo, módulo y acción en nulo, prev_sql como "SELECT 1 FROM DUAL", creo que sería hora de pensar un poco en instrumentar el código de nuestra aplicación, por lo menos para añadir un módulo y/o acción con el paquete

DBMS_APPLICATION_INFO



SQL> exec dbms_application_info.set_module('CARGA','Auditoria');

Procedimiento PL/SQL terminado correctamente.

SQL> exit

c:\> sqlplus "/ as sysdba"

SQL> SELECT entrada,
2 usuario_sistema,
3 usuario_base,
4 programa,
5 modulo,
6 accion
7 FROM auditoria_hecg;

ENTRADA USUARIO_SISTEMA USUARIO_BA PROGRAMA MODUL ACCION
--------- --------------- ---------- ----------- ----- ----------
21-OCT-08 HUGO-WIN\Hugo SYS sqlplus.exe CARGA Auditoria



De esta forma nos será más sencillo encontrar qué es lo que cada sesión realizó en el sistema.

Muchas veces no se mide el impacto que pudiera causar el monitoreo dentro de un sistema, o queries que se ejecutan relativamente rápido, pero que por la cantidad de veces que se ejecutan en el sistema, representan el 30% de las lecturas físicas en el sistema.

Este trigger no es muy intrusivo, no genera carga fuerte en el sistema, y la información que arroja es muy valiosa.

Hay que decir que para versión 9i, se deben de realizar cambios, agradezco a Issachar Zamora, los cambios que relizó en el trigger para que funcionará bien en 9i (las estadísticas de 9i no incluyen escrituras ni lecturas en bytes, además de que el stat_id cambia para algunas otras).

Una vez que tenga el trigger para 9i lo anexaré a este post.

Adicionalmente suelo poner un índice por (entrada, modulo), ya que los queries que suelo ejecutar van filtrados por fecha o por módulo en específico en un rango de fechas.

Si alguien tiene una idea de cómo mejorar, o qué parámetros cree conveniente añadir en el trigger, no duden en comentarlo.

3 comentarios:

rachisa dijo...

Que tal tocayo,

regularmente en aplicaciones cerradas como un ebusiness suite, se hace dificil la medicion de desempenio por lo cerrado del ambiente, en tu experiencia, cuales serian los pasos a seguir muy a groso modo para poder aislar y detectar el problema, quiza es una pregunta bastante compleja, pero que sugeririas revisar de inicio para poder hacer un diagnostico adecuado y atacar el problema significativamente.

Saludos

Rogert dijo...

estoy revisando esta entrada y espero en no mas de 15 días ponerla a prueba.

Saludos, en general el blog me parece excelente, yo no soy DBA, pero de cuando en cuando es necesario saber detalles de lo que mis aplicaciones estan causando.

orlandoolguin dijo...

Hola Hugo, muy interesante post, creéme que lo tomaré en cuenta, eso me inspira a publicar uno pronto de los eventos del sistema, muy similar a lo que pones en este blog aunque en otro enfoque.

Por otro lado una sugerencia que no desemboca en una diferencia sustancial de desempeño, pero si en un código elegante. En tu CASE dentro del trigger puedes usar un sólo IF con un IN como lo demuestro en el siguiente código:

SQL> create or replace procedure valida (pn_valor in number) is
2 begin
3 if pn_valor in (9, 12, 54, 58, 62, 66) then
4 dbms_output.put_line ('entra con ' || to_char (pn_valor));
5 end if;
6 end;
7 /

Procedure created.

SQL> set serveroutput on
SQL> exec valida (9);
entra con 9

PL/SQL procedure successfully completed.

SQL> exec valida (5);

PL/SQL procedure successfully completed.

SQL> exec valida (58);
entra con 58

PL/SQL procedure successfully completed.

SQL>

Muy bien, creo que es todo de momento, cambio y fuera. Saludos y un abrazo.