[concurrency-interest] deadlock in java.util.logging

Gregg Wonderly gregg at cytetech.com
Mon Sep 25 18:12:34 EDT 2006


I've encountered a deadlocking situation in java.util.logging where a thread has 
asserted a lock on a classloader which is logging some progress information. 
The java.util.logging.ConsoleHandler is at issue.  Below are the associated 
stack traces.

It seems to me that the primary issue is that StreamHandler.publish() method is 
synchronized.  It seems to me that only the doneHeader stuff is really at issue 
here.  If that section becomes the only synchronized(this) section, and writer 
is declared as volatile (to cover the setOutputStream() path to modification 
from another thread), would publish still be thread safe?

I'd like to find a solution to this and submit a bug report ASAP.

Gregg Wonderly

Java stack information for the threads listed above:
===================================================
"task":
         at java.util.logging.StreamHandler.publish(StreamHandler.java:174)
         - waiting to lock <0x1f6babc0> (a java.util.logging.ConsoleHandler)
         at java.util.logging.ConsoleHandler.publish(ConsoleHandler.java:88)
         at java.util.logging.Logger.log(Logger.java:428)
         at java.util.logging.Logger.doLog(Logger.java:450)
         at java.util.logging.Logger.log(Logger.java:473)
         at java.util.logging.Logger.fine(Logger.java:1024)
         at
net.jini.loader.pref.PreferredClassLoader.isPreferredResource(PreferredClassLoader.java:750)
         at
org.wonderly.jini2.browse.JiniDeskTop$12.isPreferredResource(JiniDeskTop.java:920)
         at
net.jini.loader.pref.PreferredClassLoader.loadClass(PreferredClassLoader.java:924)
         - locked <0x1f7484d8> (a org.wonderly.jini2.browse.JiniDeskTop$12)
         at org.wonderly.jini2.browse.JiniDeskTop$12.loadClass(JiniDeskTop.java:933)
         at java.lang.ClassLoader.loadClass(ClassLoader.java:299)
         - locked <0x1f87a3a0> (a net.jini.loader.pref.PreferredClassLoader)
         at
net.jini.loader.pref.PreferredClassLoader.loadClass(PreferredClassLoader.java:942)
         - locked <0x1f87a3a0> (a net.jini.loader.pref.PreferredClassLoader)
         at java.lang.ClassLoader.loadClass(ClassLoader.java:251)
         at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:319)
         - locked <0x1f87a3a0> (a net.jini.loader.pref.PreferredClassLoader)
         at com.sun.jini.reggie.$Proxy2.getConstraints(Unknown Source)
         at
com.sun.jini.proxy.ConstrainableProxyUtil.verifyConsistentConstraints(ConstrainableProxyUtil.java:184)
         at
com.sun.jini.reggie.ConstrainableRegistrarProxy.readObject(ConstrainableRegistrarProxy.java:146)
         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:585)
         at java.io.ObjectStreamClass.invokeReadObject(ObjectStreamClass.java:946)
         at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1818)
         at
java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1718)
         at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1304)
         at java.io.ObjectInputStream.readObject(ObjectInputStream.java:349)
         at net.jini.io.MarshalledInstance.get(MarshalledInstance.java:402)
         at
com.sun.jini.discovery.DiscoveryV1.doUnicastDiscovery(DiscoveryV1.java:397)
         at net.jini.discovery.LookupDiscovery$10.run(LookupDiscovery.java:3327)
         at java.security.AccessController.doPrivileged(Native Method)
         at
net.jini.discovery.LookupDiscovery.doUnicastDiscovery(LookupDiscovery.java:3324)
         at net.jini.discovery.LookupDiscovery.access$3900(LookupDiscovery.java:696)
         at
net.jini.discovery.LookupDiscovery$UnicastDiscoveryTask$1.performDiscovery(LookupDiscovery.java:1763)
         at
com.sun.jini.discovery.internal.MultiIPDiscovery.getSingleResponse(MultiIPDiscovery.java:152)
         at
com.sun.jini.discovery.internal.MultiIPDiscovery.getResponse(MultiIPDiscovery.java:83)
         at
net.jini.discovery.LookupDiscovery$UnicastDiscoveryTask.run(LookupDiscovery.java:1756)
         at
net.jini.discovery.LookupDiscovery$DecodeAnnouncementTask.run(LookupDiscovery.java:1599)
         at com.sun.jini.thread.TaskManager$TaskThread.run(TaskManager.java:331)
"task":
         at
net.jini.loader.pref.PreferredClassLoader.loadClass(PreferredClassLoader.java:920)
         - waiting to lock <0x1f7484d8> (a org.wonderly.jini2.browse.JiniDeskTop$12)
         at org.wonderly.jini2.browse.JiniDeskTop$12.loadClass(JiniDeskTop.java:933)
         at java.lang.ClassLoader.loadClass(ClassLoader.java:299)
         - locked <0x1f879270> (a net.jini.loader.pref.PreferredClassLoader)
         at
net.jini.loader.pref.PreferredClassLoader.loadClass(PreferredClassLoader.java:942)
         - locked <0x1f879270> (a net.jini.loader.pref.PreferredClassLoader)
         at java.lang.ClassLoader.loadClass(ClassLoader.java:251)
         at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:319)
         - locked <0x1f879270> (a net.jini.loader.pref.PreferredClassLoader)
         at com.sun.jini.reggie.RegistrarProxy.toString(RegistrarProxy.java:448)
         at java.lang.String.valueOf(String.java:2615)
         at java.lang.StringBuilder.append(StringBuilder.java:116)
         at
com.sun.jini.discovery.UnicastResponse.toString(UnicastResponse.java:118)
         at java.text.MessageFormat.subformat(MessageFormat.java:1237)
         at java.text.MessageFormat.format(MessageFormat.java:828)
         at java.text.Format.format(Format.java:133)
         at java.text.MessageFormat.format(MessageFormat.java:804)
         at java.util.logging.Formatter.formatMessage(Formatter.java:130)
         - locked <0x1f6ccc30> (a com.cytetech.log.StreamFormatter)
         at com.cytetech.log.StreamFormatter.format(StreamFormatter.java:127)
         at java.util.logging.StreamHandler.publish(StreamHandler.java:179)
         - locked <0x1f6babc0> (a java.util.logging.ConsoleHandler)
         at java.util.logging.ConsoleHandler.publish(ConsoleHandler.java:88)
         at java.util.logging.Logger.log(Logger.java:428)
         at java.util.logging.Logger.doLog(Logger.java:450)
         at java.util.logging.Logger.log(Logger.java:514)
         at
com.sun.jini.discovery.DiscoveryV1.doUnicastDiscovery(DiscoveryV1.java:414)
         at net.jini.discovery.LookupDiscovery$10.run(LookupDiscovery.java:3327)
         at java.security.AccessController.doPrivileged(Native Method)
         at
net.jini.discovery.LookupDiscovery.doUnicastDiscovery(LookupDiscovery.java:3324)
         at
net.jini.discovery.LookupDiscovery.doUnicastDiscovery(LookupDiscovery.java:3355)
         at net.jini.discovery.LookupDiscovery.access$3700(LookupDiscovery.java:696)
         at
net.jini.discovery.LookupDiscovery$UnicastDiscoveryTask.run(LookupDiscovery.java:1744)
         at com.sun.jini.thread.TaskManager$TaskThread.run(TaskManager.java:331)


More information about the Concurrency-interest mailing list