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 [EMAIL PROTECTED], priority=5, in group 'main', status:
'MONITOR'
blocks Start Level Event [EMAIL PROTECTED]
waiting for Start Level Event [EMAIL PROTECTED]
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 [EMAIL PROTECTED] daemon, priority=5, in group 'main',
status: 'MONITOR'
blocks ManagedService Update [EMAIL PROTECTED]
waiting for ManagedService Update [EMAIL PROTECTED]
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
_______________________________________________
logback-dev mailing list
[email protected]
http://qos.ch/mailman/listinfo/logback-dev
