United StatesChange Country, Oracle Worldwide Web Sites Communities I am a... I want to...
Bug ID: JDK-6814140 deadlock due to synchronized demandLogger() code that locks ServerLogManager
JDK-6814140 : deadlock due to synchronized demandLogger() code that locks ServerLogManager

Details
Type:
Bug
Submit Date:
2009-03-06
Status:
Resolved
Updated Date:
2011-02-16
Project Name:
JDK
Resolved Date:
2009-05-18
Component:
core-libs
OS:
solaris_10
Sub-Component:
java.util.logging
CPU:
sparc
Priority:
P2
Resolution:
Fixed
Affected Versions:
6u11
Fixed Versions:
6u14-rev (b09)

Related Reports
Backport:
Backport:
Backport:
Backport:
Backport:
Backport:
Backport:
Relates:
Relates:

Sub Tasks

Description
This seems to be a two fault issue (JDK and appserver). It has been verified that the problem starts to happen with JDK 6u11 first. I'm not able to reproduce the issue with 6u10.

Found one Java-level deadlock:
=============================
"Thread-0":
  waiting to lock monitor 0x00c400e0 (object 0xdaad2f30, a com.sun.enterprise.server.logging.ServerLogManager),
  which is held by "pool-1-thread-7"
"pool-1-thread-7":
  waiting to lock monitor 0x000c75a0 (object 0xdb842788, a com.sun.enterprise.loader.EJBClassLoader),
  which is held by "pool-1-thread-3"
"pool-1-thread-3":
  waiting to lock monitor 0x00c400e0 (object 0xdaad2f30, a com.sun.enterprise.server.logging.ServerLogManager),
  which is held by "pool-1-thread-7"

Java stack information for the threads listed above:
===================================================
"Thread-0":
        at java.util.logging.LogManager$Cleaner.run(LogManager.java:208)
        - waiting to lock <0xdaad2f30> (a com.sun.enterprise.server.logging.ServerLogManager)
"pool-1-thread-7":
        at java.lang.ClassLoader.loadClass(ClassLoader.java:296)
        - waiting to lock <0xdb842788> (a com.sun.enterprise.loader.EJBClassLoader)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:252)
        at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1480)
        at java.util.ResourceBundle$Control.newBundle(ResourceBundle.java:2383)
        at java.util.ResourceBundle.loadBundle(ResourceBundle.java:1406)
        at java.util.ResourceBundle.findBundle(ResourceBundle.java:1365)
        at java.util.ResourceBundle.getBundleImpl(ResourceBundle.java:1234)
        at java.util.ResourceBundle.getBundle(ResourceBundle.java:962)
        at java.util.logging.Logger.findResourceBundle(Logger.java:1257)
        - locked <0xd1cd4968> (a java.util.logging.Logger)
        at java.util.logging.Logger.setupResourceInfo(Logger.java:1312)
        - locked <0xd1cd4968> (a java.util.logging.Logger)
        at java.util.logging.Logger.getLogger(Logger.java:312)
        - locked <0xf026cd28> (a java.lang.Class for java.util.logging.Logger)
        at com.sun.enterprise.server.logging.BaseLogManager.doInitializeLogger(BaseLogManager.java:125)
        at com.sun.enterprise.server.logging.BaseLogManager.addLogger(BaseLogManager.java:195)
        - locked <0xdaae06d0> (a java.util.ArrayList)
        at java.util.logging.LogManager.demandLogger(LogManager.java:318)
        - locked <0xdaad2f30> (a com.sun.enterprise.server.logging.ServerLogManager)
        at java.util.logging.Logger.getLogger(Logger.java:309)
        - locked <0xf026cd28> (a java.lang.Class for java.util.logging.Logger)
        at com.sun.faces.util.Util.getLogger(Util.java:241)
        at com.sun.faces.util.Util.<clinit>(Util.java:94)
        at com.sun.faces.config.ConfigureListener.<clinit>(ConfigureListener.java:193)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
        at java.lang.Class.newInstance0(Class.java:355)
        at java.lang.Class.newInstance(Class.java:308)
        at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4576)
        at org.apache.catalina.core.StandardContext.start(StandardContext.java:5312)
        - locked <0xdc70c008> (a com.sun.enterprise.web.WebModule)
        at com.sun.enterprise.web.WebModule.start(WebModule.java:353)
        - locked <0xdc70c008> (a com.sun.enterprise.web.WebModule)
        at com.sun.enterprise.web.LifecycleStarter.doRun(LifecycleStarter.java:58)
        at com.sun.appserv.management.util.misc.RunnableBase.runSync(RunnableBase.java:304)
        at com.sun.appserv.management.util.misc.RunnableBase.run(RunnableBase.java:341)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
        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:619)
"pool-1-thread-3":
        at java.util.logging.LogManager.initializeGlobalHandlers(LogManager.java:887)
        - waiting to lock <0xdaad2f30> (a com.sun.enterprise.server.logging.ServerLogManager)
        at java.util.logging.LogManager.access$900(LogManager.java:129)
        at java.util.logging.LogManager$RootLogger.getHandlers(LogManager.java:1010)
        at java.util.logging.Logger.log(Logger.java:454)
        at org.eclipse.persistence.logging.JavaLog.internalLog(JavaLog.java:290)
        at org.eclipse.persistence.logging.JavaLog.log(JavaLog.java:261)
        at org.eclipse.persistence.internal.sessions.AbstractSession.log(AbstractSession.java:2453)
        at org.eclipse.persistence.internal.sessions.AbstractSession.log(AbstractSession.java:3502)
        at org.eclipse.persistence.internal.sessions.AbstractSession.log(AbstractSession.java:3477)
        at org.eclipse.persistence.internal.sessions.AbstractSession.log(AbstractSession.java:3456)
        at org.eclipse.persistence.internal.sessions.AbstractSession.log(AbstractSession.java:3387)
        at org.eclipse.persistence.internal.weaving.PersistenceWeaver.transform(PersistenceWeaver.java:81)
        at com.sun.enterprise.loader.EJBClassLoader.findClass(EJBClassLoader.java:674)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:307)
        - locked <0xdb842788> (a com.sun.enterprise.loader.EJBClassLoader)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:252)
        at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:320)
        - locked <0xdb842788> (a com.sun.enterprise.loader.EJBClassLoader)
        at java.lang.Class.forName0(Native Method)
        at java.lang.Class.forName(Class.java:247)
        at org.eclipse.persistence.internal.security.PrivilegedAccessHelper.getClassForName(PrivilegedAccessHelper.java:86)
        at org.eclipse.persistence.descriptors.ClassDescriptor.convertClassNamesToClasses(ClassDescriptor.java:956)
        at org.eclipse.persistence.sessions.Project.convertClassNamesToClasses(Project.java:289)
        at org.eclipse.persistence.internal.jpa.EntityManagerSetupImpl.deploy(EntityManagerSetupImpl.java:200)
        - locked <0xdbad1ad8> (a org.eclipse.persistence.sessions.server.ServerSession)
        at org.eclipse.persistence.internal.jpa.EntityManagerFactoryImpl.getServerSession(EntityManagerFactoryImpl.java:69)
        - locked <0xdc27e9e0> (a org.eclipse.persistence.internal.jpa.EntityManagerFactoryImpl)
        at org.eclipse.persistence.internal.jpa.EntityManagerFactoryImpl.createEntityManagerImpl(EntityManagerFactoryImpl.java:118)
        - locked <0xdc27e9e0> (a org.eclipse.persistence.internal.jpa.EntityManagerFactoryImpl)
        at org.eclipse.persistence.internal.jpa.EntityManagerFactoryImpl.createEntityManager(EntityManagerFactoryImpl.java:108)
        at com.sun.enterprise.util.EntityManagerWrapper._getDelegate(EntityManagerWrapper.java:181)
        at com.sun.enterprise.util.EntityManagerWrapper.createNativeQuery(EntityManagerWrapper.java:413)
        at be.ucl.gestionAnEnCours.dao.impl.SecuriteDAO.getAllSigleStructure(SecuriteDAO.java:178)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at com.sun.enterprise.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1011)
        at com.sun.enterprise.security.SecurityUtil.invoke(SecurityUtil.java:175)
        at com.sun.ejb.containers.BaseContainer.invokeTargetBeanMethod(BaseContainer.java:2920)
        at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:4011)
        at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:197)
        at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:83)
        at $Proxy67.getAllSigleStructure(Unknown Source)
        at be.ucl.gestionAnEnCours.domain.service.SecuriteManagerImpl.getAllSigleStructure(SecuriteManagerImpl.java:164)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at com.sun.enterprise.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1011)
        at com.sun.enterprise.security.SecurityUtil.invoke(SecurityUtil.java:175)
        at com.sun.ejb.containers.BaseContainer.invokeTargetBeanMethod(BaseContainer.java:2920)
        at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:4011)
        at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:197)
        at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:83)
        at $Proxy45.getAllSigleStructure(Unknown Source)
        at be.ucl.gestionAnEnCours.plugin.ConfigProgPlugin.init(ConfigProgPlugin.java:48)
        at org.apache.struts.action.ActionServlet.initModulePlugIns(ActionServlet.java:871)
        at org.apache.struts.action.ActionServlet.init(ActionServlet.java:359)
        at javax.servlet.GenericServlet.init(GenericServlet.java:270)
        at org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1194)
        - locked <0xdcfca068> (a org.apache.catalina.core.StandardWrapper)
        at org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:1023)
        - locked <0xdcfca068> (a org.apache.catalina.core.StandardWrapper)
        at org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:4917)
        at org.apache.catalina.core.StandardContext.start(StandardContext.java:5324)
        - locked <0xdc7146e8> (a com.sun.enterprise.web.WebModule)
        at com.sun.enterprise.web.WebModule.start(WebModule.java:353)
        - locked <0xdc7146e8> (a com.sun.enterprise.web.WebModule)
        at com.sun.enterprise.web.LifecycleStarter.doRun(LifecycleStarter.java:58)
        at com.sun.appserv.management.util.misc.RunnableBase.runSync(RunnableBase.java:304)
        at com.sun.appserv.management.util.misc.RunnableBase._submit(RunnableBase.java:176)
        at com.sun.appserv.management.util.misc.RunnableBase.submit(RunnableBase.java:192)
        at com.sun.enterprise.web.VirtualServer.startChildren(VirtualServer.java:1742)
        at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1247)
        - locked <0xdb142e60> (a com.sun.enterprise.web.VirtualServer)
        at org.apache.catalina.core.StandardHost.start(StandardHost.java:971)
        - locked <0xdb142e60> (a com.sun.enterprise.web.VirtualServer)
        at com.sun.enterprise.web.LifecycleStarter.doRun(LifecycleStarter.java:58)
        at com.sun.appserv.management.util.misc.RunnableBase.runSync(RunnableBase.java:304)
        at com.sun.appserv.management.util.misc.RunnableBase.run(RunnableBase.java:341)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
        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:619)

Found 1 deadlock.

                                    

Comments
WORK AROUND

use JDK 6 update release <= 10
                                     
2009-03-06
EVALUATION

Making demandLogger() non-sysnchronized resolves this deadlock.
                                     
2009-05-14
EVALUATION

http://hg.openjdk.java.net/jdk7/tl/jdk/rev/dba7dc47b78e
                                     
2009-07-22



Hardware and Software, Engineered to Work Together