[LOG4J2-2739] Combination of async logging and log4j-jul results in recursive call warnings

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 2.13.0
• Fix Version/s: 2.13.1
• Assignee: Carter Kozak
• Reporter: Carter Kozak
• Created: 17/Dec/19 13:35
• Updated: 01/Jan/20 19:21
• Resolved: 24/Dec/19 16:11

Description

When disruptor based asynchronous logging is enabled and log4j-jul is configured as the JUL log manager, the "Recursive call to getLogger" line is triggered by jmx initialization.

This can be worked around by disabling jmx using log4j2.disableJmx = true in log4j2.component.properties.

2019-12-17 02:00:56,722 main INFO Registered Log4j as the java.util.logging.LogManager.
2019-12-17 02:00:57,502 main WARN Recursive call to getLogger for javax.management ignored.
2019-12-17 02:00:57,518 main WARN Recursive call to getLogger for javax.management.mbeanserver ignored.
2019-12-17 02:00:57,519 main WARN Recursive call to getLogger for javax.management.mlet ignored.
2019-12-17 02:00:57,519 main WARN Recursive call to getLogger for javax.management.monitor ignored.
2019-12-17 02:00:57,537 main WARN Recursive call to getLogger for javax.management.timer ignored.
2019-12-17 02:00:57,537 main WARN Recursive call to getLogger for javax.management.notification ignored.
2019-12-17 02:00:57,538 main WARN Recursive call to getLogger for javax.management.relation ignored.
2019-12-17 02:00:57,539 main WARN Recursive call to getLogger for javax.management.modelmbean ignored.
2019-12-17 02:00:57,539 main WARN Recursive call to getLogger for javax.management.misc ignored.
2019-12-17 02:00:57,539 main WARN Recursive call to getLogger for javax.management.snmp ignored.
2019-12-17 02:00:57,541 main WARN Recursive call to getLogger for javax.management.snmp.daemon ignored. 

Stack trace of the first instance:

getLogger:92, LogManager (org.apache.logging.log4j.jul) [2]
demandLogger:551, LogManager (java.util.logging)
demandLogger:455, Logger (java.util.logging)
getLogger:502, Logger (java.util.logging)
<init>:55, ClassLogger (com.sun.jmx.remote.util)
<clinit>:365, NotificationBroadcasterSupport (javax.management)
<init>:72, MBeanServerDelegate (javax.management)
<init>:100, MBeanServerDelegateImpl (com.sun.jmx.mbeanserver)
newMBeanServerDelegate:1374, JmxMBeanServer (com.sun.jmx.mbeanserver)
newMBeanServerDelegate:66, MBeanServerBuilder (javax.management)
newMBeanServer:321, MBeanServerFactory (javax.management)
createMBeanServer:231, MBeanServerFactory (javax.management)
createMBeanServer:192, MBeanServerFactory (javax.management)
getPlatformMBeanServer:469, ManagementFactory (java.lang.management)
reregisterMBeansAfterReconfigure:140, Server (org.apache.logging.log4j.core.jmx)
setConfiguration:629, LoggerContext (org.apache.logging.log4j.core)
reconfigure:691, LoggerContext (org.apache.logging.log4j.core)
reconfigure:708, LoggerContext (org.apache.logging.log4j.core)
start:263, LoggerContext (org.apache.logging.log4j.core)
start:76, AsyncLoggerContext (org.apache.logging.log4j.core.async)
getContext:153, Log4jContextFactory (org.apache.logging.log4j.core.impl)
getContext:45, Log4jContextFactory (org.apache.logging.log4j.core.impl)
getContext:194, LogManager (org.apache.logging.log4j)
getContext:138, AbstractLoggerAdapter (org.apache.logging.log4j.spi)
getContext:34, AbstractLoggerAdapter (org.apache.logging.log4j.jul)
getLogger:48, AbstractLoggerAdapter (org.apache.logging.log4j.spi)
getLogger:97, LogManager (org.apache.logging.log4j.jul) [1]
demandLogger:551, LogManager (java.util.logging)
demandLogger:455, Logger (java.util.logging)
getLogger:502, Logger (java.util.logging)
<clinit>:27, FatalExceptionHandler (com.lmax.disruptor)
<init>:8, ExceptionHandlerWrapper (com.lmax.disruptor.dsl)
<init>:65, Disruptor (com.lmax.disruptor.dsl)
<init>:136, Disruptor (com.lmax.disruptor.dsl)
start:102, AsyncLoggerDisruptor (org.apache.logging.log4j.core.async)
maybeStartHelper:97, AsyncLoggerContext (org.apache.logging.log4j.core.async)
start:86, AsyncLoggerContext (org.apache.logging.log4j.core.async)
getContext:207, Log4jContextFactory (org.apache.logging.log4j.core.impl)
initialize:221, Configurator (org.apache.logging.log4j.core.config)
initialize:207, Configurator (org.apache.logging.log4j.core.config)
...

This is a little bit funny because log4j-core asynchronous logging uses disruptor, which internally uses JUL, so startup order can be odd. We may want to consider returning a deferred initializing logger in the recursive case instead of a no-op logger.