KBLogAnalyzer - Analizando logs de aplicaciones Genexus (.NET).




Problema:

Tengo un conjunto de archivos de log, generados con GeneXus, generalmente bastante grandes y tengo que procesarlos para encontrar lentitudes, errores o cosas a mejorar. 

Los registros son de la forma:

2023-10-09 16:01:28,930 [31] DEBUG GeneXus.Data.ADO.GxConnectionManager - GxConnectionManager.DecOpenHandles   handle '3799', datasource 'Default', openhandles 1
2023-10-09 16:01:28,991 [31] DEBUG GeneXus.Data.NTier.DataStoreProvider - gxObject:GeneXus.Programs.pxmlconceptos__default, handle '3799' cursorName:P00ME5
2023-10-09 16:01:28,991 [31] DEBUG GeneXus.Data.ADO.GxCommand - ExecuteReader: Parameters @ConId='53'

Hice un pequeño utilitario que facilita o acelera el procesamiento

Es un cmd llamado KBLogAnalyzer.cmd, que al correrlo pregunta el directorio de logs, el directorio de salida (procesa todos los archivos que estén en ese directorio) y que tipo de procesos se quiere realizar


Con eso, procesa los archivos de log, y permite generar los archivos:
  • totalByPrograms.txt Ranking de cantidad de veces que ejecuto un programa
  • totalByStmt.txt Ranking de cantidad de veces que ejecuto una sentencia SQL
  • detectDelays.txt Entrdas de log, que demoraron mas que un umbral (threshold) dado
  • unknounLogType.txt Entradas de log, que no tiene un tipo de log conocido
  • ErrorWarning.txt Entrdas de log, que son ERROR/FATAL/WARN

Ejemplos de salida

Total por programa

Cantidad_de_Veces;Programa
979831;chequeoSeguridad
281911;liquidacion
59245;usuariovalido
39352;liquidaciondetalle
39011;graboliquidacion
......

Total por Sentencia

Cantidad_de_Veces;Sentencia
551842;SELECT [AumFecha], [AumId], [AumPor] FROM [Tabla1] WITH (NOLOCK) WHERE ([AumId] = @AV23AumId1 and [AumFecha] > @HPLFecha) AND ([AumFecha] <= @AV8PLFecha) ORDER BY [AumId]
426781;SELECT [ConId], [AcuTipo], [AcuId], [ConAcuOpe], [ConAcuMult] FROM [Tabla2] WITH (NOLOCK) WHERE [ConId] = @AV32ConId and [AcuTipo] = 'H' ORDER BY [ConId]
78658;INSERT INTO [Tabla3]([FunId], [HCorLiq], [HCorLin], [DCTipo], [DCLin], [DCOpe], [DCApar], [DCUsar], [DCNro], [DCAnio], [BasId], [DCCargo], [DCCCosto], [DCMult], [DCDiv], [DCCPar], [DCImpLinea], [DCImpParci], [DCObservac], [DCAporId], [DCConId], [DCRefAux], [DCIniAguin], [DCFinAguin], [DCMovFunAL]) VALUES(@FunId, @HCorLiq, @HCorLin, @DCTipo, @DCLin, @DCOpe, @DCApar, @DCUsar, @DCNro, @DCAnio, @BasId, @DCCargo, @DCCCosto, @DCMult, @DCDiv, @DCCPar, @DCImpLinea, @DCImpParci, @DCObservac, @DCAporId, @DCConId, @DCRefAux, @DCIniAguin, @DCFinAguin, @DCMovFunAL)
.....

Sentencias lentas

Diferencia de tiempo: 2341 ms (Anterior: 10/09/2023 15:10:44, Actual: 10/09/2023 15:10:46)
2023-10-09 15:10:44,162 [15] DEBUG GeneXus.Data.GxConnectionCache - GetPreparedCommand cached stmt:SELECT [LId], [LFunId], [LCobId], [LFunFicto], [LFunRecibo], [LMovTipo], [LConId], [LConTipo], [LPorR], [LCant], [LUnit], [LImp], [LImpRechaz], [LUnitME], [LImpME], [LMovCCId], [LMovCarId], [LAL], [LMovFechaR], [LMovDescRe], [LMovDetall], [LMovFchMov], [LFunId2], [LClas], [LMovRefAux], [LMovFch], [LMovFchHas] FROM [Liquidac] WITH (UPDLOCK) WHERE [LId] = @AV8LId ORDER BY [LId]  ## 2341 ms
...

Errores y Warnings

2023-10-09 16:01:28,993 [31] ERROR GeneXus.Data.NTier.ADO.GXFatFieldGetter - getShort - index :  1  value: 53
2023-10-09 16:01:28,993 [31] WARN GeneXus.Data.NTier.ADO.GXFatFieldGetter - getString - index :  2  value: H
....

Hace más fácil encontrar los errores y luego se puede analizar más específicamente en el archivo correspondiente y ver su entorno.

Tipo de log desconocido

Los logs tiene muchas entradas que no tienen fecha y hora y pueden distorsionar los análisis. Generalmente son entradas grabada por el usuario o entradas de log multi-linea. 

En este archivo se guardan las entradas del tipo:
GX_CLIENT_ID:b09938b1-f073-42b6-b308-39a108cf332e
GX_SESSION_ID:fTNK4e%2brudk56iNv7YqsrUlZURMihC8pkNyfovvtuOk%3d

Conclusión

Si alguien lo prueba y tiene algún feedback, es bienvenido. 

PD: No conozco una forma fácil de extraer el programa y las sentencias, que funcione bien el 100% de los casos. Por ahora, funciona con los ejemplos que lo he probado, pero estoy seguro que hay casos que no va a funcionar bien.  Los fuentes estan disponibles, por lo que es facil de adaptar si se programa algo de Powershell. 




Comentarios

Entradas más populares de este blog

La nefasta influencia del golero de Cacho Bochinche en el fútbol uruguayo

Aplicación monolítica o distribuida?

Funcionalidades de GeneXus que vale la pena conocer: DATE Constants.