8010939: Deadlock in LogManager

Summary: re-order locks to avoid deadlock
Reviewed-by: mchung

src/share/classes/java/util/logging/LogManager.java

 /*
- * Copyright (c) 2000, 2012, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2000, 2013, Oracle and/or its affiliates. All rights reserved.
  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
  *
  * This code is free software; you can redistribute it and/or modify it
@@ -35,10 +35,8 @@ import java.lang.reflect.Constructor;
 import java.lang.reflect.InvocationTargetException;
 import java.lang.reflect.Method;
 import java.beans.PropertyChangeListener;
-import java.net.URL;
 import sun.misc.JavaAWTAccess;
 import sun.misc.SharedSecrets;
-import sun.security.action.GetPropertyAction;
 
 /**
  * There is a single global LogManager object that is used to
@@ -148,7 +146,6 @@ public class LogManager {
     // The global LogManager object
     private static LogManager manager;
 
-    private final static Handler[] emptyHandlers = { };
     private Properties props = new Properties();
     private final static Level defaultLevel = Level.INFO;
 
@@ -547,13 +544,10 @@ public class LogManager {
                 throw new NullPointerException();
             }
 
-            // cleanup some Loggers that have been GC'ed
-            manager.drainLoggerRefQueueBounded();
-
             LoggerWeakRef ref = namedLoggers.get(name);
             if (ref != null) {
                 if (ref.get() == null) {
-                    // It's possible that the Logger was GC'ed after the
+                    // It's possible that the Logger was GC'ed after a
                     // drainLoggerRefQueueBounded() call above so allow
                     // a new one to be registered.
                     removeLogger(name);
@@ -605,6 +599,8 @@ public class LogManager {
             return true;
         }
 
+        // note: all calls to removeLogger are synchronized on LogManager's
+        // intrinsic lock
         void removeLogger(String name) {
             namedLoggers.remove(name);
         }
@@ -887,6 +883,7 @@ public class LogManager {
         if (name == null) {
             throw new NullPointerException();
         }
+        drainLoggerRefQueueBounded();
         LoggerContext cx = getUserContext();
         if (cx.addLocalLogger(logger)) {
             // Do we have a per logger handler too?

test/java/util/logging/DrainFindDeadlockTest.java

+/*
+ * Copyright (c) 2013, Oracle and/or its affiliates. All rights reserved.
+ * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
+ *
+ * This code is free software; you can redistribute it and/or modify it
+ * under the terms of the GNU General Public License version 2 only, as
+ * published by the Free Software Foundation.
+ *
+ * This code is distributed in the hope that it will be useful, but WITHOUT
+ * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+ * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
+ * version 2 for more details (a copy is included in the LICENSE file that
+ * accompanied this code).
+ *
+ * You should have received a copy of the GNU General Public License version
+ * 2 along with this work; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
+ *
+ * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
+ * or visit www.oracle.com if you need additional information or have any
+ * questions.
+ */
+import java.lang.management.ThreadInfo;
+import java.lang.management.ThreadMXBean;
+import java.lang.Thread.State;
+import java.io.IOException;
+import java.lang.management.ManagementFactory;
+import java.util.logging.LogManager;
+import java.util.logging.Logger;
+import java.util.Map;
+
+/**
+ * @test
+ * @bug 8010939
+ * @summary check for deadlock between findLogger() and drainLoggerRefQueueBounded()
+ * @author jim.gish@oracle.com
+ * @build DrainFindDeadlockTest
+ * @run main/othervm/timeout=10 DrainFindDeadlockTest
+ */
+
+/**
+ * This test is checking for a deadlock between
+ * LogManager$LoggerContext.findLogger() and
+ * LogManager.drainLoggerRefQueueBounded() (which could happen by calling
+ * Logger.getLogger() and LogManager.readConfiguration() in different threads)
+ */
+public class DrainFindDeadlockTest {
+    private LogManager mgr = LogManager.getLogManager();
+    private final static int MAX_ITERATIONS = 100;
+
+    // Get a ThreadMXBean so we can check for deadlock.  N.B. this may
+    // not be supported on all platforms, which means we will have to
+    // resort to the traditional test timeout method. However, if
+    // we have the support we'll get the deadlock details if one
+    // is detected.
+    private final static ThreadMXBean threadMXBean =
+            ManagementFactory.getThreadMXBean();
+    private final boolean threadMXBeanDeadlockSupported =
+            threadMXBean.isSynchronizerUsageSupported();
+
+    public static void main(String... args) throws IOException, Exception {
+        new DrainFindDeadlockTest().testForDeadlock();
+    }
+
+    public static void randomDelay() {
+        int runs = (int) Math.random() * 1000000;
+        int c = 0;
+
+        for (int i=0; i<runs; ++i) {
+            c=c+i;
+        }
+    }
+
+    public void testForDeadlock() throws IOException, Exception {
+        System.out.println("Deadlock detection "
+                + (threadMXBeanDeadlockSupported ? "is" : "is not") +
+                            " available.");
+        Thread setup = new Thread(new SetupLogger(), "SetupLogger");
+        Thread readConfig = new Thread(new ReadConfig(), "ReadConfig");
+        Thread check = new Thread(new DeadlockChecker(setup, readConfig),
+                                   "DeadlockChecker");
+
+        // make the threads daemon threads so they will go away when the
+        // test exits
+        setup.setDaemon(true);
+        readConfig.setDaemon(true);
+        check.setDaemon(true);
+
+        check.start(); setup.start(); readConfig.start();
+        try {
+            check.join();
+        } catch (InterruptedException ex) {
+            ex.printStackTrace();
+        }
+        try {
+            readConfig.join();
+            setup.join();
+        } catch (InterruptedException ex) {
+            ex.printStackTrace();
+        }
+        System.out.println("Test passed");
+    }
+
+    class SetupLogger implements Runnable {
+        Logger logger = null;
+
+        @Override
+        public void run() {
+            System.out.println("Running " + Thread.currentThread().getName());
+
+            for (int i=0; i < MAX_ITERATIONS; i++) {
+                logger = Logger.getLogger("DrainFindDeadlockTest"+i);
+                DrainFindDeadlockTest.randomDelay();
+            }
+        }
+    }
+
+    class ReadConfig implements Runnable {
+        @Override
+        public void run() {
+            System.out.println("Running " + Thread.currentThread().getName());
+            for (int i=0; i < MAX_ITERATIONS; i++) {
+                try {
+                    mgr.readConfiguration();
+                } catch (IOException | SecurityException ex) {
+                    throw new RuntimeException("FAILED: test setup problem", ex);
+                }
+                DrainFindDeadlockTest.randomDelay();
+            }
+        }
+    }
+
+    class DeadlockChecker implements Runnable {
+        Thread t1, t2;
+
+        DeadlockChecker(Thread t1, Thread t2) {
+            this.t1 = t1;
+            this.t2 = t2;
+        }
+
+        void checkState(Thread x, Thread y) {
+            //            System.out.println("checkstate");
+            boolean isXblocked = x.getState().equals(State.BLOCKED);
+            boolean isYblocked = y.getState().equals(State.BLOCKED);
+            long[] deadlockedThreads = null;
+
+            if (isXblocked && isYblocked) {
+                System.out.println("threads blocked");
+                // they are both blocked, but this doesn't necessarily mean
+                // they are deadlocked
+                if (threadMXBeanDeadlockSupported) {
+                    System.out.println("checking for deadlock");
+                    deadlockedThreads = threadMXBean.findDeadlockedThreads();
+                } else {
+                    System.out.println("Can't check for deadlock");
+                }
+                if (deadlockedThreads != null) {
+                    System.out.println("We detected a deadlock! ");
+                    ThreadInfo[] threadInfos = threadMXBean.getThreadInfo(
+                            deadlockedThreads, true, true);
+                    for (ThreadInfo threadInfo: threadInfos) {
+                        System.out.println(threadInfo);
+                    }
+                    throw new RuntimeException("TEST FAILED: Deadlock detected");
+                }
+                System.out.println("We may have a deadlock");
+                Map<Thread, StackTraceElement[]> threadMap =
+                        Thread.getAllStackTraces();
+                dumpStack(threadMap.get(x), x);
+                dumpStack(threadMap.get(y), y);
+            }
+        }
+
+        private void dumpStack(StackTraceElement[] aStackElt, Thread aThread) {
+            if (aStackElt != null) {
+                 System.out.println("Thread:" + aThread.getName() + ": " +
+                                    aThread.getState());
+                 for (StackTraceElement element: aStackElt) {
+                    System.out.println("   " + element);
+                 }
+            }
+        }
+
+        @Override
+        public void run() {
+            System.out.println("Running " + Thread.currentThread().getName());
+            for (int i=0; i < MAX_ITERATIONS*2; i++) {
+                checkState(t1, t2);
+                try {
+                    Thread.sleep(10);
+                } catch (InterruptedException ex) {
+                };
+            }
+        }
+    }
+}