FULL PRODUCT VERSION :
1.6.0:
java version "1.6.0-rc"
Java(TM) SE Runtime Environment (build 1.6.0-rc-b102)
Java HotSpot(TM) Server VM (build 1.6.0-rc-b102, mixed mode)

1.5.0:
java version "1.5.0_08"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_08-b03)
Java HotSpot(TM) Server VM (build 1.5.0_08-b03, mixed mode)

ADDITIONAL OS VERSION INFORMATION :
Linux 2.4.21-40.ELsmp #1 SMP Thu Feb 2 22:22:39 EST 2006 i686 i686 i386 GNU/Linux

Microsoft Windows XP [Version 5.1.2600]


A DESCRIPTION OF THE PROBLEM :
A Mutliple thread application calling Logger.getLogger() and LogManager.addLogger() can cause deadlock in certain situation.

If an application defines a properties for parent logger (e.g. I have a logger called com.sun.Hello, and in the logging properties file I set com.sun.level=FINE), then LogManager.addLogger() will calls Logger.getLogger. Logger.getLogger locks the class and on the other hand, Logger.getLogger actually calls LogManager.addLogger if the Logger requested has not been initialised. This caused the dead lock situation as LogManager.addLogger locks the log manager instance.

STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
1) Compile the class, and create the logging properties as listed in the source code section
2) Run the class

EXPECTED VERSUS ACTUAL BEHAVIOR :
EXPECTED -
It should keep running forever, printing dots
ACTUAL -
It hangs after the first dot



ERROR MESSAGES/STACK TRACES THAT OCCUR :
Full thread dump Java HotSpot(TM) Server VM (1.5.0_08-b03 mixed mode):

"DestroyJavaVM" prio=1 tid=0x850d70c0 nid=0x6aa5 waiting on condition [0x00000000..0xbfffcc60]

"Thread-2" prio=1 tid=0x850d6338 nid=0x6ab4 waiting for monitor entry [0x847d9000..0x847d9670]
        at java.util.logging.LogManager.getLogger(LogManager.java:546)
        - waiting to lock <0xac43ec48> (a java.util.logging.LogManager)
        at java.util.logging.Logger.getLogger(Logger.java:255)
        - locked <0x8575bee0> (a java.lang.Class)
        at TestLoggingDeadLock$GetLogger.run(TestLoggingDeadLock.java:8)
        at java.lang.Thread.run(Thread.java:595)

"Thread-1" prio=1 tid=0x850d5700 nid=0x6ab3 waiting for monitor entry [0x8485a000..0x8485a7f0]
        at java.util.logging.Logger.getLogger(Logger.java:254)
        - waiting to lock <0x8575bee0> (a java.lang.Class)
        at java.util.logging.LogManager.addLogger(LogManager.java:395)
        - locked <0xac43ec48> (a java.util.logging.LogManager)
        at TestLoggingDeadLock$AddLogger.run(TestLoggingDeadLock.java:25)
        at java.lang.Thread.run(Thread.java:595)

"Low Memory Detector" daemon prio=1 tid=0x850a7bd0 nid=0x6ab1 runnable [0x00000000..0x00000000]

"CompilerThread1" daemon prio=1 tid=0x850a6820 nid=0x6ab0 waiting on condition [0x00000000..0x00000000]

"CompilerThread0" daemon prio=1 tid=0x850a58d0 nid=0x6aaf waiting on condition [0x00000000..0x00000000]

"AdapterThread" daemon prio=1 tid=0x850a4940 nid=0x6aae waiting on condition [0x00000000..0x00000000]

"Signal Dispatcher" daemon prio=1 tid=0x850a3b98 nid=0x6aad waiting on condition [0x00000000..0x00000000]

"Finalizer" daemon prio=1 tid=0x8509a488 nid=0x6aac in Object.wait() [0x84efd000..0x84efd670]
        at java.lang.Object.wait(Native Method)
        - waiting on <0xac4106d8> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
        - locked <0xac4106d8> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
        at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=1 tid=0x85099f88 nid=0x6aab in Object.wait() [0x84f7e000..0x84f7e7f0]
        at java.lang.Object.wait(Native Method)
        - waiting on <0xac4105e8> (a java.lang.ref.Reference$Lock)
        at java.lang.Object.wait(Object.java:474)
        at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
        - locked <0xac4105e8> (a java.lang.ref.Reference$Lock)

"VM Thread" prio=1 tid=0x85097ca8 nid=0x6aaa runnable

"GC task thread#0 (ParallelGC)" prio=1 tid=0x08076f40 nid=0x6aa6 runnable

"GC task thread#1 (ParallelGC)" prio=1 tid=0x08077b20 nid=0x6aa7 runnable

"GC task thread#2 (ParallelGC)" prio=1 tid=0x08078700 nid=0x6aa8 runnable

"GC task thread#3 (ParallelGC)" prio=1 tid=0x080792e0 nid=0x6aa9 runnable

"VM Periodic Task Thread" prio=1 tid=0x850a9100 nid=0x6ab2 waiting on condition


Found one Java-level deadlock:
=============================
"Thread-2":
  waiting to lock monitor 0x0807a5cc (object 0xac43ec48, a java.util.logging.LogManager),
  which is held by "Thread-1"
"Thread-1":
  waiting to lock monitor 0x0807a54c (object 0x8575bee0, a java.lang.Class),
  which is held by "Thread-2"

Java stack information for the threads listed above:
===================================================
"Thread-2":
        at java.util.logging.LogManager.getLogger(LogManager.java:546)
        - waiting to lock <0xac43ec48> (a java.util.logging.LogManager)
        at java.util.logging.Logger.getLogger(Logger.java:255)
        - locked <0x8575bee0> (a java.lang.Class)
        at TestLoggingDeadLock$GetLogger.run(TestLoggingDeadLock.java:8)
        at java.lang.Thread.run(Thread.java:595)
"Thread-1":
        at java.util.logging.Logger.getLogger(Logger.java:254)
        - waiting to lock <0x8575bee0> (a java.lang.Class)
        at java.util.logging.LogManager.addLogger(LogManager.java:395)
        - locked <0xac43ec48> (a java.util.logging.LogManager)
        at TestLoggingDeadLock$AddLogger.run(TestLoggingDeadLock.java:25)
        at java.lang.Thread.run(Thread.java:595)

Found 1 deadlock.


REPRODUCIBILITY :
This bug can be reproduced always.

---------- BEGIN SOURCE ----------
import java.util.logging.LogManager;
import java.util.logging.Logger;

public class TestLoggingDeadLock {
public static class GetLogger implements Runnable {
public void run() {
for (;;) {
Logger.getLogger("Hello");
System.out.print(".");
}
}
}

public static class MyLogger extends Logger {
protected MyLogger(String name) {
super(name, null);
}
}

public static class AddLogger implements Runnable {
public void run() {
for (int i=0;;i++) {
Logger addLogger = new MyLogger("com.sun.Hello"+i);
LogManager.getLogManager().addLogger(addLogger);
}
}
}

public static void main(String args[]) throws Exception {
System.setProperty("java.util.logging.config.file","testlogging.properties");
LogManager.getLogManager().readConfiguration();
Thread t1 = new Thread(new AddLogger());
Thread t2 = new Thread(new GetLogger());

t1.start();
t2.start();
}
}

And testlogging.properties file:

com.sun.LEVEL=FINE


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