-
Bug
-
Resolution: Duplicate
-
P3
-
None
-
6u20
-
x86
-
solaris_2.5.1
FULL PRODUCT VERSION :
java version "1.6.0_18"
Java(TM) SE Runtime Environment (build 1.6.0_18-b07)
Java HotSpot(TM) Server VM (build 16.0-b13, mixed mode)
ADDITIONAL OS VERSION INFORMATION :
Linux hostname 2.6.9-42.EL.vision.1smp #1 SMP Tue Feb 3 09:56:18 EST 2009 i686 i686 i386 GNU/Linux
and
Linux hostname 2.6.18-164.el5PAE #1 SMP Tue Aug 18 15:59:11 EDT 2009 i686 i686 i386 GNU/Linux
EXTRA RELEVANT SYSTEM CONFIGURATION :
Both machines have more than one core.
A DESCRIPTION OF THE PROBLEM :
When multiple threads are logging at the same time, the getLogger() function eventually returns a different logger than the one initialized when it was called the first time. All the configuration done on the first logger is then lost.
The problem started appearing in 1.6.0_18. I validated that it still exists in 1.6.0_20 and that it wasn't in 1.6.0_17.
STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
I did this test class to reproduce the problem.
It should exit when the reference to the initial logger is lost.
I noticed that it crashes much quickly when the function initRootLogger() is called. It usually takes 1 to 2 seconds to exit with an error. When initRootLogger() isn't called, it can take a couple of seconds to a couple of minutes.
package loggertester;
import java.util.logging.*;
public class LoggerTester {
public static String LOGGER = "tester";
public void initRootLogger() {
Logger.getLogger("").getHandlers();
Logger rootLogger = Logger.getLogger("");
rootLogger.setLevel(Level.INFO);
Handler[] handlers = rootLogger.getHandlers();
for (Handler handler : handlers) {
handler.setLevel(Level.INFO);
}
}
public void start() {
String initialLogger = Logger.getLogger(LOGGER).toString();
while (true) {
if (!initialLogger.equals(Logger.getLogger(LOGGER).toString())) {
System.out.println("Logger changed from " + initialLogger + " to " + Logger.getLogger(LOGGER));
System.exit(-1);
}
Logger.getLogger(LOGGER).fine("LoggerTester log");
}
}
public static void main(String[] args) {
LoggerTester tester = new LoggerTester();
tester.initRootLogger();
Thread thread = new Thread() {
@Override
public void run() {
while (true) {
Logger.getLogger(LOGGER).fine("Thread log");
}
}
};
System.out.println("Starting logger loops");
thread.start();
tester.start();
}
}
EXPECTED VERSUS ACTUAL BEHAVIOR :
EXPECTED -
The program should never exit as the logger returned by getLogger() should always be the same.
ACTUAL -
The program returns saying that the logger changed in the course of the execution.
REPRODUCIBILITY :
This bug can be reproduced always.
CUSTOMER SUBMITTED WORKAROUND :
1.6.0_17 works as expected.
Release Regression From : 6u17
The above release value was the last known release where this
bug was not reproducible. Since then there has been a regression.
java version "1.6.0_18"
Java(TM) SE Runtime Environment (build 1.6.0_18-b07)
Java HotSpot(TM) Server VM (build 16.0-b13, mixed mode)
ADDITIONAL OS VERSION INFORMATION :
Linux hostname 2.6.9-42.EL.vision.1smp #1 SMP Tue Feb 3 09:56:18 EST 2009 i686 i686 i386 GNU/Linux
and
Linux hostname 2.6.18-164.el5PAE #1 SMP Tue Aug 18 15:59:11 EDT 2009 i686 i686 i386 GNU/Linux
EXTRA RELEVANT SYSTEM CONFIGURATION :
Both machines have more than one core.
A DESCRIPTION OF THE PROBLEM :
When multiple threads are logging at the same time, the getLogger() function eventually returns a different logger than the one initialized when it was called the first time. All the configuration done on the first logger is then lost.
The problem started appearing in 1.6.0_18. I validated that it still exists in 1.6.0_20 and that it wasn't in 1.6.0_17.
STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
I did this test class to reproduce the problem.
It should exit when the reference to the initial logger is lost.
I noticed that it crashes much quickly when the function initRootLogger() is called. It usually takes 1 to 2 seconds to exit with an error. When initRootLogger() isn't called, it can take a couple of seconds to a couple of minutes.
package loggertester;
import java.util.logging.*;
public class LoggerTester {
public static String LOGGER = "tester";
public void initRootLogger() {
Logger.getLogger("").getHandlers();
Logger rootLogger = Logger.getLogger("");
rootLogger.setLevel(Level.INFO);
Handler[] handlers = rootLogger.getHandlers();
for (Handler handler : handlers) {
handler.setLevel(Level.INFO);
}
}
public void start() {
String initialLogger = Logger.getLogger(LOGGER).toString();
while (true) {
if (!initialLogger.equals(Logger.getLogger(LOGGER).toString())) {
System.out.println("Logger changed from " + initialLogger + " to " + Logger.getLogger(LOGGER));
System.exit(-1);
}
Logger.getLogger(LOGGER).fine("LoggerTester log");
}
}
public static void main(String[] args) {
LoggerTester tester = new LoggerTester();
tester.initRootLogger();
Thread thread = new Thread() {
@Override
public void run() {
while (true) {
Logger.getLogger(LOGGER).fine("Thread log");
}
}
};
System.out.println("Starting logger loops");
thread.start();
tester.start();
}
}
EXPECTED VERSUS ACTUAL BEHAVIOR :
EXPECTED -
The program should never exit as the logger returned by getLogger() should always be the same.
ACTUAL -
The program returns saying that the logger changed in the course of the execution.
REPRODUCIBILITY :
This bug can be reproduced always.
CUSTOMER SUBMITTED WORKAROUND :
1.6.0_17 works as expected.
Release Regression From : 6u17
The above release value was the last known release where this
bug was not reproducible. Since then there has been a regression.
- duplicates
-
JDK-6949710 the GC'able nature of Logging objects needs to be made brutally clear
- Closed
- relates to
-
JDK-6274920 JDK logger holds strong reference to java.util.logging.Logger instances
- Closed