NPE in org.apache.logging.log4j.core.async.RingBufferLogEventHandler4.notifyCallback()

[verjan-isencia]

Description

When using BasicAsyncLoggerContextSelector in log4j2 v2.24.3, when logging RingBufferLogEventHandler4.notifyCallback() is called, and it tries to use an instance variable sequenceCallback that is not set. I am using disruptor v3.4.4.202406060700, because according to the manifest file of log4j2-core, the accepted range of versions of disruptor is from 3.4 to 4 (excluded).

But it appears to me that the RingBufferLogEventHandler4 implementation is conceived for disruptor 4. There is a method defined to set the value of sequenceCallback:

/*
* Overrides a method from Disruptor 4.x. Do not remove.
*/

public void setSequenceCallback(final Sequence sequenceCallback) {
    this.sequenceCallback = sequenceCallback;
}

So I suspect this code is actually meant to work with disruptor 4. I am working in an OSGI environment, so the version range in the Manifest file is used to determine which version of disruptor to use. Adding disruptor v4.0.xx does not work as the build tool looks for packages with a version less then 4.

Configuration

Version: 2.24.3 (in combination with disruptor v3.4.4.202406060700)
Application Platform: OSGI
Operating system: Windows 11
JDK: OpenJDK 17

Logs

AsyncLogger error handling event seq=238, value='org.apache.logging.log4j.core.async.RingBufferLogEvent@6c16f29d': java.lang.NullPointerException: Cannot invoke "com.lmax.disruptor.Sequence.set(long)" because "this.sequenceCallback" is null
java.lang.NullPointerException: Cannot invoke "com.lmax.disruptor.Sequence.set(long)" because "this.sequenceCallback" is null
	at org.apache.logging.log4j.core.async.RingBufferLogEventHandler4.notifyCallback(RingBufferLogEventHandler4.java:67)
	at org.apache.logging.log4j.core.async.RingBufferLogEventHandler4.onEvent(RingBufferLogEventHandler4.java:61)
	at org.apache.logging.log4j.core.async.RingBufferLogEventHandler4.onEvent(RingBufferLogEventHandler4.java:31)
	at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:168)
	at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
	at java.base/java.lang.Thread.run(Thread.java:833)

Reproduction

I suppose it will occur whenever using BasicAsyncLoggerContextSelector in log4j2 v2.24.3 combined with a disruptor version less then 4.

[ppkarwasz]

Hi @verjan-isencia,

Thank you for reporting this issue.

This appears to be a composite problem caused by two factors:

1. In version 2.23.0, we introduced support for Disruptor 4, while still maintaining compatibility with Disruptor 3—the last major version that supports our Java 8 baseline. However, the tool we use to generate the OSGi manifest assumes by default that only one major version of each dependency is supported. As a result, we forgot to explicitly override this and set the supported version range for Disruptor to [3.4,5). This will be corrected in Fixes OSGi descriptor to accept Disruptor 4 #3707.

2. To work around breaking changes in Disruptor 4, we use reflection to load the appropriate class for the detected version:
   

   logging-log4j2/log4j-core/src/main/java/org/apache/logging/log4j/core/async/DisruptorUtil.java

   Lines 53 to 54 in 49cdf74

   	static final int DISRUPTOR_MAJOR_VERSION =
   	LoaderUtil.isClassAvailable("com.lmax.disruptor.SequenceReportingEventHandler") ? 3 : 4;

   Unfortunately, this detection fails in your environment and incorrectly identifies your Disruptor version as 4.x. We have not been able to reproduce this issue in our PAX Exam 4 tests with either Equinox or Felix.

Could you please provide more details about your OSGi environment? A minimal reproducible example would be especially helpful.

[verjan-isencia]

I have been debugging the problem in our OSGI platform, and the problem seems to be with the classloader used at the moment the static variable in DisruptorUtil is initialized:

    static final int DISRUPTOR_MAJOR_VERSION =
            LoaderUtil.isClassAvailable("com.lmax.disruptor.SequenceReportingEventHandler") ? 3 : 4;

Inside LoaderUtil, the classloader is chosen with which to call Class.forName("com.lmax.disruptor.SequenceReportingEventHandler") and it ends up using the ThreadContextClassLoader. Problem is that in our case that happens to be the org.apache.aries.cdi.container.internal.loader.BundleClassLoader (because we need support for CDI at some point in the application), and that classloader does not appear to see any classes of the disruptor bundle.

The problem would be fixed using the bundle classloader of the disruptor bundle (f.e. com.lmax.disruptor.EventHandler.class.getClassLoader()). If not, I suppose I could try to find a way to get the version initialized earlier in the startup process.

[jvz]

Also noticing that SequenceReportingEventHandler appears to also be available in Disruptor version 3.4.4. Otherwise, the general patch here for DisruptorUtil looks something like:

    static final int DISRUPTOR_MAJOR_VERSION = calculateDisruptorMajorVersion();

    static int calculateDisruptorMajorVersion() {
        final ClassLoader classLoader = EventHandler.class.getClassLoader();
        try {
            Class.forName("com.lmax.disruptor.SequenceReportingEventHandler", true, classLoader);
            return 4;
        } catch (final ClassNotFoundException | LinkageError e) {
            return 3;
        }
    }