Registrando errores en una tabla de LOG

Como los stored procedures y los triggers se ejecutan en el Servidor desde el Cliente no se puede monitorear lo que está ocurriendo dentro de ellos. Pero saber lo que ocurre dentro de ellos es muy importante cuando estamos buscando errores o problemas.

Entonces, una alternativa es crear una tabla de LOG, o sea, una tabla donde registraremos todo lo que nos interese saber mientras se está ejecutando un stored procedure o trigger.

La tabla de LOG puede tener una estructura similar a la siguiente:

Captura 1. Si haces clic en la imagen la verás más grande

En esta tabla solamente usaremos el comando INSERT porque lo que nos interesa es saber lo que ocurre dentro de los stored procedures y los triggers entonces no tiene sentido usar UPDATE alguna vez.

A la tabla LOG le agregaremos dos triggers: uno para incrementar el valor del identificador y el otro para insertar dentro de la tabla los valores constantes.

CREATE TRIGGER BI_LOG_LOG_IDENTI FOR LOG
   ACTIVE BEFORE INSERT
   POSITION 0
AS
BEGIN
   IF (NEW.LOG_IDENTI IS NULL OR NEW.LOG_IDENTI = 0) THEN
      NEW.LOG_IDENTI = GEN_ID(LOG_LOG_IDENTI_GEN, 1);
END

Como puedes ver, el trigger superior incrementa el valor del identificador en uno.

CREATE TRIGGER LOG_BI FOR LOG
   ACTIVE BEFORE INSERT
   POSITION 1
AS
BEGIN

   NEW.LOG_USUARI = CURRENT_USER;
   NEW.LOG_FECHOR = CURRENT_TIMESTAMP;
   NEW.LOG_COMPUT = (SELECT M.MON$REMOTE_ADDRESS FROM MON$ATTACHMENTS M WHERE M.MON$ATTACHMENT_ID = CURRENT_CONNECTION);

END

Este trigger inserta dentro de las columnas LOG_USUARI, LOG_FECHOR y LOG_COMPUT sus correspondientes valores. Como esos valores son constantes no vale la pena escribirlos cada vez que insertamos una fila en la tabla de LOG, lo mejor es tener un trigger que se encargue de esa tarea.

Si no tuviéramos este trigger tendríamos que escribir:

INSERT INTO
   LOG
VALUES
   (0, CURRENT_USER, CURRENT_TIMESTAMP, 'MiTabla', (SELECT M.MON$REMOTE_ADDRESS FROM MON$ATTACHMENTS M WHERE M.MON$ATTACHMENT_ID = CURRENT_CONNECTION), MiStop, MiValor);

Pero como tenemos un trigger podemos escribir:

INSERT INTO
   LOG
   (LOG_TABLAX, LOG_STOPXX, LOG_VALORX)
VALUES
   ('MiTabla', MiStop, MiValor);

El autor de este blog prefiere la segunda forma, pero sobre gustos…

Ahora que ya tenemos la tabla de LOG y sus triggers podemos dedicarnos a insertar sus filas en los lugares que los necesitemos. Algo muy importante a recordar es que las inserciones en la tabla de LOG deben hacerse siempre con IN AUTONOMOUS TRANSACTION.

¿Por qué?

Porque las transacciones autónomas son independientes de la transacción principal y siempre son «comiteadas» o confirmadas, sin importar si la transacción principal terminó con un COMMIT o con un ROLLBACK.

De esta manera nos aseguramos que en la tabla de LOG siempre se inserten las filas, porque eso es justamente lo que nos interesa, que tenga filas que nos permitan conocer lo que está pasando dentro de un stored procedure o de un trigger.

Ejemplo:

CREATE TRIGGER BIENES_BI FOR BIENES
   ACTIVE BEFORE INSERT
   POSITION 1
AS
   DECLARE VARIABLE lcCodigo D_NOMBRE15;
   DECLARE VARIABLE lnNumero D_CANTIDAD1;
   DECLARE VARIABLE lcInicia D_CHAR3;
BEGIN

/* Primero, se halla el último código de esta categoría */
   FOR SELECT
      BIE_CODIGO
   FROM
      BIENES
   WHERE
      BIE_IDECAT = NEW.BIE_IDECAT
   ORDER BY
      BIE_CODIGO
   INTO
      :lcCodigo
   DO BEGIN
   END

   /* Si no se encontró, el número será 1. Si se encontró, será el siguiente */
   IF (lcCodigo IS NULL) THEN
      lnNumero = 1;
   ELSE
      lnNumero = CAST(SUBSTRING(lcCodigo FROM 4 FOR 5) AS INTEGER) + 1;

IN AUTONOMOUS TRANSACTION DO BEGIN
   INSERT INTO LOG(LOG_TABLAX, LOG_STOPXX, LOG_VALORX) VALUES('BIENES', 1, :lcCodigo);
   INSERT INTO LOG(LOG_TABLAX, LOG_STOPXX, LOG_VALORX) VALUES('BIENES', 2, :lnNumero);
END

   /* Se obtienen los caracteres iniciales del código */
   lcInicia = (SELECT CAT_INICIA FROM CATEG_ACTIVO WHERE CAT_IDENTI = NEW.BIE_IDECAT);

IN AUTONOMOUS TRANSACTION DO BEGIN
   INSERT INTO LOG(LOG_TABLAX, LOG_STOPXX, LOG_VALORX) VALUES('BIENES', 3, :lcInicia);
END

   /* Se forma el código del bien que se grabará en la tabla */
   NEW.BIE_CODIGO = lcInicia || LPAD(lnNumero, 5, '0');

IN AUTONOMOUS TRANSACTION DO BEGIN
   INSERT INTO LOG(LOG_TABLAX, LOG_STOPXX, LOG_VALORX) VALUES('BIENES', 4, NEW.BIE_CODIGO);
END

END

En este trigger he puesto tres veces IN AUTONOMOUS TRANSACTION y dentro de ellos los INSERT a la tabla de LOG. En este caso se podría haber usado un solo IN AUTONOMOUS TRANSACTION al final y poner en él todos los INSERT, pero la forma en que está es para mostrar que se pueden escribir varios INSERT INTO LOG si así se desea o necesita.

Al insertar un nuevo bien a la tabla de BIENES se insertan 4 filas a la tabla de LOG, como podemos ver a continuación:

Captura 2. Si haces clic en la imagen la verás más grande

Si la conexión hubiera sido por dirección de IP en la columna LOG_COMPUT se hubiera visto el número de IP de la computadora.

En la columna LOG_VALORX tenemos los valores de las variables en la primera inserción (LOG_STOPXX = 1), en la segunda inserción (LOG_STOPXX =2), etc.

Conclusión:

Tener una tabla de LOG para registrar en ella todo lo que ocurre dentro de los stored procedures y de los triggers es de una gran ayuda cuando necesitamos depurar código fuente. Hay que recordar que la inserción en la tabla de LOG siempre debe hacerse dentro de un IN AUTONOMOUS TRANSACTION para que esa inserción sea siempre «comiteada» (o sea: confirmada), sin importar como termine la transacción principal.

Artículos relacionados:

El índice del blog Firebird21

El foro del blog Firebird21