Quarkus logging and log4j2 support

[ppatierno]

I am reading the Quarkus documentation about logging here but there are a few questions I can't find proper answers.
What does it mean for Quarkus supporting log4j2?
I mean, other than adding the log4j2-jboss-logmanager dependency to route Log4j logs to JBoss Log Manager ...

Is it possible to use log4j2.properties file to configure logging? Or it has to be always application.properties file?

Is it possible to leverage the log4j2 automatic reconfiguration without the need to restart the application?

How does it work if you need more loggers in order to specify a different log level for each of them. For example, in our Strimzi Kafka bridge (we are porting to Quarkus) we have something like this:

# HTTP OpenAPI specific logging levels (default is INFO)
# Logging healthy and ready endpoints is very verbose because of Kubernetes health checking.
logger.healthy.name = http.openapi.operation.healthy
logger.healthy.level = WARN
logger.ready.name = http.openapi.operation.ready
logger.ready.level = WARN

Where healthy and ready are two OpenAPI operation (related to an HTTP call) for which we are able to specify different logging levels.
Is it possible something like this in Quarkus?

[quarkus-bot[bot]]

/cc @Sgitario (kubernetes), @geoand (kubernetes), @iocanel (kubernetes)

[geoand]

@jamezp and @dmlloyd can give you all the gory details

[dmlloyd]

The logging backend is always JBoss LogManager, but we support merging log messages from many different frontends.

flowchart LR

A(JBoss Logging) --> X(JBoss LogManager)
B(java.util.logging) --> X
C(System.Logger) --> X
D(slf4j 1 & 2) --> X
E(log4j) --> X
F(log4j2) --> X
G(LogBack) --> X
H(Apache commons-logging) --> X

X --> O1(Console logging)
X --> O2(File logging)
X --> O3(Custom handlers)

Loading

As with all extensions in Quarkus, the log manager is configured using application.properties. Quarkus does not support dynamic reconfiguration at run time, in order to keep the image size minimal and startup time fast.

However, it is possible to programmatically reconfigure logging at run time using either the java.util.logging or JBoss LogManager (org.jboss.logmanager) APIs in order to change log levels or make other adjustments as needed. Doing this by way of (for example) an authenticated REST endpoint which is designed for this purpose could be safer/more secure than relying on filesystem modification.

[dmlloyd]

In JBoss LogManager, categories and logger names are equivalent; internally there is one logger per category. If you want multiple loggers per category, I would recommend using a sub-category.

I also personally advise that logger categories be established based on the process being described, rather than the (common) practice of naming categories after class names. Using class names is fragile because they become sensitive to internal refactoring, and the logger might describe many unrelated actions or processes. Instead, a class which has a logger instance for each logical process being described is much more resilient to refactoring, and also allows each logical process to be logged at a different level, with different formatting, or even to different log backends. I normally go with package name (or similar reverse-domain construct) plus process name; for example "org.example.billing.create-bill" or "org.example.storage.process-document" or whatever. But, that is up to you; JBoss LogManager supports the class name idiom as well.

[ppatierno]

Hey @dmlloyd thanks again ...
Taking a look at the logging doc again, it sounds to me that a "category" can be a package down to the class.
What I understand from your answer is the exact opposite, that using class is not a good thing to do and we can use custom categories related more to the process.
It seems to match with what we have.
Just to provide you more context, right now we have an HttpOpenApiOperation class representing an HTTP request "handler" which on creation gets a corresponding logger instance as you can see here https://github.com/strimzi/strimzi-kafka-bridge/blob/main/src/main/java/io/strimzi/kafka/bridge/http/HttpOpenApiOperation.java#L31
As said before the logger name will be something like http.openapi.operation.<operation-name> and it will have a corresponding configuration in the log4j2.properties file.
Moving this implementation to use "categories" sounds like having something like this in the application.properties:

quarkus.log.category."http.openapi.operation.<operation-name>".level=DEBUG

From what you said it seems that instead of "injecting" a Logger as we usually do in Quarkus application, I can have the same as today so creating the Logger with the name/category I need.
Is my understanding right?

From here, because in the end we need this for selecting specific logging levels on each HTTP request, isn't there any feature to facilitate this when using Quarkus RESTeasy Reactive (which is the one we use)?

[ppatierno]

From what you said it seems that instead of "injecting" a Logger as we usually do in Quarkus application, I can have the same as today so creating the Logger with the name/category I need.
Is my understanding right?

So yes I answered my own question ... I tried something like this:

Logger log = Logger.getLogger("my.own.logger");
log.info("***** my.own.logger: Info message");
log.debug("***** my.own.logger: Debug message");

With no configuration in the application.properties file, it prints only INFO level.
By adding quarkus.log.category."my.own.logger".level=DEBUG it prints at DEBUG level as well. Or setting to WARN, it does print nothing. Cool!

It's still in place my question about facilitating the logging for HTTP request related to the usage of Quarkus RESTeasy Reactive :-)

[dmlloyd]

Hey @dmlloyd thanks again ... Taking a look at the logging doc again, it sounds to me that a "category" can be a package down to the class. What I understand from your answer is the exact opposite, that using class is not a good thing to do and we can use custom categories related more to the process.

Technically it's just a dot-separated string, where each segment corresponds to a hierarchical level of loggers. As for the docs - well, logging is still a fairly divisive topic, so I won't say one way is "right" or "wrong" but I have my preference. :-)

It seems to match with what we have.

Great!

Just to provide you more context, right now we have an HttpOpenApiOperation class representing an HTTP request "handler" which on creation gets a corresponding logger instance as you can see here https://github.com/strimzi/strimzi-kafka-bridge/blob/main/src/main/java/io/strimzi/kafka/bridge/http/HttpOpenApiOperation.java#L31 As said before the logger name will be something like http.openapi.operation.<operation-name> and it will have a corresponding configuration in the log4j2.properties file. Moving this implementation to use "categories" sounds like having something like this in the application.properties:

quarkus.log.category."http.openapi.operation.<operation-name>".level=DEBUG

Yes, that seems like it would be correct.

From what you said it seems that instead of "injecting" a Logger as we usually do in Quarkus application, I can have the same as today so creating the Logger with the name/category I need. Is my understanding right?

Right, in fact in nearly all cases, I would always create a logger instance and store it in a static final field.

From here, because in the end we need this for selecting specific logging levels on each HTTP request, isn't there any feature to facilitate this when using Quarkus RESTeasy Reactive (which is the one we use)?

I'm not sure about RESTeasy Reactive but several log APIs use an enumerated Level type of some sort, so one idea would be that you could select the level at a point early in the request and then pass the level around to the rest of the handler, using methods like LOGGER.log(level, ...) or equivalent.

So yes I answered my own question ... I tried something like this:

Logger log = Logger.getLogger("my.own.logger");
log.info("***** my.own.logger: Info message");
log.debug("***** my.own.logger: Debug message");

With no configuration in the application.properties file, it prints only INFO level. By adding quarkus.log.category."my.own.logger".level=DEBUG it prints at DEBUG level as well. Or setting to WARN, it does print nothing. Cool!

👍

It's still in place my question about facilitating the logging for HTTP request related to the usage of Quarkus RESTeasy Reactive :-)

Hopefully the above gives you some inspiration or ideas.