Uploaded image for project: 'JDK'
  1. JDK
  2. JDK-6947908

JAVA Logging interface is not threadsafe since 1.6.0_18

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Duplicate
    • Icon: P3 P3
    • None
    • 6u20
    • core-libs

      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.

            dcubed Daniel Daugherty
            ndcosta Nelson Dcosta (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

              Created:
              Updated:
              Resolved:
              Imported:
              Indexed: