Logs

¿A quién no le ha tocado lidiar alguna vez con un log? Es una pregunta sencilla, y más de uno ha echado una risilla al leerla porque se imagina de qué va el tema. Efectivamente, vamos a hablar de la utilidad y la eficacia de la información presente en los logs, esos ficheros llenos de letras que nos dan muchos dolores de cabeza.

Tenemos muchos tipos de logs, dependiendo del equipo del que provengan y la utilidad que se da al mismo. No es lo mismo un log de un firewall que el del servidor de aplicaciones del programa de cuentas de la empresa. En el mundo de las redes de control ocurre lo mismo que en las redes empresariales. No tenemos el mismo log en una RTU que en el Front-End de comunicaciones.
El mundo de control tiene muchas deficiencias en cuanto al mundo del log se refiere. Tradicionalmente los equipos de control eran autónomos y estaban aislados del mundo, a menudo el operario se encargaba de su supervisión, entonces ¿para que necesito un log? Este hecho hace que, ahora que los centros de control están interconectados, no tengamos constancia del funcionamiento de muchos equipos al no poder consultar su listado de mensajes, su log.
Esta carencia la han solucionado algunos proveedores mediante programas que se encargan de hacer un log de determinadas variables del equipo utilizando un formato estándar para todos los mensajes, ¿pero es realmente comprensible esa salida?

Evidentemente no podemos comparar la lectura de un log de un equipo que presenta registro de eventos propio, de otro sacado a base de un programa genérico. El primero presenta mensajes de todo tipo, como siempre dependerá del nivel de detalle (debug, info, warning, error, etc.) que hayamos puesto en la configuración, pero que, en general, serán de diferente índole y darán diversa información sobre el encendido o apagado del equipo, las librerías que Carga y utiliza, los fallos o avisos, etc. En el segundo, como ya hemos dicho, la estructura es común en todos los mensajes, por lo que es más comprensible, pero a cambio no se pueden presentar tantos mensajes y tan diversos como en el primero caso.

2009-10-20 23:50:02 T1: Regins preparada para recibir trazas y errores. (regins,regMain.c,158)
2009-10-20 23:50:02 T1: Canal: sactraza.91259729.servidor.RegistroInstancia.*.> (regins,regMain.c,159)
2009-10-20 23:50:02 T1: Regins preparada para recibir trazas y errores. (regins,regMain.c,181)
2009-10-20 23:50:02 T1: Canal: sactraza.91259730.servidor.RegistroInstancia.*.> (regins,regMain.c,182)
[GEN]2009-10-20 23:50:04 T2: [APL_FEND/geaplp2 (1)].--- Heart Beat BDSAC (7 ms) --- (gestins,geConsultasIniciales.pc,616)
[PRI]2009-10-20 23:51:39 T2: AVISO_MANDO: Llega mando estado. IdSac 795936 | Tipo 2001 | Valor 0 | Maquina 14436667 | IdPoe 50660453 (fccMain,fcuCbSFE_Accion.c,224)
[GEN]2009-10-20 23:51:39 T2: [APL_FEND/geaplp2 (1)].--- Heart Beat BDSAC (6 ms) --- (gestins,geConsultasIniciales.pc,616)
[PRI]2009-10-20 23:51:43 T2: AVISO_INFO: MENSAJE NO CONSIDERADO!!!! dataStorTimeSync session 61 (PRAT) sector 0 quantity 1 IOA 100!!!!!!!!!!!!!! (fccMain,fcuLib101.c,2111)
[GEN]2009-10-20 23:51:44 T2: [APL_FEND/geaplp2 (1)].--- Heart Beat BDSAC (7 ms) --- (gestins,geConsultasIniciales.pc,616)
[PRI]2009-10-20 23:52:04 T2: AVISO_MANDO: Llega mando estado. IdSac 350115 | Tipo 2010 | Valor 0 | Maquina 14436667 | IdPoe 50660453 (fccMain,fcuCbSFE_Accion.c,224)
[PRI]2009-10-20 23:52:10 T2: AVISO_MANDO: Llega mando estado. IdSac 350115 | Tipo 2010 | Valor 0 | Maquina 14436667 | IdPoe 50660453 (fccMain,fcuCbSFE_Accion.c,224)
[PRI]2009-10-20 23:52:24 T2: AVISO_CONEX: 'DESCONEXION REMOTA POR NOTIFICACION SCADA' para RTU (ER687593/TREG1/32790) (fccMain,fcuSFE.c,1109)
[PRI]2009-10-20 23:52:24 T2: AVISO_CONEX: Procediendo a marcar para gestion reconexion la remota ('ER687593'/'TREG1'/'32790') ('REMOTA MARCADA PARA GESTION RECONEXION POR DESCONEXION') (fccMain,fccReconexionRemotas.c,378)

En el fragmento de log anterior, perteneciente a un Front-End de comunicaciones, podemos observar mensajes de todo tipo, del equipo, configurados por el usuario y que el equipo no comprende, conexión y desconexión de equipos, etc.

< date="'2007-09-04T17:41:05.940+06:30'" local="'N'" name="'DB_UPDATE'" desc="'DB_UPDATE'" val="'YES'/">
< date="'2007-09-04T17:48:05.565+06:30'" local="'N'" name="'TEMP_HIGH_CB1'" desc="'TEMPERATURE" val="'TRUE'/">
< date="'2007-09-04T18:02:05.376+06:30'" local="'N'" name="'TEMP_HIGH_CB1'" desc="'TEMPERATURE" val="'FALSE'/">
< date="'2007-09-04T18:12:21.884+06:30'" local="'N'" name="'TEMP_HIGH_CB1'" desc="'TEMPERATURE" val="'TRUE'/">
< date="'2007-09-04T21:03:34.521+06:30'" local="'N'" name="'TEMP_HIGH_CB1'" desc="'TEMPERATURE" val="'FALSE'/">
< date="'2007-09-04T21:03:37.459+06:30'" local="'N'" name="'TEMP_HIGH_CB2'" desc="'TEMP_HIGH_CB2'" val="'FALSE'/">
< date="'2007-09-04T21:03:37.516+06:30'" local="'N'" name="'BULK_SUPLY_CB1'" desc="'BULK" val="'FALSE'/">
< date="'2007-09-04T21:03:37.895+06:30'" local="'N'" name="'FAN_FAIL_CB2'" desc="'FAN_FAIL_CB2'" val="'FALSE'/">
< date="'2007-09-04T21:03:38.194+06:30'" local="'N'" name="'IORACK_SUPLY_CB1'" desc="'I/O" val="'FALSE'/">
< date="2007-09-04T17:41:05.940+06:30" local="N" name="DB_UPDATE" desc="DB_UPDATE" val="YES">

Claramente este otro fragmento, de una RTU, es muy diferente del anterior. En este caso estamos viendo un fragmento en el que todos los mensajes son iguales. Aquí se puede apreciar la similitud de todos los mensajes, y se pueden apreciar todos los cambios en las variables y seguirlos fácilmente. Como ya hemos indicado, no tenemos la versatilidad de los equipos con log propio.

Podemos decir que si el equipo no presenta logs podernos utilizar un “parche” para conseguirlos, pero no serán de la misma calidad y utilidad que los producidos directamente por los equipos.

Y todo esto, porque ahora se comienza a analizar los logs de los elementos de campo nos damos cuenta que son muy básicos. Para los operarios los logs no son algo a utilizar, para los informáticos los elementos de campo no van con ellos, cedamos todos un poco y entendamonos.

Jairo Alonso
S21sec Labs