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

Aplicación monolítica o distribuida?

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

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