Las clases para logging del paquete JUL incluidas en la API de Java

Las trazas o logs en una aplicación forman parte de la parte del área de trazabilidad, observabilidad, monitorización e incluso en el área de seguridad, una de las funcionalidades que necesitan las aplicaciones, más imprescindible aún en los microservicios. Las trazas son mensajes con información que emite la aplicación para su análisis, estas se pueden emitir a un destino que puede ser simplemente la salida estándar de la consola, un archivo y en los sistemas más avanzados un sistema ELK para centralizar las trazas en un único sistema compuesto por múltiples aplicaciones. Una buena práctica es emitir las trazas en la salida estándar de la aplicación y que sea un proceso externo el que determina como y donde se guardan las trazas de la aplicación, lo que proporciona la flexibilidad de cambiar donde se guardan las trazas sin requerir cambios en la aplicación.

Las trazas permiten ver qué ha ocurrido hace tiempo y conocer qué ocurre en la aplicación en tiempo real. Las trazas incluyen las excepciones que se generan en la aplicación y errores, identificados los errores que se están produciendo las mismas trazas dan pistas de las condiciones en las que se producen, identificar el problema, reproducirlo y con todo ello hacer los cambios en el código necesarios para corregir los errores. Sin las trazas es mucho más difícil conocer qué errores se están produciendo en la aplicación y en qué condiciones se producen para reproducirlo. Hay que tener en cuenta que muchas veces la mayor parte del tiempo que se emplea para corregir un error es en identificar las causas y reproducirlo, la parte de corregirlo haciendo cambios en el código generalmente es una pequeña parte de todo el tiempo empleado. La facilidad y rapidez para corregir un error en gran medida depende de que la aplicación emita una colección de buenas trazas.

En Java la librería Log4j es la más utilizada para la funcionalidad de trazas, es una librería muy completa que tiene todas las funcionalidades relativas a trazas que requiera una aplicación en el momento actual o en el futuro. Otra librería muy popular en Java es SLF4 que permite independizar a la aplicación de la implementación de la traza pudiendo cambiar de una u otra según se desee.

Otra alternativa es usar las clases que se incluyen en él la propia API de Java para logging en el paquete java.util.logging. No son tan avanzadas como las de Log4j pero son suficientes para muchos casos de uso. Dado a un grave fallo de seguridad en Log4j qué ha afectado a muchas empresas, y raíz de esta situación quizá alguna persona considere utilizar o revisar las clases de logging de Java como alternativa a incluir una dependencia para algo que con lo que ofrece la API quizá sea suficiente para una aplicación.

Las clases de logging de Java

Al ofrecer Java en su API clases para realizar tareas de logging significa que cualquier aplicación las pueda utilizar sin ninguna dependencia adicional a partir de la versión 1.4 en la que fueron incluidas. A las clases y sistema de logging de Java se le denomina JUL por las primeras letras de los paquetes en las que están, java.util.logging.

Las clases principales de JUL son equivalentes a las que se encuentran en otras librerías ya que en definitiva en cualquier librería representan los mismos conceptos del área de dominio de logging.

• Logger: es la clase de entidad principal que usan las aplicaciones para emitir trazas. Se crea una instancia de logger diferente por cada componente específico del sistema o aplicación.
• LogRecord: es una clase que contiene los datos a ser pasados entre el framework de logging y los log handlers.
• Handler: envía los objetos LogRecord a una variedad de destinos incluyendo memoria, flujos de salida, la consola, archivos y sockets. Existe una variedad de subclases de Handler con una implementación para cada destino. Adicionalmente los Handlers pueden ser desarrollados por tercera partes e integrados sobre el núcleo de la plataforma.
• Level: define un conjunto estándar de niveles de log que se usan para controlar la salida y gravedad del mensaje. Los programas pueden ser configurados para emitir trazas para algunos niveles mientras se ignoran las trazas de otros.
• Filter: proporciona un control fino sobre lo que es emitido, más allá del control proporcionado por los niveles de log. La API de logging soporta un mecanismo de propósito general que permite al código de la aplicación asociar filtros arbitrarios para controlar la salida de las trazas..
• Formatter: proporciona soporte para especificar cómo son formateados los objetos LogRecord. El paquete de JUL incluye dos formateadores, SimpleFormatter y XMLFormatter, para formatear los registros de log en texto plano o XML respectivamente. Al igual que con los Handlers, terceras partes pueden desarrollar Formatters adicionales.

Motivos para usar JUL

Log4j es una de las mejores sino la mejor librería para trazas en Java, las ventajas son flexibilidad en caso de necesitar funcionalidades más en el futuro siendo raro que se necesite algo en materia de logging que no soporte Log4j de alguna forma. Logj4 permite guardar archivos, rotar los archivos por fecha o volumen de datos guardando cierto número de copias de seguridad, información de contexto entre más funcionalidades avanzadas, cosas adicionales que no tiene JUL. JUL por el contrario es una solución que no requiere incluir una dependencia adicional el proyecto y una solución más sencilla que puede ser más que suficiente para una aplicación o un pequeño script.

Depende del contexto del proyecto en sí es más conveniente usar solo JUL u optar por Log4j, no hay una misma respuesta para todos proyectos y a veces no hay ningún motivo claro para decidirse entre una u otra, siendo ambas más que suficientes. En el entorno de Google Cloud Functions por ejemplo solo entiende correctamente las trazas emitidas con JUL en el caso de una función con implementación Java. Es utilizar JUL directamente o utilizar Log4j sin que los niveles de las trazas se identifiquen bien en en los paneles de monitorización de Google Cloud Functions o en caso de que Log4j lo tuviese usar un adaptador para Log4j que redirija las trazas sobre JUL. Con la petición LOG4J2-3282 en Log4j a partir de la versión 2.17.2 precisamente proporciona un adaptador que envía las trazas a la consola utilizando JUL.

Incluir una dependencia en una aplicación debe estar justificado, no conviene añadir dependencias que de las que solo se usan una sola clase. Incluir una dependencia añade tamaño a la aplicación teniendo en cuenta que no solo se incluye esa dependencia sino además las transitivas, incluir dependencias de forma indiscriminada en un proyecto hace que pueda ocurrir un conflicto entre las diferentes versiones de dos. También en el caso de que una dependencia está justificada conviene optar por una que tenga pocas dependencias de forma transitiva por los mismos motivos.

Ejemplo usando las clases de Java para trazas

Este ejemplo muestra un uso básico de las clases de JUL que emite varias trazas usando diferente nivel para cada mensaje, en la salida de la consola se muestra cada uno de los mensajes con el formato por defecto que además del nivel y el mensaje incluye la fecha y hora como metadato adicional en la que ha ido emitido. Como suele ser una convención la instancia de Logger se inicializa como una variable estática privada a partir del nombre de la clase que queda disponible para ser usada en cualquier parte del código de la clase. En este caso la instancia no está en una variable estática para el caso de indicar un argumento hacer la configuración previa.

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23

package io.github.picodotdev.blogbitix.javalogging;

import java.io.InputStream;
import java.util.Arrays;
import java.util.logging.Level;
import java.util.logging.Logger;
import java.util.logging.LogManager;

public class Main {

    public static void main(String[] args) throws Exception {
        if (Arrays.asList(args).contains("--config")) {
            InputStream configuration = Main.class.getResourceAsStream("/jul.properties");
            LogManager.getLogManager().readConfiguration(configuration);
        }
        Logger logger = Logger.getLogger(Main.class.getName());

        logger.log(Level.FINE, "Hello World!");
        logger.log(Level.INFO, "Hello World!");
        logger.log(Level.WARNING, "Hello World!");
        logger.log(Level.SEVERE, "Hello World!", new Exception());
    }
}

1
2

$ ./gradlew run

1
2
3
4
5
6
7
8

ene 20, 2022 11:56:28 P. M. io.github.picodotdev.blogbitix.javalogging.Main main
INFORMACIÓN: Hello World!
ene 20, 2022 11:56:28 P. M. io.github.picodotdev.blogbitix.javalogging.Main main
ADVERTENCIA: Hello World!
ene 20, 2022 11:56:28 P. M. io.github.picodotdev.blogbitix.javalogging.Main main
GRAVE: Hello World!
java.lang.Exception
        at io.github.picodotdev.blogbitix.javalogging.Main.main(Main.java:21)

El formato del mensaje se puede cambiar estableciendo una propiedad de sistema en el comando de ejecución que inicia la máquina virtual. En el javadoc de la clase SimpleFormatter está detallada la explicación del formato y símbolos de la expresión para dar formato al mensaje. Cambiando el formato el resultado en la salida del programa cambia.

1
2

$ ./gradlew run -Djava.util.logging.SimpleFormatter.format="%1\$tF %1\$tT.%1\$tL %4\$-12.12s %2\$60.60s %5\$s%6\$s%n"

1
2
3
4
5

2022-01-20 23:56:51.271 INFORMACIÓN          io.github.picodotdev.blogbitix.javalogging.Main main Hello World!
2022-01-20 23:56:51.334 ADVERTENCIA          io.github.picodotdev.blogbitix.javalogging.Main main Hello World!
2022-01-20 23:56:51.334 GRAVE                io.github.picodotdev.blogbitix.javalogging.Main main Hello World!
java.lang.Exception
        at io.github.picodotdev.blogbitix.javalogging.Main.main(Main.java:21)

Configuración de JUL

Una forma de configurar JUL es a través de un archivo de propiedades, utilizar un archivo de configuración en vez código tiene la ventaja que no es necesario cambiar código en la aplicación para cambiar el comportamiento de JUL y si el archivo de configuración es obtenido de forma externa a la aplicación no es necesario compilar ni generar un nuevo artefacto ejecutable para cambiar la configuración.

El archivo de configuración permite cambiar los handlers a los que se envía las trazas, especificar el nivel de log mínimo aceptado por cada logger y finalmente configurar un Formatter para cambiar el formato por defecto de los mensajes a uno personalizado.

En este ejemplo de archivo de configuración se cambia el nivel de trazas de los logger que están en la jerarquía de nombres io.github.picodotdev.blogbitix.javalogging en base al nombre del paquete haciendo que solo acepten las trazas de nivel fine o superior, por defecto en el solo se aceptan las de nivel information. En el archivo de configuración es también posible indicar el formato de los mensajes. Con la configuración personalizada la salida del mismo programa es diferente.

1
2
3
4
5
6
7
8

.level=INFO
io.github.picodotdev.blogbitix.jul.level=FINE
io.github.picodotdev.blogbitix.jul.handlers=java.util.logging.ConsoleHandler

java.util.logging.ConsoleHandler.level=FINE
java.util.logging.ConsoleHandler.formatter=java.util.logging.SimpleFormatter

java.util.logging.SimpleFormatter.format=%1$tF %1$tT.%1$tL %4$-12.12s %3$60s %5$s%6$s%n

1
2

$ ./gradlew run --args="--config"

1
2
3
4
5
6

2022-01-20 23:57:22.385 DETALLADO                 io.github.picodotdev.blogbitix.javalogging.Main Hello World!
2022-01-20 23:57:22.401 INFORMACIÓN               io.github.picodotdev.blogbitix.javalogging.Main Hello World!
2022-01-20 23:57:22.402 ADVERTENCIA               io.github.picodotdev.blogbitix.javalogging.Main Hello World!
2022-01-20 23:57:22.402 GRAVE                     io.github.picodotdev.blogbitix.javalogging.Main Hello World!
java.lang.Exception
        at io.github.picodotdev.blogbitix.javalogging.Main.main(Main.java:21)

Soportar JUL y Log4j como implementación

A veces por flexibilidad interesa poder cambiar de implementación de framework de logging, añadir esta flexibilidad implica añadir un intermediario entre la aplicación y la implementación, en Java la librería SLF4J es precisamente este intermediario y permite cambiar de implementación a través de configuración sin necesidad de más cambios en el código de la aplicación cuya dependencia directa está en el intermediario y no en la implementación.

Sin embargo, por el mismo motivo de evitar incluir dependencias en un proyecto para casos sencillos es posible desarrollar un intermediario sencillo que haga la función de SLF4J. Esta implementación sencilla incluye algunos conceptos comunes de logging como la entidad Logger y Level. La clase Logger en este caso además para emitir las trazas se usa como factoría para obtener las instancias de Logger, para poder cambiar de implementación hace uso de un LogSupplier que simplemente es una función que recibe como parámetro una clase y devuelve una instancia de Logger. Configurando un LogSupplier u otro se cambia de implementación de framework de logging.

Estas son las funciones lambdas que implementan la interfaz LogSuplier, una implementación sirve para obtener instancias de Logger de JUL y otra implementación obtiene instancias de Logger de Log4j.

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22

package io.github.picodotdev.blogbitix.javalogging;

public interface Logger {

    void trace(String message);

    void trace(String message, Object... params);

    void info(String message);

    void info(String message, Object... params);

    void warn(String message);

    void warn(String message, Object... params);

    void error(String message);

    void error(String message, Object... params);

    void error(Throwable error);
}

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19

package io.github.picodotdev.blogbitix.javalogging;

public class LogManager {

    private static LoggerSupplier supplier;

    public static void configure(LoggerSupplier supplier) {
        LogManager.supplier = supplier;
    }

    public static Logger getLogger(Class clazz) {
        return supplier.get(clazz);
    }

    public interface LoggerSupplier {

        Logger get(Class clazz);
    }
}

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47

package io.github.picodotdev.blogbitix.javalogging;

import java.util.logging.Level;
import java.util.logging.Handler;

public class JulLogger implements Logger {

    private static Handler handler;
    private final java.util.logging.Logger logger;

    private JulLogger(Class clazz) {
        this.logger = java.util.logging.Logger.getLogger(clazz.getName());
        if (handler != null) {
            this.logger.addHandler(handler);
        }
    }

    public static void setLoggingHandler(Handler handler) {
        JulLogger.handler = handler;
    }

    public static Logger getLogger(Class clazz) {
        return new JulLogger(clazz);
    }

    @Override
    public void trace(String message) {
        trace(message, new Object[0]);
    }

    @Override
    public void trace(String message, Object... params) {
        logger.log(Level.FINE, adapt(message), params);
    }

    ...

    private String adapt(String message) {
        String m = message;
        int i = 0;
        while (m.contains("{}")) {
            m = m.replaceFirst("\\{\\}", "{" + i + "}");
            i += 1;
        }
        return m;
    }
}

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32

package io.github.picodotdev.blogbitix.javalogging;

import org.apache.logging.log4j.LogManager;

public class Log4j2Logger implements Logger {

    private final org.apache.logging.log4j.Logger logger;

    private Log4j2Logger(Class clazz) {
        this.logger = LogManager.getLogger(clazz);
    }

    public static Logger getLogger(Class clazz) {
        return new Log4j2Logger(clazz);
    }

    @Override
    public void trace(String message) {
        trace(message, new Object[0]);
    }

    @Override
    public void trace(String message, Object... params) {
        logger.trace(adapt(message), params);
    }

    ...

    private String adapt(String message) {
        return message;
    }
}

Al iniciar la aplicación según una variable de entorno, propiedad del sistema o argumento del programa se configura el LogSupplier para usar la implementación deseada.

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22

import io.github.picodotdev.blogbitix.javalogging.Log4j2Logger;
import io.github.picodotdev.blogbitix.javalogging.LoggerSupplier;
import io.github.picodotdev.blogbitix.javalogging.LogManager;
import io.github.picodotdev.blogbitix.javalogging.JulLogger;

...

LoggerSupplier supplier = null;
if (log.equals("log4j")) {
    supplier = (clazz) -> Log4j2Logger.getLogger(clazz);
} else if (log.equals("jul-gcp")) {
    java.util.logging.LogManager.getLogManager().readConfiguration(Main.class.getResourceAsStream("/jul-gcp.properties"));
    JulLogger.setLoggingHandler(new LoggingHandler());
    supplier = (clazz) -> JulLogger.getLogger(clazz);
} else if (log.equals("jul")) {
    java.util.logging.LogManager.getLogManager().readConfiguration(Main.class.getResourceAsStream("/jul.properties"));
    supplier = (clazz) -> JulLogger.getLogger(clazz);
} else {
    java.util.logging.LogManager.getLogManager().readConfiguration(Main.class.getResourceAsStream("/jul.properties"));
    supplier = (clazz) -> JulLogger.getLogger(clazz);
}
LogManager.configure(supplier);

Con la petición de LOG4J2-3282 deja de ser necesario usar JUL directamente y se puede utilizar a través de Log4j pero este es un ejemplo de una implementación sencilla en vez de tener que recurrir al SLF4J para la tarea de tener la flexibilidad de cambiar de implementación entre JUL o Log4j.

El código fuente completo del ejemplo puedes descargarlo del repositorio de ejemplos de Blog Bitix alojado en GitHub.