JDK-6609468 : (rb) ResourceBundle and/or SimpleDateFormat not thread safe (hangs JVM)
  • Type: Bug
  • Component: core-libs
  • Sub-Component: java.util:i18n
  • Affected Version: 1.4.2,5.0u4,6u7
  • Priority: P2
  • Status: Closed
  • Resolution: Cannot Reproduce
  • OS: solaris_8,solaris_10
  • CPU: x86,sparc
  • Submitted: 2007-09-26
  • Updated: 2010-07-29
  • Resolved: 2009-10-23
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
Other Other Other JDK 6 JDK 7
5.0u21-revFixed 5.0u22-revFixed 5.0u23Fixed 6u17-revFixed 7Resolved
Related Reports
Relates :  
Relates :  
Description
FULL PRODUCT VERSION :
java version "1.4.2_04"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.4.2_04-b05)
Java HotSpot(TM) Client VM (build 1.4.2_04-b05, mixed mode)

ADDITIONAL OS VERSION INFORMATION :
SunOS tsunami 5.8 Generic_108528-23 sun4u sparc SUNW,Sun-Blade-1000
Linux cyclone 2.4.18-3 #1 Thu Apr 18 07:37:53 EDT 2002 i686 unknown


A DESCRIPTION OF THE PROBLEM :
The JVM can be made to hang* if one thread is constructing a SimpleDateFormat object at the same time that another read is making the first call to java.util.logging.Logger.warning().

*by hang, I mean that these two threads sit in wait() calls, but are not deadlocked (according to the JVM deadlock detector).  Any other thread which calls Class.forName() will also hang.

In my particular case, I happen to use a commercial package (jclass) whose jar file contains an [apparently] erroneous MANIFEST file.  So when the JVM is reading this jar file, it calls the java.util.logging API to print messages to the screen saying:
Mar 11, 2004 3:23:40 PM java.util.jar.Attributes read
WARNING: Duplicate name in Manifest: Depends-On

If, during the initialization of the java.util.logging API, a SimpleDateFormat object is constructed (in another thread), the JVM hangs.  You must use "kill -9" to recover from this situation.

Getting this hang to occur is an effort in timing, no doubt affected by the platform on which it runs.  On the solaris box (2.8), it hangs 20% of the time.  On the linux box (2.4.18) it hangs 100% of the time.  I did minimal testing on windows but the test code I have here does not hang on that platform.

STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
If you have access to the JClass 3.6.1 jars, then run the test code provided below.  If not, then get a jar file with a MANIFEST file which contains repeated "Depends-On" tags (I guess, generated by "jar" from JDK 1.2 or older?) so that loading a class from said jar file causes the WARNING to appear.

On my linux box, run "java -classpath .:/path/to/jclass/jcfield361J.jar Hang" to see the bug (it prints a few lines, then hangs forever.  kill -9 to terminate).
  To engage the workaround, run "java -classpath .:/path/to/jclass/jcfield361J.jar Hang not".  See the code for details.

EXPECTED VERSUS ACTUAL BEHAVIOR :
EXPECTED -
It should print some debug, and then the JVM should exit normally.

ACTUAL -
\java -classpath .:/products/installations/cots/java/jclass36J/lib/jcfield361J.jar Hang
Hang Thread 1 awaiting release
Hang Thread 2 awaiting release
Hang Thread 1 Construction starting.
Hang Thread 2 Construction starting.
Hang1 in static initializer
Hang2 in static initializer


(hangs forever at this point, although Ctrl-\ will print stack traces)

ERROR MESSAGES/STACK TRACES THAT OCCUR :
When hung, the stack traces look as follows.  It clearly shows that 2 threads are wait()'ing, both are attempting to initialize ResourceBundle stuff, for different reasons (new SimpleDateFormat(), vs java.util.logging.warning()).

\java -classpath .:/products/installations/cots/java/jclass36J/lib/jcfield361J.jar Hang
Hang Thread 1 awaiting release
Hang Thread 2 awaiting release
Hang Thread 1 Construction starting.
Hang Thread 2 Construction starting.
Hang1 in static initializer
Hang2 in static initializer
Full thread dump Java HotSpot(TM) Client VM (1.4.2_04-b05 mixed mode):

"DestroyJavaVM" prio=1 tid=0x080fc808 nid=0x40a2 waiting on condition [0..bfffb2e4]

"Hang Thread 2" prio=1 tid=0x080fb720 nid=0x40ac in Object.wait() [4cd56000..4cd588c8]
    at java.lang.Object.wait(Native Method)
    - waiting on <0x447664c0> (a sun.misc.SoftCache)
    at java.lang.Object.wait(Object.java:429)
    at java.util.ResourceBundle.findBundle(ResourceBundle.java:862)
    - locked <0x447664c0> (a sun.misc.SoftCache)
    at java.util.ResourceBundle.getBundleImpl(ResourceBundle.java:711)
    at java.util.ResourceBundle.getBundle(ResourceBundle.java:538)
    at sun.text.resources.LocaleData$1.run(LocaleData.java:113)
    at java.security.AccessController.doPrivileged(Native Method)
    at sun.text.resources.LocaleData.getBundle(LocaleData.java:111)
    at sun.text.resources.LocaleData.getDateFormatZoneData(LocaleData.java:107)
    at java.text.DateFormatSymbols.cacheLookup(DateFormatSymbols.java:418)
    at java.text.DateFormatSymbols.initializeData(DateFormatSymbols.java:468)
    at java.text.DateFormatSymbols.<init>(DateFormatSymbols.java:103)
    at java.text.SimpleDateFormat.<init>(SimpleDateFormat.java:472)
    at java.text.DateFormat.get(DateFormat.java:678)
    at java.text.DateFormat.getDateInstance(DateFormat.java:480)
    at java.text.MessageFormat.makeFormat(MessageFormat.java:1374)
    at java.text.MessageFormat.applyPattern(MessageFormat.java:447)
    at java.text.MessageFormat.<init>(MessageFormat.java:347)
    at java.util.logging.SimpleFormatter.format(SimpleFormatter.java:48)
    - locked <0x44781b00> (a java.util.logging.SimpleFormatter)
    at java.util.logging.StreamHandler.publish(StreamHandler.java:178)
    - locked <0x44780e48> (a java.util.logging.ConsoleHandler)
    at java.util.logging.ConsoleHandler.publish(ConsoleHandler.java:87)
    at java.util.logging.Logger.log(Logger.java:424)
    at java.util.logging.Logger.doLog(Logger.java:446)
    at java.util.logging.Logger.log(Logger.java:469)
    at java.util.logging.Logger.warning(Logger.java:968)
    at java.util.jar.Attributes.read(Attributes.java:399)
    at java.util.jar.Manifest.read(Manifest.java:219)
    at java.util.jar.Manifest.<init>(Manifest.java:52)
    at java.util.jar.JarFile.getManifest(JarFile.java:158)
    at sun.misc.URLClassPath$5.getManifest(URLClassPath.java:620)
    at java.net.URLClassLoader.defineClass(URLClassLoader.java:220)
    at java.net.URLClassLoader.access$100(URLClassLoader.java:55)
    at java.net.URLClassLoader$1.run(URLClassLoader.java:194)
    at java.security.AccessController.doPrivileged(Native Method)
    at java.net.URLClassLoader.findClass(URLClassLoader.java:187)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:289)
    - locked <0x4475ae00> (a sun.misc.Launcher$AppClassLoader)
    at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:274)
    - locked <0x4475ae00> (a sun.misc.Launcher$AppClassLoader)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:235)
    at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:302)
    - locked <0x4475ae00> (a sun.misc.Launcher$AppClassLoader)
    at Hang3.<clinit>(Hang3.java:5)
    at Hang2.<clinit>(Hang2.java:4)
    at java.lang.Class.forName0(Native Method)
    at java.lang.Class.forName(Class.java:141)
    at Hang$Runner.run(Hang.java:68)
    at java.lang.Thread.run(Thread.java:534)

"Hang Thread 1" prio=1 tid=0x080fb3c0 nid=0x40ab waiting for monitor entry [4ccd6000..4ccd78c8]
    at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:260)
    - waiting to lock <0x4475ae00> (a sun.misc.Launcher$AppClassLoader)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:235)
    at java.util.ResourceBundle.loadBundle(ResourceBundle.java:1009)
    at java.util.ResourceBundle.findBundle(ResourceBundle.java:884)
    at java.util.ResourceBundle.getBundleImpl(ResourceBundle.java:711)
    at java.util.ResourceBundle.getBundle(ResourceBundle.java:538)
    at sun.text.resources.LocaleData$1.run(LocaleData.java:113)
    at java.security.AccessController.doPrivileged(Native Method)
    at sun.text.resources.LocaleData.getBundle(LocaleData.java:111)
    at sun.text.resources.LocaleData.getDateFormatZoneData(LocaleData.java:107)
    at java.text.DateFormatSymbols.cacheLookup(DateFormatSymbols.java:418)
    at java.text.DateFormatSymbols.initializeData(DateFormatSymbols.java:468)
    at java.text.DateFormatSymbols.<init>(DateFormatSymbols.java:103)
    at java.text.SimpleDateFormat.<init>(SimpleDateFormat.java:442)
    at java.text.SimpleDateFormat.<init>(SimpleDateFormat.java:424)
    at Hang1.<clinit>(Hang1.java:6)
    at java.lang.Class.forName0(Native Method)
    at java.lang.Class.forName(Class.java:141)
    at Hang$Runner.run(Hang.java:68)
    at java.lang.Thread.run(Thread.java:534)

"Signal Dispatcher" daemon prio=1 tid=0x08091678 nid=0x40a8 waiting on condition [0..0]

"Finalizer" daemon prio=1 tid=0x0808bd00 nid=0x40a6 in Object.wait() [4c942000..4c9428c8]
    at java.lang.Object.wait(Native Method)
    - waiting on <0x44740490> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:111)
    - locked <0x44740490> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:127)
    at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=1 tid=0x0808b088 nid=0x40a5 in Object.wait() [4c8c1000..4c8c18c8]
    at java.lang.Object.wait(Native Method)
    - waiting on <0x44740380> (a java.lang.ref.Reference$Lock)
    at java.lang.Object.wait(Object.java:429)
    at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:115)
    - locked <0x44740380> (a java.lang.ref.Reference$Lock)

"VM Thread" prio=1 tid=0x08087e78 nid=0x40a4 runnable

"VM Periodic Task Thread" prio=1 tid=0x08093db8 nid=0x40aa waiting on condition
"Suspend Checker Thread" prio=1 tid=0x08090c08 nid=0x40a7 runnable


REPRODUCIBILITY :
This bug can be reproduced often.

---------- BEGIN SOURCE ----------
Due to the timing sensitiveness of the code, what is pasted here is exactly what ALWAYS hangs on linux.  Attempting to "simply" the test case further resulted in no hangs, so my example code may be more complex than necessary to reproduce the problem.  Apologies for that.  I have 4 files:

File 1:  Hang.java:
import java.text.SimpleDateFormat;

public class Hang
{   
    static Object _syncObject = new Object();
    static Boolean _release = Boolean.FALSE;
    
    public static void main(String args[])
    {
        if (args.length > 0)
        {
            System.out.println("creating SimpleDateFormat to avoid hang...");
            SimpleDateFormat sdf = new SimpleDateFormat("HH:MM:SS");
            System.out.println("done creating SimpleDateFormat to avoid hang.");
        }
        Runnable r1 = new Runner("Hang1");
        Runnable r2 = new Runner("Hang2");
        Thread t1 = new Thread(r1, "Hang Thread 1");
        Thread t2 = new Thread(r2, "Hang Thread 2");
        t1.start();
        t2.start();
        try
        {
            Thread.currentThread().sleep(1000);
        }
        catch (Exception e)
        {
            System.out.println("insomniac?");
        }

        synchronized (_syncObject)
        {
            _release = Boolean.TRUE;
            _syncObject.notifyAll();
        }
    }
    static class Runner implements Runnable
    {
        String _loadMe;

        public Runner(String loadMe)
        {
            _loadMe = loadMe;
        }

        public void run ()
        {
            String threadName = Thread.currentThread().getName();
            synchronized(_syncObject)
            {
                while (_release == Boolean.FALSE)
                {
                    System.out.println(threadName + " awaiting release");
                    try
                    {
                        _syncObject.wait();
                    }
                    catch (Exception e)
                    {
                    }
                }
            }
            Object o = null;
            System.out.println(threadName + " Construction starting.");
            try
            {
                o = Class.forName(_loadMe).newInstance();
            }
            catch (Exception e)
            {
                e.printStackTrace();
            }
            System.out.println(threadName + " Construction complete.");
            System.out.println(threadName + " Constructed:" + o);
        }
    }
}



File 2:  Hang1.java
import java.text.SimpleDateFormat;
    
public class Hang1
{       
    static { System.out.println("Hang1 in static initializer"); };
    static SimpleDateFormat sdf = new SimpleDateFormat("HH:mm:ss");
    static { System.out.println("Hang1 done with static initializer"); };
}           




File 3:  Hang2.java
public class Hang2
{   
    static { System.out.println("Hang2 in static initializer"); };
    public static Hang3 h3 = new Hang3();
    static { System.out.println("Hang2 done with static initializer"); };
}   



File 4: Hang3.java (in this file, if you don't have jclass 3.61, change the import line to substitute a class from a jar file containing a slightly malformed MANIFEST file)

import jclass.field.JCCalendarValidator;

public class Hang3
{   
    public static JCCalendarValidator validator = new JCCalendarValidator();

    public Hang3()
    {
        System.out.println("In Hang3 constructor");
    }
}

---------- END SOURCE ----------

CUSTOMER SUBMITTED WORKAROUND :
In my testing, a valid workaround is to construct a SimpleDateFormat object in the main thread before launching any other threads.  I can't be positive that my workaround fixes it, due to the timing-sensitive nature of the synchronization problem.

Comments
EVALUATION Closing this SubCR for 7 as 'not reproducible'. This was fixed by the fix for 4735126.
23-10-2009

EVALUATION The problem (seen with the attached test case) is not repdoducible, possibly because of the class loader rearchitecture done in JDK7.
06-08-2009

EVALUATION ClassLoader in Hang Thread 2 uses ResourceBundle through Logging. When Hang Thread 1 is loading SimpleDateFormat which calls ResourceBundle which calls the ClassLoader which is locked by Hang Thread 2.
21-07-2009

EVALUATION Is the deadlock symptom reproducible on JDK6? Note that SimpleDateFormat and any java.text.Format subclasses are thread-unsafe. Please refer to their API docs.
21-07-2009