[logback-dev] [JIRA] Created: (LBCLASSIC-81) Deadlock while configuring at runtime and requesting a new logger

Holger Mense (JIRA) noreply-jira at qos.ch
Tue Nov 4 14:51:21 CET 2008

Deadlock while configuring at runtime and requesting a new logger

                 Key: LBCLASSIC-81
                 URL: http://jira.qos.ch/browse/LBCLASSIC-81
             Project: logback-classic
          Issue Type: Bug
          Components: joran
    Affects Versions: 0.9.11
         Environment: Windows XP
Sun JDK 1.5.0_15
Logback 0.9.11
            Reporter: Holger Mense
            Assignee: Logback dev list
            Priority: Critical

In a multithreaded environment a request of a logger instance can led to a deadlock, when another thread tries to apply a new configuration.

In GenericConfigurator.doConfigure(InputSource):97 a lock is set on a Context instance. Then the new configuration will be applied. During this, a lock on the logger is required. When now a new logger instance is requested by LoggerFactory, LoggerContext.getLogger(String) is called. The operation sets a lock on the root logger to create a new child logger. At the end the method LoggerContext.incSize() is called to increase the number of entries in the loggerCache. This method is declared as "synchronized" and needs a lock on LoggerContext.

Requesting a new logger instance while starting a reconfiguration of logback leds to a deadlock. LoggerContext.incSize() waits for a lock of the context (which is locked by GenericConfigurator), while waiting for lock of logger in Logger.setLevel() - which is locked by LoggerContext.

For further information, see the thread dump:

ManagedService Update Queue at 5, priority=5, in group 'main', status: 'MONITOR'
             blocks Start Level Event Dispatcher at 6
             waiting for Start Level Event Dispatcher at 6
              at ch.qos.logback.classic.Logger.setLevel(Logger.java:188)
              at ch.qos.logback.classic.joran.action.LoggerAction.begin(LoggerAction.java:63)
              at ch.qos.logback.core.joran.spi.Interpreter.callBeginAction(Interpreter.java:262)
              at ch.qos.logback.core.joran.spi.Interpreter.startElement(Interpreter.java:136)
              at ch.qos.logback.core.joran.spi.Interpreter.startElement(Interpreter.java:118)
              at ch.qos.logback.core.joran.spi.EventPlayer.play(EventPlayer.java:36)
              at ch.qos.logback.core.joran.spi.Interpreter.play(Interpreter.java:321)
              at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:98)
              at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:74)
              at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:55)
              at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:48)

Start Level Event Dispatcher at 6 daemon, priority=5, in group 'main', status: 'MONITOR'
             blocks ManagedService Update Queue at 5
             waiting for ManagedService Update Queue at 5
              at ch.qos.logback.classic.LoggerContext.incSize(LoggerContext.java:153)
              at ch.qos.logback.classic.LoggerContext.getLogger(LoggerContext.java:142)
              at ch.qos.logback.classic.LoggerContext.getLogger(LoggerContext.java:46)
              at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:161)
              at org.slf4j.bridge.SLF4JBridgeHandler.getSLF4JLogger(SLF4JBridgeHandler.java:149)
              at org.slf4j.bridge.SLF4JBridgeHandler.publish(SLF4JBridgeHandler.java:234)
              at java.util.logging.Logger.log(Logger.java:452)
              at java.util.logging.Logger.doLog(Logger.java:474)
              at java.util.logging.Logger.log(Logger.java:497)
              at java.util.logging.Logger.info(Logger.java:1.016)

A quick fix is to set a lock on the LoggerContext in LoggerContext.getLogger(String). I am not sure, if this is the best solution, but it seems to work.

This message is automatically generated by JIRA.
If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira


More information about the logback-dev mailing list