Azure Functions | Administrar el nivel de Log con ILogger

Cuando desarrollamos una Azure Function y la depuramos en local, poco se puede ver en la consola que se levanta y nos muestra la traza dada la cantidad y la velocidad con la que se muestra la información. Gracias al archivo de configuración de la function «host.json» podemos gestionar el nivel de logging que deseamos mostrar y así poder ver nuestros propios mensajes.

Contexto

A la hora de depurar en local una Azure Function no suele haber demasiado problema ya que la cantidad de mensajes mostrados no es demasiado alta, pero en el momento en el que comenzamos a tener más Azure Functions y con mayor complejidad, o incluso Azure Durable Functions, la cosa se vuelve caótica porque seremos incapaces de detectar mensajes importantes en dicha traza ya que el buffer de la consola no es infinito y porque con cada escritura de log, el puntero se situa al final de la consola.

Como se puede apreciar en la imagen, no es posible leer los logs que aparecen entre los logs de la propia ejecución de nuestra Azure Function ya que, aunque podemos identificar que hay Critical, Error, etc, no somos capaces de leer el texto del mensaje y además nos pasan desapercibidos los logs de información y el mensaje de consola que he puesto.

[FunctionName("LoggingSampleFx")]
public static void Run([TimerTrigger("*/5 * * * * *")]TimerInfo myTimer,
[Queue("myqueue-items")]ICollector<MyQueueMessage> myQueueItems,
ILogger log)
{
log.LogTrace($"TRACE - Hello world: {DateTime.Now}");
log.LogDebug($"DEBUG - Hello world: {DateTime.Now}");
log.LogInformation($"INFO - Hello world: {DateTime.Now}");
log.LogWarning($"WARNING - Hello world: {DateTime.Now}");
log.LogError($"ERROR - Hello world: {DateTime.Now}");
log.LogCritical($"CRITICAL - Hello world: {DateTime.Now}");
Console.WriteLine($"CONSOLE MESSAGE - Hello world: {DateTime.Now}");

myQueueItems.Add(new MyQueueMessage { Title = "Hello Queue 1", MessageDate = DateTime.Now });
myQueueItems.Add(new MyQueueMessage { Title = "Hello Queue 2", MessageDate = DateTime.Now });
myQueueItems.Add(new MyQueueMessage { Title = "Hello Queue 3", MessageDate = DateTime.Now });
}

Administrar el nivel de Log (LogLevel)

Para poder administrar qué queremos que se muestre en la consola, lo que debemos hacer es editar el fichero host.json y añadir el bloque de control de nivel de registro (LogLevel) correspondiente para el contexto de la Function y el subcontexto de la function en concreto, si es que queremos afinar a ese nivel.

Para trabajar con el logging en .Net Core, se han introducido «ámbitos» como puede ser Console, Microsoft o, en este caso, Function que nos permite gestionar el LogLevel a partir de ese contexto afinando hasta las propias functions como veremos más adelante.

Niveles

Antes que nada, debemos conocer los valores que puede tomar LogLevel ya que, el que establezcamos será el nivel mínimo que se mostrará en la consola. Este orden se establece según el valor numérico de la siguiente tabla que podemos ver en este enlace

Nivel por defecto

Si queremos establecer un nivel por defecto para todos los logs de nuestra Azure Function, debemos introducir el siguiente código en el fichero host.json

"logging": {
"fileLoggingMode": "always",
"logLevel": {
"default": "Information"
}
}

De esta forma, el fichero debería parecerse a lo siguiente

{
"version": "2.0",
"logging": {
"fileLoggingMode": "always",
"logLevel": {
"default": "Information"
},
"applicationInsights": {
"samplingExcludedTypes": "Request",
"samplingSettings": {
"isEnabled": true
}
}
}
}

Si hemos configurado Application Insights en nuestra Azure Function, ya dispondremos del bloque «logging» y el sub-bloque «applicationInsighs». Si no lo hemos configurado, podemos omitir el bloque «applicationInsights»

Como se puede apreciar, tenemos la siguiente secuencia de configuración «logging» => «logLevel» => «default» donde «default» tiene el valor «Information». Esto quiere decir que a partir de ahora sólo se mostrarán los logs que sean como mínimo de nivel de Información. Eso quiere decir que los logs de nivel Debug y Trace no aparecerán pero, aún así, es complicado leer nada y además, sí que queremos que aparezcan esos logs.

Nivel de registro para todas las Azure Functions

Si afinamos un poco más, iremos al ámbito de toda nuestra Azure Function con lo que podremos gestionar qué queremos que aparezca a nivel de nuestra Function y restringir algo más el resto de mensajes de ejecución. Esto lo lograremos añadiendo la etiqueta «Function» con el valor «Trace» y cambiando el valor por defecto a «Error» de forma que para la function recibiremos todos los mensajes pero para el resto de logs está restringido a aquellos que sean de nivel «Error» o superior.

"logLevel": {
"default": "Error",
"Function": "Trace"
},

Como se puede observar, ahora aparecen los registros Trace y Debug entre algo menos de registros de ejecución pero, aún así es complicado leer esos logs ya que siguen apareciendo los de ejecución del resto de Azure Functions que tenemos en nuestro proyecto ya que están dentro del mismo ámbito así que, debemos seguir afinando.

Nivel de registro para una Azure Function concreta

Ahora vamos a restringir aún más qué registros queremos ver en la consola, añadiendo el sub-ámbito al fichero host.json de la siguiente forma.

"logLevel": {
"default": "Error",
"Function": "Warning",
"Function.LoggingSampleFx": "Trace"
},

Como se puede ver, he añadido una nueva etiqueta «Function.FunctionsLogging» con el valor «Trace» y he modificado el valor de la etiqueta «Function» a «Error». De esta forma, estaremos indicando que para la function «LoggingSampleFx» queremos que se registre cualquier mensaje de nivel Trace o superior, para el resto de Azure Functions de nivel «Warning» o superior y para cualquier otro elemento del proyecto, de nivel «Error» o superior.

En este caso, sí podemos identificar los mensajes que estamos escribiendo desde nuestra Azure Function y podremos saber qué está pasando en todo momento.

Vídeo del ejemplo

Conclusión

Es posible administrar los logs de nuestras Azure Functions, de modo que podamos ver en la consola sólo los mensajes que necesitemos y así poder realizar depuraciones más rápidas y eficientes, lo que nos ayudará a ser más productivos, sin hablar de que evitamos la molestia de ver cómo la consola está en continua escritura de mensajes.

Espero que os sirva de ayuda.

Enjoy coding!