Uploaded image for project: 'logback'
  1. logback
  2. LOGBACK-142

Logback Context is not thread safe, throws java.util.ConcurrentModificationException

    XMLWordPrintable

Details

    • Icon: Bug Bug
    • Resolution: Fixed
    • Icon: Major Major
    • 1.0.10
    • None
    • None
    • None
    • Windows 7 OS, Java 1.6 build 1.6.0_27-b07, Tomcat 7

    Description

      We see the following exception in Status messages for LoggerContext (see attached pic lbClassicStatus.jpg)

      java.util.ConcurrentModificationException
      at java.util.Hashtable$Enumerator.next(Hashtable.java:1031)
      at ch.qos.logback.classic.LoggerContext.syncRemoteView(LoggerContext.java:93)
      at ch.qos.logback.classic.LoggerContext.putProperty(LoggerContext.java:101)
      at ch.qos.logback.core.util.ContextUtil.addHostNameAsProperty(ContextUtil.java:42)
      at ch.qos.logback.classic.joran.action.ConfigurationAction.begin(ConfigurationAction.java:48)
      at ch.qos.logback.core.joran.spi.Interpreter.callBeginAction(Interpreter.java:276)
      at ch.qos.logback.core.joran.spi.Interpreter.startElement(Interpreter.java:148)
      at ch.qos.logback.core.joran.spi.Interpreter.startElement(Interpreter.java:130)
      at ch.qos.logback.core.joran.spi.EventPlayer.play(EventPlayer.java:50)
      at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:147)
      at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:133)
      at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:96)
      at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:55)
      at ch.qos.logback.classic.util.ContextInitializer.configureByResource(ContextInitializer.java:75)
      at com.excilys.ebi.utils.spring.log.logback.LogbackConfigurer.initLogging(LogbackConfigurer.java:90)
      at com.excilys.ebi.utils.spring.log.logback.web.LogbackWebConfigurer.initLogging(LogbackWebConfigurer.java:92)
      at com.excilys.ebi.utils.spring.log.logback.web.LogbackConfigListener.contextInitialized(LogbackConfigListener.java:43)
      at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4723)
      at org.apache.catalina.core.StandardContext$1.call(StandardContext.java:5226)
      at org.apache.catalina.core.StandardContext$1.call(StandardContext.java:5221)
      at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
      at java.util.concurrent.FutureTask.run(FutureTask.java:138)
      at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
      at java.lang.Thread.run(Thread.java:662)

      Our web application set default configuration logback.xml file in the class path so that logback will use it to configure itself during initialization. It is slightly different (only set info level) from the default basic configuration, used in case there is no such file (see attached logback.xml).

      The real logback.xml configuration file is outside of the web application (attached as logback-conf.xml) and we reconfigure logapp to use it with spring integration lib
      https://github.com/excilys/spring-log

      Not sure that the rest of the description will be helpful to troubleshoot the problem, but this is how we reproduce it:

      This is the example code:

      <context-param>
      <param-name>logbackConfigLocation</param-name>
      <param-value>file:${basedir}/conf/logback.xml</param-value>
      </context-param>

      <listener>
      <listener-class>com.excilys.ebi.utils.spring.log.logback.web.LogbackConfigListener</listener-class>
      </listener>

      After spring is loaded LogbackConfigListener class will initialize logback from the given location and reset the logger context.

      Code snip from LogbackConfigListener init logging below:

      public static void initLogging(String location) throws FileNotFoundException, JoranException

      { String resolvedLocation = SystemPropertyUtils.resolvePlaceholders(location); URL url = ResourceUtils.getURL(resolvedLocation); ContextSelector selector = ContextSelectorStaticBinder.getSingleton().getContextSelector(); LoggerContext loggerContext = selector.getLoggerContext(); // in the current version logback automatically configures at startup // the context, so we have to reset it loggerContext.reset(); ContextInitializer contextInitializer = new ContextInitializer(loggerContext); contextInitializer.configureByResource(url); // reset JUL // don't forget to configure the LevelChangePropagator contextListener // in the config file!!! SLF4JBridgeHandler.install(); }

      We sometimes receive concurrency modification exception from the logback core code. We never observe this issue if we remove default logback file from the class path as initial configuration.
      To prevent this exception we also delay logback configuration loading.

      Thank you,
      Svetla

      Attachments

        1. lbClassicStatus.jpg
          1015 kB
          Svetla Arnaudova
        2. logback.xml
          0.5 kB
          Svetla Arnaudova
        3. logback-conf.xml.xml
          2 kB
          Svetla Arnaudova

        Activity

          People

            ceki Ceki Gülcü
            svetla.arnaudova Svetla Arnaudova
            Votes:
            6 Vote for this issue
            Watchers:
            8 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: