Java Solaris Communities Sun Store Join SDN My Profile Why Join?
 
Bug Database
Bug Detail
Quick Lists
Top 25 Bugs
Top 25 RFE's
Recently Closed Bugs
Printable Page Printable Page


Bug Database
Bug ID: 6814140
Votes 0
Synopsis deadlock due to synchronized demandLogger() code that locks ServerLogManager
Category java:classes_util_logging
Reported Against
Release Fixed 6u14-rev(b09), 5.0u19-rev(b03) (Bug ID:2177860) , 5.0u20-rev(b03) (Bug ID:2179652) , 6u15-rev(b04) (Bug ID:2179964)
State 10-Fix Delivered, bug
Priority: 2-High
Related Bugs 6487638 , 6813411
Submit Date 06-MAR-2009
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 ( customer  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 ( customer  0xdb842788, a com.sun.enterprise.loader.EJBClassLoader),
  which is held by "pool-1-thread-3"
"pool-1-thread-3":
  waiting to lock monitor 0x00c400e0 ( customer  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. customer .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. customer .catalina.core.StandardContext.listenerStart(StandardContext.java:4576)
        at org. customer .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. customer .logging.JavaLog.internalLog(JavaLog.java:290)
        at org.eclipse. customer .logging.JavaLog.log(JavaLog.java:261)
        at org.eclipse. customer .internal.sessions.AbstractSession.log(AbstractSession.java:2453)
        at org.eclipse. customer .internal.sessions.AbstractSession.log(AbstractSession.java:3502)
        at org.eclipse. customer .internal.sessions.AbstractSession.log(AbstractSession.java:3477)
        at org.eclipse. customer .internal.sessions.AbstractSession.log(AbstractSession.java:3456)
        at org.eclipse. customer .internal.sessions.AbstractSession.log(AbstractSession.java:3387)
        at org.eclipse. customer .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. customer .internal.security.PrivilegedAccessHelper.getClassForName(PrivilegedAccessHelper.java:86)
        at org.eclipse. customer .descriptors.ClassDescriptor.convertClassNamesToClasses(ClassDescriptor.java:956)
        at org.eclipse. customer .sessions.Project.convertClassNamesToClasses(Project.java:289)
        at org.eclipse. customer .internal.jpa.EntityManagerSetupImpl.deploy(EntityManagerSetupImpl.java:200)
        - locked <0xdbad1ad8> (a org.eclipse. customer .sessions.server.ServerSession)
        at org.eclipse. customer .internal.jpa.EntityManagerFactoryImpl.getServerSession(EntityManagerFactoryImpl.java:69)
        - locked <0xdc27e9e0> (a org.eclipse. customer .internal.jpa.EntityManagerFactoryImpl)
        at org.eclipse. customer .internal.jpa.EntityManagerFactoryImpl.createEntityManagerImpl(EntityManagerFactoryImpl.java:118)
        - locked <0xdc27e9e0> (a org.eclipse. customer .internal.jpa.EntityManagerFactoryImpl)
        at org.eclipse. customer .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. customer .struts.action.ActionServlet.initModulePlugIns(ActionServlet.java:871)
        at org. customer .struts.action.ActionServlet.init(ActionServlet.java:359)
        at javax.servlet.GenericServlet.init(GenericServlet.java:270)
        at org. customer .catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1194)
        - locked <0xdcfca068> (a org. customer .catalina.core.StandardWrapper)
        at org. customer .catalina.core.StandardWrapper.load(StandardWrapper.java:1023)
        - locked <0xdcfca068> (a org. customer .catalina.core.StandardWrapper)
        at org. customer .catalina.core.StandardContext.loadOnStartup(StandardContext.java:4917)
        at org. customer .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. customer .catalina.core.ContainerBase.start(ContainerBase.java:1247)
        - locked <0xdb142e60> (a com.sun.enterprise.web.VirtualServer)
        at org. customer .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.
Posted Date : 2009-03-06 11:18:00.0
Work Around
use JDK 6 update release <= 10
Evaluation
Making demandLogger() non-sysnchronized resolves this deadlock.
Posted Date : 2009-05-14 10:12:57.0

http://hg.openjdk.java.net/jdk7/tl/jdk/rev/dba7dc47b78e
Posted Date : 2009-07-22 22:08:30.0
Comments
  
  Include a link with my name & email   

Submitted On 15-NOV-2009
DavidJWelch
In IBM Operating Systems for mainframes,  a Kernel service called ENQ/DEQ existed, and all processes requested queue locks and shares Simultaneously! If you can't manage that, always request your resources in the same order, and free them in the same order!
- An old IBM Systems dude.


Submitted On 15-NOV-2009
DavidJWelch
You should not have closed this bug, a similar one will bite you in the future!

See previous comment



PLEASE NOTE: JDK6 is formerly known as Project Mustang