glassfish
  1. glassfish
  2. GLASSFISH-20784

Deadlock in loggers due to parallel startup of services

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Critical Critical
    • Resolution: Fixed
    • Affects Version/s: 4.1
    • Fix Version/s: 4.1
    • Component/s: hk2, logging
    • Labels:
      None

      Description

      See the deadlock below. We were not seeing it earlier, because services were starting in a single thread, but HK2 team have enabled parallel startup of services and that's causing this deadlock. You may like to talk to HK2 team to disable parallel startup feature in glassfish for now.

      Found one Java-level deadlock:
      =============================
      "RunLevelControllerThread-1377679090695":
      waiting to lock monitor 0x82e187dc (object 0xb12e1030, a java.util.logging.LogManager$LoggerContext),
      which is held by "RunLevelControllerThread-1377679090692"
      "RunLevelControllerThread-1377679090692":
      waiting to lock monitor 0x805034b4 (object 0xb12e0000, a java.util.logging.LogManager),
      which is held by "RunLevelControllerThread-1377679090695"

      Java stack information for the threads listed above:
      ===================================================
      "RunLevelControllerThread-1377679090695":
      at java.util.logging.LogManager$LoggerContext.findLogger(LogManager.java:489)

      • waiting to lock <0xb12e1030> (a java.util.logging.LogManager$LoggerContext)
        at java.util.logging.LogManager.setLevelsOnExistingLoggers(LogManager.java:1356)
      • locked <0xb12e0000> (a java.util.logging.LogManager)
        at java.util.logging.LogManager.readConfiguration(LogManager.java:1115)
        at java.util.logging.LogManager.readConfiguration(LogManager.java:988)
        at com.sun.enterprise.server.logging.LogManagerService.postConstruct(LogManagerService.java:288)
        at org.jvnet.hk2.internal.ClazzCreator.postConstructMe(ClazzCreator.java:298)
        at org.jvnet.hk2.internal.ClazzCreator.create(ClazzCreator.java:345)
        at org.jvnet.hk2.internal.SystemDescriptor.create(SystemDescriptor.java:454)
        at org.glassfish.hk2.runlevel.internal.AsyncRunLevelContext.findOrCreate(AsyncRunLevelContext.java:184)
        at org.jvnet.hk2.internal.Utilities.createService(Utilities.java:2296)
        at org.jvnet.hk2.internal.ServiceHandleImpl.getService(ServiceHandleImpl.java:98)
      • locked <0xaa383cf8> (a java.lang.Object)
        at org.jvnet.hk2.internal.ServiceHandleImpl.getService(ServiceHandleImpl.java:87)
        at org.glassfish.hk2.runlevel.internal.CurrentTaskFuture$QueueRunner.oneJob(CurrentTaskFuture.java:947)
        at org.glassfish.hk2.runlevel.internal.CurrentTaskFuture$QueueRunner.run(CurrentTaskFuture.java:932)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:722)
        "RunLevelControllerThread-1377679090692":
        at java.util.logging.LogManager.drainLoggerRefQueueBounded(LogManager.java:811)
      • waiting to lock <0xb12e0000> (a java.util.logging.LogManager)
        at java.util.logging.LogManager$LoggerContext.addLocalLogger(LogManager.java:511)
      • locked <0xb12e1030> (a java.util.logging.LogManager$LoggerContext)
        at java.util.logging.LogManager.addLogger(LogManager.java:848)
        at java.util.logging.LogManager.demandLogger(LogManager.java:405)
        at java.util.logging.Logger.demandLogger(Logger.java:317)
        at java.util.logging.Logger.getLogger(Logger.java:408)
        at com.sun.enterprise.naming.util.LogFacade.<clinit>(LogFacade.java:55)
        at com.sun.enterprise.naming.impl.SerialInitContextFactory.getInitialContext(SerialInitContextFactory.java:155)
        at javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:684)
        at javax.naming.InitialContext.getDefaultInitCtx(InitialContext.java:307)
        at javax.naming.InitialContext.init(InitialContext.java:242)
        at javax.naming.InitialContext.<init>(InitialContext.java:192)
        at com.sun.enterprise.naming.impl.GlassfishNamingManagerImpl.<init>(GlassfishNamingManagerImpl.java:122)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:525)
        at org.glassfish.hk2.utilities.reflection.ReflectionHelper.makeMe(ReflectionHelper.java:1092)
        at org.jvnet.hk2.internal.ClazzCreator.createMe(ClazzCreator.java:261)
        at org.jvnet.hk2.internal.ClazzCreator.create(ClazzCreator.java:336)
        at org.jvnet.hk2.internal.SystemDescriptor.create(SystemDescriptor.java:454)
        at org.jvnet.hk2.internal.SingletonContext.findOrCreate(SingletonContext.java:119)
        at org.jvnet.hk2.internal.Utilities.createService(Utilities.java:2296)
        at org.jvnet.hk2.internal.ServiceLocatorImpl.getService(ServiceLocatorImpl.java:590)
        at org.jvnet.hk2.internal.IterableProviderImpl.get(IterableProviderImpl.java:88)
        at org.glassfish.kernel.javaee.MEJBService.postConstruct(MEJBService.java:82)
        at org.jvnet.hk2.internal.ClazzCreator.postConstructMe(ClazzCreator.java:298)
        at org.jvnet.hk2.internal.ClazzCreator.create(ClazzCreator.java:345)
        at org.jvnet.hk2.internal.SystemDescriptor.create(SystemDescriptor.java:454)
        at org.glassfish.hk2.runlevel.internal.AsyncRunLevelContext.findOrCreate(AsyncRunLevelContext.java:184)
        at org.jvnet.hk2.internal.Utilities.createService(Utilities.java:2296)
        at org.jvnet.hk2.internal.ServiceHandleImpl.getService(ServiceHandleImpl.java:98)
      • locked <0xaa383dc8> (a java.lang.Object)
        at org.jvnet.hk2.internal.ServiceHandleImpl.getService(ServiceHandleImpl.java:87)
        at org.glassfish.hk2.runlevel.internal.CurrentTaskFuture$QueueRunner.oneJob(CurrentTaskFuture.java:947)
        at org.glassfish.hk2.runlevel.internal.CurrentTaskFuture$QueueRunner.run(CurrentTaskFuture.java:932)
        at org.glassfish.hk2.runlevel.internal.CurrentTaskFuture$UpOneJob.run(CurrentTaskFuture.java:678)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:722)

      Found 1 deadlock.

        Issue Links

          Activity

          Hide
          Joe Di Pol added a comment -

          A couple of logging deadlocks were fixed in JDK7u60, so this problem may go away under JDK7u60 (or JDK8) or newer.

          Show
          Joe Di Pol added a comment - A couple of logging deadlocks were fixed in JDK7u60, so this problem may go away under JDK7u60 (or JDK8) or newer.
          Hide
          sandeep.shrivastava added a comment -

          This is a JDK issue that has been already reported in https://bugs.openjdk.java.net/browse/JDK-8010939

          The fix is available in JDK7u60 and later as Joe noted.

          Show
          sandeep.shrivastava added a comment - This is a JDK issue that has been already reported in https://bugs.openjdk.java.net/browse/JDK-8010939 The fix is available in JDK7u60 and later as Joe noted.

            People

            • Assignee:
              sandeep.shrivastava
              Reporter:
              Sanjeeb Sahoo
            • Votes:
              1 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: