Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

when I update log4j2's version to 2.24.2,I get a error #3284

Open
SweetWuXiaoMei opened this issue Dec 12, 2024 · 8 comments
Open

when I update log4j2's version to 2.24.2,I get a error #3284

SweetWuXiaoMei opened this issue Dec 12, 2024 · 8 comments

Comments

@SweetWuXiaoMei
Copy link

This is the log link:https://github.com/apache/servicecomb-java-chassis/actions/runs/12290867484/job/34298772628?pr=4640#step:5:4557
You can drag the page to the bottom。
the main error:

Error:  org.apache.servicecomb.core.invocation.timeout.PassingTimeStrategyTest.should_init_when_start_as_first_node_of_a_process_but_not_first_of_a_chain -- Time elapsed: 0.001 s <<< ERROR!
java.lang.NoClassDefFoundError: Could not initialize class org.apache.servicecomb.core.tracing.TraceIdLogger
	at org.apache.servicecomb.core.Invocation.<init>(Invocation.java:107)
	at org.apache.servicecomb.core.invocation.timeout.PassingTimeStrategyTest.should_init_when_start_as_first_node_of_a_process_but_not_first_of_a_chain(PassingTimeStrategyTest.java:37)
	at java.base/java.lang.reflect.Method.invoke(Method.java:569)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
Caused by: java.lang.ExceptionInInitializerError: Exception java.lang.NullPointerException [in thread "main"]
	at org.apache.logging.log4j.core.util.internal.InternalLoggerRegistry.computeIfAbsent(InternalLoggerRegistry.java:151)
	at org.apache.logging.log4j.core.LoggerContext.getLogger(LoggerContext.java:530)
	at org.apache.logging.log4j.core.LoggerContext.getLogger(LoggerContext.java:503)
	at org.apache.logging.log4j.core.LoggerContext.getLogger(LoggerContext.java:65)
	at org.apache.logging.slf4j.Log4jLoggerFactory.newLogger(Log4jLoggerFactory.java:49)
	at org.apache.logging.slf4j.Log4jLoggerFactory.newLogger(Log4jLoggerFactory.java:32)
	at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getLogger(AbstractLoggerAdapter.java:52)
	at org.apache.logging.slf4j.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:32)
	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:363)
	at org.apache.servicecomb.core.tracing.TraceIdLogger.<clinit>(TraceIdLogger.java:26)
	at org.apache.servicecomb.core.Invocation.init(Invocation.java:131)
	at org.apache.servicecomb.core.Invocation.<init>(Invocation.java:123)
	at org.apache.servicecomb.core.TestInvocation.traceId_producerCreateTraceId(TestInvocation.java:209)

the main code:

public class TraceIdLogger {
  private static final Logger LOGGER = LoggerFactory.getLogger("scb-trace-id");

  private static final Marker MARKER = new ScbMarker();

  public static final String KEY_TRACE_ID = "SERVICECOMB_TRACE_ID";

  private final Invocation invocation;

  public TraceIdLogger(Invocation invocation) {
    this.invocation = invocation;
  }

  public Invocation getInvocation() {
    return invocation;
  }

  public static String constructSource(String source) {
    return "[" + source + "(" +
        Thread.currentThread().getStackTrace()[2].getLineNumber() + ")]";
  }

  public final String getName() {
    return invocation.getTraceId();
  }

  public void error(String format, Object... arguments) {
    MDC.put(KEY_TRACE_ID, getName());
    LOGGER.error(MARKER, format, arguments);
    MDC.remove(KEY_TRACE_ID);
  }

  public void warn(String format, Object... arguments) {
    MDC.put(KEY_TRACE_ID, getName());
    LOGGER.warn(MARKER, format, arguments);
    MDC.remove(KEY_TRACE_ID);
  }

  public void info(String format, Object... arguments) {
    MDC.put(KEY_TRACE_ID, getName());
    LOGGER.info(MARKER, format, arguments);
    MDC.remove(KEY_TRACE_ID);
  }

  public void debug(String format, Object... arguments) {
    MDC.put(KEY_TRACE_ID, getName());
    LOGGER.debug(MARKER, format, arguments);
    MDC.remove(KEY_TRACE_ID);
  }
}

the log4j.xml:

<Configuration status="INFO">
    <Appenders>
        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="[%d][%t][%p][%c:%L] %m%n" />
        </Console>
    </Appenders>
    <Loggers>
        <Root level="INFO">
            <AppenderRef ref="Console" />
        </Root>
    </Loggers>
</Configuration>

It seems that getLogger execution failed

@ppkarwasz
Copy link
Contributor

@SweetWuXiaoMei,

The NPE seems to be caused by JMockit. JMockit instruments all the objects involved in your test run (including the "global" Log4j Core objects and their fields). This is the reason why Map.computeIfAbsent() returns null in your test run. Normally this function never returns null (of course, unless the mappingFunction argument returns null, which is not the case here).

I don't have experience with the JMockit agent, so I cannot tell you if the behavior is expected (I doubt it) or is the result of a bug. You should probably reach out to the JMockit dev team.

@SweetWuXiaoMei
Copy link
Author

// See if the logger is created by another thread in the meantime
            final Map<String, WeakReference<Logger>> loggerRefByName =
                    loggerRefByNameByMessageFactory.computeIfAbsent(messageFactory, ignored -> new HashMap<>());
            WeakReference<Logger> loggerRef = loggerRefByName.get(name);
            if (loggerRef != null && (logger = loggerRef.get()) != null) {
                return logger;
            }

This code snippet looks like a bug.If it is created for the first time, the loggerRefByName variable is null.
Because loggerRefByNameByMessageFactory.computeIfAbsent will return null. I can fix this bug if needed.

@SweetWuXiaoMei
Copy link
Author

this code snip from log4j2 version 2.24.2

@SweetWuXiaoMei
Copy link
Author

SweetWuXiaoMei commented Dec 19, 2024

version 2.24.1 is :

public Logger getLogger(final String name, final MessageFactory messageFactory) {
    MessageFactory effectiveMessageFactory = messageFactory != null ? messageFactory : DEFAULT_MESSAGE_FACTORY;
    Logger oldLogger = (Logger)this.loggerRegistry.getLogger(name, effectiveMessageFactory);
    if (oldLogger != null) {
      return oldLogger;
    } else {
      Logger newLogger = this.newInstance(name, effectiveMessageFactory);
      this.loggerRegistry.putIfAbsent(name, effectiveMessageFactory, newLogger);
      return (Logger)this.loggerRegistry.getLogger(name, effectiveMessageFactory);
    }
  }

version 2.24.2 is:

public Logger computeIfAbsent(
            final String name,
            final MessageFactory messageFactory,
            final BiFunction<String, MessageFactory, Logger> loggerSupplier) {

        // Check arguments
        requireNonNull(name, "name");
        requireNonNull(messageFactory, "messageFactory");
        requireNonNull(loggerSupplier, "loggerSupplier");

        // Read lock fast path: See if logger already exists
        @Nullable Logger logger = getLogger(name, messageFactory);
        if (logger != null) {
            return logger;
        }

        // Write lock slow path: Insert the logger
        writeLock.lock();
        try {

            // See if the logger is created by another thread in the meantime
            final Map<String, WeakReference<Logger>> loggerRefByName =
                    loggerRefByNameByMessageFactory.computeIfAbsent(messageFactory, ignored -> new HashMap<>());
            WeakReference<Logger> loggerRef = loggerRefByName.get(name);
            if (loggerRef != null && (logger = loggerRef.get()) != null) {
                return logger;
            }

            // Create the logger
            logger = loggerSupplier.apply(name, messageFactory);

            // Report name and message factory mismatch if there are any
            final String loggerName = logger.getName();
            final MessageFactory loggerMessageFactory = logger.getMessageFactory();
            if (!loggerMessageFactory.equals(messageFactory)) {
                StatusLogger.getLogger()
                        .error(
                                "Newly registered logger with name `{}` and message factory `{}`, is requested to be associated with a different name `{}` or message factory `{}`.\n"
                                        + "Effectively the message factory of the logger will be used and the other one will be ignored.\n"
                                        + "This generally hints a problem at the logger context implementation.\n"
                                        + "Please report this using the Log4j project issue tracker.",
                                loggerName,
                                loggerMessageFactory,
                                name,
                                messageFactory);
                // Register logger under alternative keys
                loggerRefByNameByMessageFactory
                        .computeIfAbsent(loggerMessageFactory, ignored -> new HashMap<>())
                        .putIfAbsent(loggerName, new WeakReference<>(logger));
            }

            // Insert the logger
            loggerRefByName.put(name, new WeakReference<>(logger));
            return logger;
        } finally {
            writeLock.unlock();
        }
    }

@ppkarwasz
Copy link
Contributor

@SweetWuXiaoMei,

// See if the logger is created by another thread in the meantime
final Map<String, WeakReference<Logger>> loggerRefByName =
loggerRefByNameByMessageFactory.computeIfAbsent(messageFactory, ignored -> new HashMap<>());
WeakReference<Logger> loggerRef = loggerRefByName.get(name);
if (loggerRef != null && (logger = loggerRef.get()) != null) {
return logger;
}

This code snippet looks like a bug.If it is created for the first time, the loggerRefByName variable is null. Because loggerRefByNameByMessageFactory.computeIfAbsent will return null. I can fix this bug if needed.

You are probably confusing Map.putIfAbsent() with Map.computeIfAbsent():

  • putIfAbsent() returns the previous value associated to a given key, so it can return null.
  • computeIfAbsent() returns the current value associated to a given key (existing or computed). It can only return null if the lambda returns null. Since () -> new HashMap<>() never returns null, neither does computeIfAbsent().

The reason why null is returned in your test case is that your are mocking the loggerRefByNameByMessageFactory map using JMockit. Every method of a mocked object usually returns null and I confirmed that this is your case by running your ServiceComb test in a debugger.

I have no experience with JMockit, so I don't know how to configure it to leave the Log4j classes alone. You should probably ask the JMockit developers directly.

@SweetWuXiaoMei
Copy link
Author

image

I’m not sure why it’s not showing the proxy object here. However, it definitely doesn’t enter the map’s computeIfAbsent method. Could you teach me how to check if it’s being proxied? Thank you.

@ppkarwasz
Copy link
Contributor

I’m not sure why it’s not showing the proxy object here. However, it definitely doesn’t enter the map’s computeIfAbsent method. Could you teach me how to check if it’s being proxied? Thank you.

JMockit does not create proxy objects, but it instruments (modifies) the classes that are loaded by the JVM. So the objects are instances of the same classes as declared, but the bytecode of the classes is modified.

You can see in the debugger that Map.computeIfAbsent() is redirected to mockit.internal.expectations.mocking.MockedBridge.invoke(), which ends up returning null. This is probably a bug in JMockito, try reporting it there. Since Map.computeIfAbsent() is a default method, my guess is that JMockito fails to support default methods.

@SweetWuXiaoMei
Copy link
Author

Sure, thank you for your answer. I will report the issue to the JMockit development team. However, right now I want to understand how I can know if a class has been modified by bytecode instrumentation. I want to learn how you would go about doing this. In Intellij, there is no indication that the bytecode has been modified.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants