[Enhancement] Use Fluent Logging API to provide accurate, concise, and elegant logging

[Pil0tXia]

Search before asking

• I had searched in the issues and found no similar issues.

Enhancement Request

This issue is a sub-task of #4681.

The purpose of this issue is to provide syntactic support for resolving the logging problem #4681 by upgrading the versions of log4j and slf4j.

Background Knowledge

Disscussion: apache/logging-log4j2#2133

The additional isDebugEnabled() check before log.debug() is performed in order to avoid invoking the methods referenced in the message field, thus improving logging performance. For example:

log.debug("formatted msg: {}", formatMsg(rawMsg));

Even when the log level is set to info, the formatMsg(rawMsg) method will still be called and return a result before being passed as an argument to log.debug(). This takes time.

Describe the solution you'd like

Solution Selection

Since slf4j does not support passing arguments through the Supplier introduced in log4j 2.13.0 (discussed in qos-ch/slf4j#70, no need to read though), we will not adopt the solution of lazy invocation by passing the Supplier parameter. Additionally, the usage of the Supplier appears redundant, and most contributors cannot understand the difference between using a Supplier or not without prior knowledge.

The Fluent Logging API since slf4j 2.0.0 provides a more elegant and space-saving way of writing code. The modifications to the WatchFileManager class demonstrate the recommended approach.

Scenarios where Fluent Logging API is unnecessary

Only the scenario mentioned in the Background Knowledge section require the use of Fluent Logging API. For example, in the case of the changes in Codec class L224, where no object parameters are passed or existing objects are referenced, there is no additional performance overhead, and there is no need to pre-evaluate log levels. The simplest usage of slf4j can be directly applied.

Are you willing to submit PR?

• Yes I am willing to submit a PR!

Code of Conduct

• I agree to follow this project's Code of Conduct *

[Pil0tXia]

@yanrongzhen

Spring connector introduced log4j-to-slf4j-2.17.1.jar (according to 03aa825). You have excluded it from testImplementation by testImplementation.exclude group: 'org.apache.logging.log4j', module: 'log4j-to-slf4j'. Do you want to exclude it completely from implementation just like 8daf32a?

> Task :eventmesh-connectors:eventmesh-connector-spring:dependencyInsight
org.apache.logging.log4j:log4j-to-slf4j:2.17.1
  Variant compile:
    | Attribute Name                 | Provided | Requested    |
    |--------------------------------|----------|--------------|
    | org.gradle.status              | release  |              |
    | org.gradle.category            | library  | library      |
    | org.gradle.libraryelements     | jar      | classes      |
    | org.gradle.usage               | java-api | java-api     |
    | org.gradle.dependency.bundling |          | external     |
    | org.gradle.jvm.environment     |          | standard-jvm |
    | org.gradle.jvm.version         |          | 8            |

org.apache.logging.log4j:log4j-to-slf4j:2.17.1
\--- org.springframework.boot:spring-boot-starter-logging:2.5.9
     \--- org.springframework.boot:spring-boot-starter:2.5.9
          +--- compileClasspath
          \--- org.springframework.boot:spring-boot-starter-validation:2.5.9

A web-based, searchable dependency report is available by adding the --scan option

[ppkarwasz]

The main problem with fluent logging APIs is that they are considerably slower than the classic API on disabled log statements.

I did some benchmarks last year (cf. apache/logging-log4j2#1203) for the Log4j API. The results for SLF4J must be similar.

Although the difference is in nanoseconds, I would use the classical API when possible.

[Pil0tXia]

@ppkarwasz Sure, I will encapsulate Fluent Logging API and Supplier into LogUtils and use it only when the passed logging parameter includes time-consuming method calls.

[pandaapo]

The main problem with fluent logging APIs is that they are considerably slower than the classic API on disabled log statements.

@Pil0tXia
Since this has been verified by @ppkarwasz as "considerably slow", I don't think it's necessary to consider introducing the Fluent Logging API. I am more in favor of the classic API, even including removing LogUtils.

[Pil0tXia]

@pandaapo I've just wrote a Javadoc:

Compared to the performance gap exhibited by the Fluent Logging API at the billion-per-second level, the overhead of myMethod() is more significant. How do you feel after adding this Javadoc statement?

[pandaapo]

@Pil0tXia
Your LogUtis.debug(log, "xxx{}", () -> myMethod()) will use the Fluent Logging API that is considerably slow compared to the classic API. This may not necessarily bring more benefits than not delaying the execution of myMethod().
Moreover, in most cases, passed myMethod() to the logger API is not time-consuming.

[ppkarwasz]

The main problem with fluent logging APIs is that they are considerably slower than the classic API on disabled log statements.

@Pil0tXia Since this has been verified by @ppkarwasz as "considerably slow", I don't think it's necessary to consider introducing the Fluent Logging API. I am more in favor of the classic API, even including removing LogUtils.

@pandaapo, the fluent API is slower, but you also must compare the order of magnitude:

• by my tests the fluent API is slower than the classic API by an order of 10-100 ns,
• if you call an expensive formatMsg that is a delay by an order of several µs.

So my advice would be: if the classic API has a method, use the classic API. If the classic API lacks a method (like for addArgument(Supplier)) use the fluent API.

[pandaapo]

The main problem with fluent logging APIs is that they are considerably slower than the classic API on disabled log statements.

@Pil0tXia Since this has been verified by @ppkarwasz as "considerably slow", I don't think it's necessary to consider introducing the Fluent Logging API. I am more in favor of the classic API, even including removing LogUtils.

@pandaapo, the fluent API is slower, but you also must compare the order of magnitude:

• by my tests the fluent API is slower than the classic API by an order of 10-100 ns,
• if you call an expensive formatMsg that is a delay by an order of several µs.

So my advice would be: if the classic API has a method, use the classic API. If the classic API lacks a method (like for addArgument(Supplier)) use the fluent API.

@ppkarwasz
My opinion is that formatMsg is not expensive or time-consuming in most cases, so the fluent API may not necessarily bring more benefits than not delaying the execution of formatMsg(). But your suggestion is more scientific than mine: “if the classic API has a method, use the classic API. If the classic API lacks a method (like for addArgument(Supplier)) use the fluent API.”.
I agree with directly using classic API, occasionally using fluent API in specific cases, and removing LogUtils.

[pandaapo]

@Pil0tXia
#4697 (comment), this is the opinion and approach that I agree with. If you still have different opinions, in order to avoid further arguments, let's wait for other developers in the community to express their opinions.

[Pil0tXia]

@pandaapo

I think the encapsulated LogUtils is simpler than the original Fluent Logging API.

LogUtils:

LogUtil.debug(log, "A time-consuming method: {}", () -> myMethod());

The original Fluent Logging API:

log.atDebug().setMessage("A time-consuming method: {}").addArgument(() -> myMethod()).log();

or:

log.atDebug().addArgument(() -> myMethod()).log("A time-consuming method: {}");

[ppkarwasz]

I am still convinced that Log4j API provides the best of both approaches. Using Logger#debug(String, Supplier...) you can write the above example as:

log.debug("A time-consuming method: {}", () -> myMethod());

There is not need for LogUtils nor the fluent API. This is available since Log4j API 2.4, so precedes SLF4J 2.x by several years.

[Pil0tXia]

@ppkarwasz I'd like to write that way however IDEA told me that Unable to resolve method 'debug' in 'Logger':

It seems SLF4J does not support suppliers.

[ppkarwasz]

Yes, SLF4J does not support suppliers in their classic API, but Log4j API does.

If you want to test it for a single class, replace the Lombok @Slf4j annotation with @Log4j2.

[Pil0tXia]

@ppkarwasz I have replaced @Slf4j with @Log4j2 and IDEA is still saying Unable to resolve method 'debug(String, <lambda expression>)':

[ppkarwasz]

Since log is created by Lombok, IDEA probably needs some kind of refresh or rebuild to understand that the type of log changes from org.slf4j.Logger to org.apache.logging.log4j.Logger.

[Pil0tXia]

@ppkarwasz Resolved. A dependency transfer issue.

I think the supplier usage of log4j2 is the most concise one. However, is it necessary for us to replace all the @Slf4j annotations with @Log4j2 and remove the SLF4J dependency from the project? What impact would this have?

[Pil0tXia]

@ppkarwasz I noticed that both Slf4j and Log4j2 don't support void debug(String, Supplier<?>, Throwable);, which means I can't write like this:

        try {
            ......
        } catch (Exception e) {
            log.debug("A time-consuming method: {}", () -> myMethod(), e);
        }

If encapsulation is still needed, I may prefer to continue using Slf4j.

[ppkarwasz]

@Pil0tXia,

In the next release of rewrite-logging-frameworks there will be a recipe to automatically convert from SLF4J to Log4j API. They release every two weeks, so it will be available soon.

Regarding passing a Throwable to Log4j API, the first argument that has no {} placeholder is interpreted as the throwable, so you can write:

        try {
            ......
        } catch (Exception e) {
            log.debug("A time-consuming method: {}", () -> myMethod(), () -> e);
        }

[all the arguments must be Suppliers or none of them]

[Pil0tXia]

@ppkarwasz When rewriting the supplier usage of Log4j2 to Slf4j using rewrite-logging-frameworks, how would the following code be modified?

        try {
            ......
        } catch (Exception e) {
            log.debug("A time-consuming method: {}", () -> myMethod(), () -> e);
        }

[Pil0tXia]

So, to replace some of the following writing:

            if (log.isDebugEnabled()) {
                log.debug("A time-consuming method: {}", myMethod());
            }

we now have three options:

• Continue using Slf4j

  • use Fluent Logging API

  log.atDebug().setMessage("A time-consuming method: {}").addArgument(() -> myMethod()).log();

  log.atDebug().addArgument(() -> myMethod()).log("A time-consuming method: {}");

  Pro: able to remove LogUtils

  Con: not concise; no much value in learning it

  • encapsulate Fluent Logging API in LogUtils

  LogUtil.debug(log, "A time-consuming method: {}", () -> myMethod());

  Pro: able to support customized usage such as adding a Throwable behind suppliers: LogUtil.debug(log, "A time-consuming method: {}", () -> myMethod(), e);

  Con: not the native usage

• Use @Log4j2 instead of @Slf4j

log.debug("A time-consuming method: {}", () -> myMethod());

Pro: concise; able to remove LogUtils; we are using log4j2.xml as config, so the logs printed in the console won't change

Con: If one day we no longer use Log4j2, there may be a need to switch to a different logging artifact.

Which one of these three options is not bad, but for the developer's habit, the writing of "Use @Log4j2 instead of @Slf4j" may be the best; however, if there is resistance to migrating the logging API, we can choose to "encapsulate Fluent Logging API in LogUtils."

@pandaapo Which one do you prefer?

[pandaapo]

So, to replace some of the following writing:

            if (log.isDebugEnabled()) {
                log.debug("A time-consuming method: {}", myMethod());
            }

we now have three options:

• Continue using Slf4j

  • use Fluent Logging API

  log.atDebug().setMessage("A time-consuming method: {}").addArgument(() -> myMethod()).log();

  log.atDebug().addArgument(() -> myMethod()).log("A time-consuming method: {}");

  Pro: able to remove LogUtils
  Con: not concise; no much value in learning it

  • encapsulate Fluent Logging API in LogUtils

  LogUtil.debug(log, "A time-consuming method: {}", () -> myMethod());

  Pro: able to support customized usage such as adding a Throwable behind suppliers: LogUtil.debug(log, "A time-consuming method: {}", () -> myMethod(), e);
  Con: not the native usage

• Use @Log4j2 instead of @Slf4j

log.debug("A time-consuming method: {}", () -> myMethod());

Pro: concise; able to remove LogUtils; we are using log4j2.xml as config, so the logs printed in the console won't change

Con: If one day we no longer use Log4j2, there may be a need to switch to a different logging artifact.

Which one of these three options is not bad, but for the developer's habit, the writing of "Use @Log4j2 instead of @Slf4j" may be the best; however, if there is resistance to migrating the logging API, we can choose to "encapsulate Fluent Logging API in LogUtils."

@pandaapo Which one do you prefer?

@Pil0tXia,

@ppkarwasz prefers to use a purer Log4j API. You prefer to use encapsulated LogUtils that contains Fluent Logging API (SLF4J). I prefer to use SLF4J's native API.

As you said "these three options are not bad", so I sincerely believe that there is still a need for another reviewer to express views on these options.

[ppkarwasz]

@ppkarwasz When rewriting the supplier usage of Log4j2 to Slf4j using rewrite-logging-frameworks, how would the following code be modified?

        try {
            ......
        } catch (Exception e) {
            log.debug("A time-consuming method: {}", () -> myMethod(), () -> e);
        }

Currently rewrite-logging-frameworks doesn't rewrite lambdas (it leaves them as is), but it might in the future, when openrewrite/rewrite-logging-frameworks#127 has been implemented.

Con: If one day we no longer use Log4j2, there may be a need to switch to a different logging artifact.

This is a common misconception about Log4j 2.x: Log4j API and Log4j Core (both developed by the Apache Logging Services team) are separate products (cf. API separation) the same way SLF4J and Logback (both developed by Ceki Gülcü) are separate products.

If you were using the Log4j API, you can:

• switch to Logback by replacing log4j-core with log4j-to-slf4j + logback-classic as runtime dependencies,
• switch to java.util.logging by replacing log4j-core with log4j-to-jul.

These changes do not require changes in the code.

Regarding the advantages of the Log4j API, Remko wrote a nice StackOverflow answer some time ago.

There is also one advantage Remko does not mention: the Log4j API uses the Apache development process. It's easier for the community to suggest changes in the API.

[Pil0tXia]

Regarding whether EventMesh should be programmed against Slf4j or Log4j2 APIs, we need to consider two aspects. On one hand, when EventMesh is used as a client to access a distributed log collection platform, we need to check whether the log collection platform supports EventMesh's log framework. On the other hand, when EventMesh provides an SDK for users, we need to ensure that the provided SDK supports the user's log framework.

Framework Dependency of Log Collection Platforms

The logging services of most cloud service providers directly support underlying implementations such as Log4j2/Logback, skipping the Slf4j API layer:

• https://help.aliyun.com/zh/schedulerx/use-cases/integrate-log-service-with-schedulerx-2-0#p-q5p-s2n-tv3
• https://help.aliyun.com/zh/sls/user-guide/collect-log4j-logs#section-k8v-4tx-n2k
• https://cloud.tencent.com/document/product/614/66244

Except for Google Cloud Functions, which only accepts java.util.logging, Log4j2 needs to use log4j-to-slf4j to route logs to Slf4j and then use JUL from Slf4j as the implementation. This involves an additional layer of abstraction and implementation.

Therefore, for EventMesh as a client accessing a distributed log collection platform, using Log4j2 or Slf4j+Log4j2 is both acceptable.

SDK Provided by EventMesh

Similarly, referring to cloud service providers, most product SDKs depend on Slf4j and allow users to switch underlying implementations to Log4j2/Logback:

• https://help.aliyun.com/zh/tablestore/support/faq-about-the-tablestore-sdk-for-java-logging-framework#section-xp2-ber-hcz
• https://help.aliyun.com/document_detail/151852.html

The advantage of this approach is that users can change the log format of the SDK, unifying it with the log format of their application.

Some SDKs include built-in log implementations, allowing users to print SDK logs without adding log implementation dependencies to the client application:

• https://help.aliyun.com/zh/apsaramq-for-rocketmq/cloud-message-queue-rocketmq-5-x-series/developer-reference/log-configuration#section-gnw-8p1-h6b

There are also a few SDKs that force users to use Slf4j+Log4j2:

• https://docs.aws.amazon.com/lambda/latest/dg/java-logging.html#java-logging-log4j2
• https://docs.aws.amazon.com/sdk-for-java/latest/developer-guide/logging-slf4j.html

Currently, the EventMesh SDK only depends on slf4j-api, and the specific implementation depends on the client application. If the EventMesh SDK uses log4j-api and the client application uses Slf4j+Logback, then the client application needs to additionally include log4j-to-slf4j.

Therefore, I would prefer to retain Slf4j for the SDK.

[Pil0tXia]

I have reviewed all the logs in EventMesh, most of them involve object references, a few of them being string operations. and few time-consuming methods. However, the main drawback of the Fluent Logging API is that, in terms of simplicity, it is not only inferior to LogUtils but even less so than the original usage with isDebugEnabled.

For this section of code in TcpClient:

    if (log.isDebugEnabled()) {
        LogUtils.debug(log, "close tcp client failed.|remote address={}", channel.remoteAddress(), e);
    }

The Fluent Logging API would require the following:

    log.atDebug().setMessage("close tcp client failed.|remote address={}")
        .addArgument(() -> channel.remoteAddress())
        .setCause(e).log();

In terms of both lines of code and readability, it is not as favorable as the former.

However, with LogUtils, you can write it as follows:

    LogUtil.debug(log, "close tcp client failed.|remote address={}", () -> channel.remoteAddress(), e);

@pandaapo The existing issue with LogUtils is excessive wrapping and being too bulky. I would remove LogUtils' wrapping for all slf4j normal usage and redundant isDebugEnabled checks, then retain only the methods with Supplier (lambda expression) parameters. What do you think of this approach?

[pandaapo]

I have reviewed all the logs in EventMesh, most of them involve object references, a few of them being string operations. and few time-consuming methods. However, the main drawback of the Fluent Logging API is that, in terms of simplicity, it is not only inferior to LogUtils but even less so than the original usage with isDebugEnabled.

For this section of code in TcpClient:

    if (log.isDebugEnabled()) {
        LogUtils.debug(log, "close tcp client failed.|remote address={}", channel.remoteAddress(), e);
    }

The Fluent Logging API would require the following:

    log.atDebug().setMessage("close tcp client failed.|remote address={}")
        .addArgument(() -> channel.remoteAddress())
        .setCause(e).log();

In terms of both lines of code and readability, it is not as favorable as the former.

However, with LogUtils, you can write it as follows:

    LogUtil.debug(log, "close tcp client failed.|remote address={}", () -> channel.remoteAddress(), e);

@pandaapo The existing issue with LogUtils is excessive wrapping and being too bulky. I would remove LogUtils' wrapping for all slf4j normal usage and redundant isDebugEnabled checks, then retain only the methods with Supplier (lambda expression) parameters. What do you think of this approach?

@Pil0tXia,

• Use purer Log4j API that supports all functions in the current project, including switching logging frameworks if needed.
• Lightweighting LogUtils's encapsulation for SLF4J to simplify the writing of Lambda expressions and Throwable parameters.
• Use SLF4J's native API.

For these three options, I think we have already clearly explained our respective reasons. In cases where consensus cannot be reached among multiple feasible solutions, I believe there is a need for another reviewer to express views on these three options as I have mentioned several times before.
I am willing to abide by the choice made by the majority in the community (Community Over Code).