2.24.0 status logger warns about message factory mismatch

[arlampin]

Description

After updating to 2.24.0 from 2.23.1, the status logger logs the following warning:

2024-09-09T12:14:29.525247Z main WARN The Logger eu.lampinen.log4j2test.Test was created with the message factory org.apache.logging.log4j.message.ReusableMessageFactory@3d680b5a and is now requested with a null message factory (defaults to org.apache.logging.log4j.message.ParameterizedMessageFactory), which may create log events with unexpected formatting.

The whole sample code is below

import org.apache.logging.log4j.LogManager;

public class Test {

    static {
        System.setProperty("log4j2.statusLoggerLevel", "WARN");
    }

    public static void main(String[] args) {
        LogManager.getLogger(Test.class).error("Hello {}", "world!");
        LogManager.getLogger(Test.class).error("Hello {}", "world!");
    }

}

I think this is caused by a mismatch between

• AbstractLogger.checkMessageFactory, which uses constant DEFAULT_MESSAGE_FACTORY_CLASS
• Logger.getEffectiveMessageFactory, which uses either ReusableMessageFactory or ParameterizedMessageFactory depending on Constants.ENABLE_THREADLOCALS.

Setting log4j2.enable.threadlocals=false will disable the warning.

Configuration

Version: 2.24.0

JDK: Azul 21

Logs

2.23.1

ERROR - Hello world!
ERROR - Hello world!

2.24.0

ERROR - Hello world!
2024-09-09T12:16:29.792995Z main WARN The Logger eu.lampinen.log4j2test.Test was created with the message factory org.apache.logging.log4j.message.ReusableMessageFactory@49d904ec and is now requested with a null message factory (defaults to org.apache.logging.log4j.message.ParameterizedMessageFactory), which may create log events with unexpected formatting.
ERROR - Hello world!

Reproduction

See above

[vy]

@arlampin, thanks so much for the report and the analysis, much appreciated! 🙇 I will take care of this issue and make sure that it is fixed with the upcoming 2.24.1, which we expect to release in ~2 weeks.

[lauredogit]

Hello,

We also upgraded from 2.23.1 to 2.24.0 and have the same warning.

Unfortunately, this is not just a warning and a false-positive as with 2.6.0, this actually leads to logs having the wrong formattings...

[vy]

@lauredogit, thanks for the feedback.

1. Would you mind providing us a minimal example (i.e., Main.java, pom.xml, and log4j2.xml) that we can reproduce your problem, please?
2. Could you see if Implement MessageFactory-namespaced logger registry #2936 fixes your problem, please? (See BUILDING.adoc for details. In short, you need to checkout the feature/2.x/deprecate-AL-checkMF branch, run ./mvnw install -DskipTests using a JDK 17, and use the produced 2.25.0-SNAPSHOT in your code.)

[lauredogit]

This happening in environments with some load.

The exact message is:

WARN The Logger xxx.yyy.zzz was created with the message factory org.apache.logging.log4j.message.ReusableMessageFactory@1e9e6edf and is now requested with a null message factory (defaults to org.apache.logging.log4j.message.ParameterizedMessageFactory), which may create log events with unexpected formatting.

I could not reproduce it locally at this stage.

We are still investigating.

This is a Web application (single Web application in its application server), with hundreds of log files in different formats.

With 2.24.0, some formats are randomly mixed up (e.g. JSON logs are in plain text format).

Most of our loggers are obtained with

private static final Logger LOG = LogManager.getLogger(SomeClass.class);

Some are obtained via

static final Logger LOG = LogManager.getContext(SomeClass.class.getClassLoader(), false).getLogger("some.package.some.id");

We do have a custom org.apache.logging.log4j.core.layout.AbstractStringLayout for our JSON logs.

Logs were fine with 2.23.0 and 2.23.1 (for months in production under heavy load).

I'll post more when we have more information or a reproducer.

[lauredogit]

As far as I can see at the moment, our issue seems to come from the new usage of org.apache.logging.log4j.core.impl.MementoMessage.

We should be able to fix that at our end (TBC).

[lauredogit]

Ok, we assumed wrongly in our custom Layout that we would always receive ObjectMessage instances.

With 2.24.0, we are now getting MementoMessage instances, hence our issue.

We will fix our custom Layout and the issue will be gone for us.

We will also not presume anymore that we will obtain given Message types and only use the contract in the Message interface.

The warning could well be a false-positive as in 2.6...

[vy]

If I understand it correctly you have a custom JSON-producing layout. Would you mind sharing why using JsonTemplateLayout is not an option for you? Op vr 13 sep 2024 om 17:44 schreef lauredogit ***@***.***>

…

Ok, we assumed *wrongly* in our custom Layout that we would always receive *ObjectMessage* instances. With 2.24.0, we are now getting *MementoMessage* instances, hence our issue. We will fix our custom Layout and the issue will be gone for us. We will also not presume anymore that we will obtain given Message types and only use the contract in the *Message* interface. The warning could well be a false-positive as in 2.6... — Reply to this email directly, view it on GitHub <#2933 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAARTSNDUZBNDJTNTM66CQ3ZWMB5HAVCNFSM6AAAAABN4N2KROVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDGNBZGI2TINZXGE> . You are receiving this because you were assigned.Message ID: ***@***.***>