-
Bug
-
Resolution: Unresolved
-
P3
-
7u21, 8
-
linux
FULL PRODUCT VERSION :
java version "1.7.0_21"
Java(TM) SE Runtime Environment (build 1.7.0_21-b11)
Java HotSpot(TM) 64-Bit Server VM (build 23.21-b01, mixed mode)
ADDITIONAL OS VERSION INFORMATION :
Linux hsrs12.aoa.twosigma.com 3.4.21-ts1 #13 SMP Wed Feb 13 21:40:57 GMT 2013 x86_64 GNU/Linux
A DESCRIPTION OF THE PROBLEM :
This is very similar to http://bugs.sun.com/view_bug.do?bug_id=6977677 in that our "RUNNABLE" thread is also stuck waiting to lock the LogManager instance 'manager' after having locked a class that our BLOCKED thread is waiting for but after having already locked the 'manager' object, except via a different code path and the class lock is on sun.util.logging.PlatformLogger in our case instead of java.util.logging.L
ogger as it is in this linked bug report).
In our case, our "RUNNABLE" thread is stuck in LogManager.getLogManager() instead (of in Logger.getLogger) waiting to lock the LogManager instance 'manager' but after having locked the sun.util.logging.PlatformLogger class instead (of the java.util.logging.Logger class), which our BLOCKED thread is waiting after having also locked the 'manager' object.
Our "RUNNABLE" thread got to LogManager.getLogManager() ultimately from <clinit> of HttpURLConnection, an internal sun class that spools up a PlatformLogger, also an internal sun class, which eventually redirects to a LogManager managed logger).
Here are our two threads with the relevant stack traces:
::::::::::::::
Thread-1
::::::::::::::
"Thread-1" daemon prio=10 tid=0x00002b266c819000 nid=0x83e8 in Object.wait() [0x00002b266ad3e000]
java.lang.Thread.State: RUNNABLE
at java.util.logging.LogManager.getLogManager(LogManager.java:267)
at java.util.logging.Logger.getPlatformLogger(Logger.java:423)
at java.util.logging.LoggingProxyImpl.getLogger(LoggingProxyImpl.java:41)
at sun.util.logging.LoggingSupport.getLogger(LoggingSupport.java:100)
at sun.util.logging.PlatformLogger$JavaLogger.<init>(PlatformLogger.java:497)
at sun.util.logging.PlatformLogger$JavaLogger.<init>(PlatformLogger.java:492)
at sun.util.logging.PlatformLogger.<init>(PlatformLogger.java:164)
at sun.util.logging.PlatformLogger.getLogger(PlatformLogger.java:128)
- locked <0x0000000610fa4c40> (a java.lang.Class for sun.util.logging.PlatformLogger)
at sun.net.www.protocol.http.HttpURLConnection.<clinit>(HttpURLConnection.java:372)
at sun.net.www.protocol.http.Handler.openConnection(Handler.java:62)
at sun.net.www.protocol.http.Handler.openConnection(Handler.java:57)
at java.net.URL.openConnection(URL.java:971)
...
::::::::::::::
Thread-2
::::::::::::::
"Thread-2" prio=10 tid=0x00000000022dd000 nid=0x834b waiting for monitor entry [0x00002b2619446000]
java.lang.Thread.State: BLOCKED (on object monitor)
at sun.util.logging.PlatformLogger.redirectPlatformLoggers(PlatformLogger.java:139)
- waiting to lock <0x0000000610fa4c40> (a java.lang.Class for sun.util.logging.PlatformLogger)
at java.util.logging.LogManager$2.run(LogManager.java:291)
at java.util.logging.LogManager$2.run(LogManager.java:286)
at java.security.AccessController.doPrivileged(Native Method)
at java.util.logging.LogManager.readPrimordialConfiguration(LogManager.java:286)
- locked <0x00000006118c1648> (a java.util.logging.LogManager)
at java.util.logging.LogManager.getLogManager(LogManager.java:268)
at java.util.logging.Logger.<init>(Logger.java:252)
...
STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
This is hard to reproduce since it's a race condition. I tried to write a minimal class that I could try to get to hang, but wasn't successful (i.e. it always completed w/o hanging), as follows (but hopefully you get the idea):
cat << EOF > TestJavaUtilLoggingDeadlock.java
import java.util.logging.LogManager;
import java.util.logging.Logger;
import sun.net.www.protocol.http.HttpURLConnection;
public class TestJavaUtilLoggingDeadlock {
public static void main(String[] args) {
int iterations = Integer.valueOf(args[0]);
for (int i = 0; i < iterations; i++) {
System.out.println("Iteration: " + i);
Thread t1 = new Thread("Lock-PlatformLogger-first") {
@Override
public void run() {
HttpURLConnection.getHttpLogger();
}
};
Thread t2 = new Thread("Lock-LogManager-first") {
@Override
public void run() {
//LogManager.getLogManager();
Logger.getLogger("blah");
}
};
t1.start();
t2.start();
}
System.out.println("Done.");
}
}
EOF
javac -XDignore.symbol.file TestJavaUtilLoggingDeadlock.java
java TestJavaUtilLoggingDeadlock 1000000 > /tmp/test.out &
for run in {1..100}; do jstack $! > stack.$run; done &
REPRODUCIBILITY :
This bug can be reproduced occasionally.
CUSTOMER SUBMITTED WORKAROUND :
Just rerun and often the race condition doesn't occur during the rerun.
java version "1.7.0_21"
Java(TM) SE Runtime Environment (build 1.7.0_21-b11)
Java HotSpot(TM) 64-Bit Server VM (build 23.21-b01, mixed mode)
ADDITIONAL OS VERSION INFORMATION :
Linux hsrs12.aoa.twosigma.com 3.4.21-ts1 #13 SMP Wed Feb 13 21:40:57 GMT 2013 x86_64 GNU/Linux
A DESCRIPTION OF THE PROBLEM :
This is very similar to http://bugs.sun.com/view_bug.do?bug_id=6977677 in that our "RUNNABLE" thread is also stuck waiting to lock the LogManager instance 'manager' after having locked a class that our BLOCKED thread is waiting for but after having already locked the 'manager' object, except via a different code path and the class lock is on sun.util.logging.PlatformLogger in our case instead of java.util.logging.L
ogger as it is in this linked bug report).
In our case, our "RUNNABLE" thread is stuck in LogManager.getLogManager() instead (of in Logger.getLogger) waiting to lock the LogManager instance 'manager' but after having locked the sun.util.logging.PlatformLogger class instead (of the java.util.logging.Logger class), which our BLOCKED thread is waiting after having also locked the 'manager' object.
Our "RUNNABLE" thread got to LogManager.getLogManager() ultimately from <clinit> of HttpURLConnection, an internal sun class that spools up a PlatformLogger, also an internal sun class, which eventually redirects to a LogManager managed logger).
Here are our two threads with the relevant stack traces:
::::::::::::::
Thread-1
::::::::::::::
"Thread-1" daemon prio=10 tid=0x00002b266c819000 nid=0x83e8 in Object.wait() [0x00002b266ad3e000]
java.lang.Thread.State: RUNNABLE
at java.util.logging.LogManager.getLogManager(LogManager.java:267)
at java.util.logging.Logger.getPlatformLogger(Logger.java:423)
at java.util.logging.LoggingProxyImpl.getLogger(LoggingProxyImpl.java:41)
at sun.util.logging.LoggingSupport.getLogger(LoggingSupport.java:100)
at sun.util.logging.PlatformLogger$JavaLogger.<init>(PlatformLogger.java:497)
at sun.util.logging.PlatformLogger$JavaLogger.<init>(PlatformLogger.java:492)
at sun.util.logging.PlatformLogger.<init>(PlatformLogger.java:164)
at sun.util.logging.PlatformLogger.getLogger(PlatformLogger.java:128)
- locked <0x0000000610fa4c40> (a java.lang.Class for sun.util.logging.PlatformLogger)
at sun.net.www.protocol.http.HttpURLConnection.<clinit>(HttpURLConnection.java:372)
at sun.net.www.protocol.http.Handler.openConnection(Handler.java:62)
at sun.net.www.protocol.http.Handler.openConnection(Handler.java:57)
at java.net.URL.openConnection(URL.java:971)
...
::::::::::::::
Thread-2
::::::::::::::
"Thread-2" prio=10 tid=0x00000000022dd000 nid=0x834b waiting for monitor entry [0x00002b2619446000]
java.lang.Thread.State: BLOCKED (on object monitor)
at sun.util.logging.PlatformLogger.redirectPlatformLoggers(PlatformLogger.java:139)
- waiting to lock <0x0000000610fa4c40> (a java.lang.Class for sun.util.logging.PlatformLogger)
at java.util.logging.LogManager$2.run(LogManager.java:291)
at java.util.logging.LogManager$2.run(LogManager.java:286)
at java.security.AccessController.doPrivileged(Native Method)
at java.util.logging.LogManager.readPrimordialConfiguration(LogManager.java:286)
- locked <0x00000006118c1648> (a java.util.logging.LogManager)
at java.util.logging.LogManager.getLogManager(LogManager.java:268)
at java.util.logging.Logger.<init>(Logger.java:252)
...
STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
This is hard to reproduce since it's a race condition. I tried to write a minimal class that I could try to get to hang, but wasn't successful (i.e. it always completed w/o hanging), as follows (but hopefully you get the idea):
cat << EOF > TestJavaUtilLoggingDeadlock.java
import java.util.logging.LogManager;
import java.util.logging.Logger;
import sun.net.www.protocol.http.HttpURLConnection;
public class TestJavaUtilLoggingDeadlock {
public static void main(String[] args) {
int iterations = Integer.valueOf(args[0]);
for (int i = 0; i < iterations; i++) {
System.out.println("Iteration: " + i);
Thread t1 = new Thread("Lock-PlatformLogger-first") {
@Override
public void run() {
HttpURLConnection.getHttpLogger();
}
};
Thread t2 = new Thread("Lock-LogManager-first") {
@Override
public void run() {
//LogManager.getLogManager();
Logger.getLogger("blah");
}
};
t1.start();
t2.start();
}
System.out.println("Done.");
}
}
EOF
javac -XDignore.symbol.file TestJavaUtilLoggingDeadlock.java
java TestJavaUtilLoggingDeadlock 1000000 > /tmp/test.out &
for run in {1..100}; do jstack $! > stack.$run; done &
REPRODUCIBILITY :
This bug can be reproduced occasionally.
CUSTOMER SUBMITTED WORKAROUND :
Just rerun and often the race condition doesn't occur during the rerun.
- relates to
-
JDK-8299060 Server deadlock due to JDK 8 java.util.logging (JUL)
-
- Open
-