7113878: LogManager - namedLoggers should be ConcurrentHashMap instead of Hashtable

NamedLoggers is now a ConcurrentHashMap. findLogger is updated to take benefit of the change.

Co-authored-by: Peter Levart <peter.levart@gmail.com>
Reviewed-by: dholmes, lancea, martin, mchung, plevart

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

@@ -31,6 +31,7 @@ import java.util.*;
 import java.security.*;
 import java.lang.ref.ReferenceQueue;
 import java.lang.ref.WeakReference;
+import java.util.concurrent.ConcurrentHashMap;
 import java.util.concurrent.CopyOnWriteArrayList;
 import sun.misc.JavaAWTAccess;
 import sun.misc.SharedSecrets;
@@ -579,7 +580,8 @@ public class LogManager {
     // added in the user context.
     class LoggerContext {
         // Table of named Loggers that maps names to Loggers.
-        private final Hashtable<String,LoggerWeakRef> namedLoggers = new Hashtable<>();
+        private final ConcurrentHashMap<String,LoggerWeakRef> namedLoggers =
+                new ConcurrentHashMap<>();
         // Tree of named Loggers
         private final LogNode root;
         private LoggerContext() {
@@ -642,21 +644,44 @@ public class LogManager {
         }
 
 
-        synchronized Logger findLogger(String name) {
-            // ensure that this context is properly initialized before
-            // looking for loggers.
-            ensureInitialized();
+        Logger findLogger(String name) {
+            // Attempt to find logger without locking.
             LoggerWeakRef ref = namedLoggers.get(name);
-            if (ref == null) {
-                return null;
+            Logger logger = ref == null ? null : ref.get();
+
+            // if logger is not null, then we can return it right away.
+            // if name is "" or "global" and logger is null
+            // we need to fall through and check that this context is
+            // initialized.
+            // if ref is not null and logger is null we also need to
+            // fall through.
+            if (logger != null || (ref == null && !name.isEmpty()
+                    && !name.equals(Logger.GLOBAL_LOGGER_NAME))) {
+                return logger;
             }
-            Logger logger = ref.get();
-            if (logger == null) {
-                // Hashtable holds stale weak reference
-                // to a logger which has been GC-ed.
-                ref.dispose();
+
+            // We either found a stale reference, or we were looking for
+            // "" or "global" and didn't find them.
+            // Make sure context is initialized (has the default loggers),
+            // and look up again, cleaning the stale reference if it hasn't
+            // been cleaned up in between. All this needs to be done inside
+            // a synchronized block.
+            synchronized(this) {
+                // ensure that this context is properly initialized before
+                // looking for loggers.
+                ensureInitialized();
+                ref = namedLoggers.get(name);
+                if (ref == null) {
+                    return null;
+                }
+                logger = ref.get();
+                if (logger == null) {
+                    // The namedLoggers map holds stale weak reference
+                    // to a logger which has been GC-ed.
+                    ref.dispose();
+                }
+                return logger;
             }
-            return logger;
         }
 
         // This method is called before adding a logger to the
@@ -752,7 +777,6 @@ public class LogManager {
             final LogManager owner = getOwner();
             logger.setLogManager(owner);
             ref = owner.new LoggerWeakRef(logger);
-            namedLoggers.put(name, ref);
 
             // Apply any initial level defined for the new logger, unless
             // the logger's level is already initialized
@@ -789,10 +813,17 @@ public class LogManager {
             node.walkAndSetParent(logger);
             // new LogNode is ready so tell the LoggerWeakRef about it
             ref.setNode(node);
+
+            // Do not publish 'ref' in namedLoggers before the logger tree
+            // is fully updated - because the named logger will be visible as
+            // soon as it is published in namedLoggers (findLogger takes
+            // benefit of the ConcurrentHashMap implementation of namedLoggers
+            // to avoid synchronizing on retrieval when that is possible).
+            namedLoggers.put(name, ref);
             return true;
         }
 
-        synchronized void removeLoggerRef(String name, LoggerWeakRef ref) {
+        void removeLoggerRef(String name, LoggerWeakRef ref) {
             namedLoggers.remove(name, ref);
         }
 
@@ -800,7 +831,7 @@ public class LogManager {
             // ensure that this context is properly initialized before
             // returning logger names.
             ensureInitialized();
-            return namedLoggers.keys();
+            return Collections.enumeration(namedLoggers.keySet());
         }
 
         // If logger.getUseParentHandlers() returns 'true' and any of the logger's

jdk/test/java/util/logging/LogManager/TestLoggerNames.java

@@ -0,0 +1,239 @@
+/*
+ * Copyright (c) 2015, 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.util.Collections;
+import java.util.Enumeration;
+import java.util.Iterator;
+import java.util.List;
+import java.util.concurrent.CopyOnWriteArrayList;
+import java.util.concurrent.Phaser;
+import java.util.concurrent.Semaphore;
+import java.util.logging.Handler;
+import java.util.logging.LogManager;
+import java.util.logging.Logger;
+
+
+/**
+ * @test
+ * @bug 7113878
+ * @summary This is not a test that will check that 7113878 is fixed, but
+ *          rather a test that will invoke the modified code & try to verify
+ *          that fixing 7113878 has not introduced some big regression.
+ *          This test should pass, whether 7113878 is there or not.
+ * @run main/othervm TestLoggerNames
+ * @author danielfuchs
+ */
+public class TestLoggerNames {
+
+    static final class TestLogger extends java.util.logging.Logger {
+
+        final Semaphore sem = new Semaphore(0);
+        final Semaphore wait = new Semaphore(0);
+
+        public TestLogger(String name, String resourceBundleName) {
+            super(name, resourceBundleName);
+        }
+
+        @Override
+        public Handler[] getHandlers() {
+           boolean found = false;
+           try {
+                System.out.println("Entering "+getName()+" getHandlers()");
+                for (StackTraceElement ste : Thread.currentThread().getStackTrace()) {
+                    if (LogManager.class.getName().equals(ste.getClassName())
+                            && "reset".equals(ste.getMethodName())) {
+                        found = true;
+                        System.out.println(getName()+" getHandlers() called by " + ste);
+                    }
+                }
+                sem.release();
+                try {
+                    System.out.println("TestLogger: Acquiring wait for "+getName());
+                    wait.acquire();
+                    try {
+                        System.out.println("TestLogger: Acquired wait for "+getName());
+                        return super.getHandlers();
+                    } finally {
+                        System.out.println("TestLogger: Releasing wait for "+getName());
+                        wait.release();
+                    }
+                } finally {
+                    System.out.println("Unblocking "+getName());
+                    sem.acquire();
+                    System.out.println("Unblocked "+getName());
+                    if (found) {
+                        System.out.println("Reset will proceed...");
+                    }
+                }
+            } catch (InterruptedException x) {
+                throw new IllegalStateException(x);
+            }
+        }
+    }
+
+    static volatile boolean stop;
+    static volatile Throwable resetFailed;
+    static volatile Throwable checkLoggerNamesFailed;
+    static volatile Phaser phaser = new Phaser(2);
+
+
+    static void checkLoggerNames(List<Logger> loggers) {
+        Enumeration<String> names = LogManager.getLogManager().getLoggerNames();
+        if (names instanceof Iterator) {
+            for (Iterator<?> it = Iterator.class.cast(names); it.hasNext(); ) {
+                try {
+                    it.remove();
+                    throw new RuntimeException("Iterator supports remove!");
+                } catch (UnsupportedOperationException x) {
+                    System.out.println("OK: Iterator doesn't support remove.");
+                }
+            }
+        }
+        List<String> loggerNames = Collections.list(names);
+        if (!loggerNames.contains("")) {
+            throw new RuntimeException("\"\"" +
+                    " not found in " + loggerNames);
+        }
+        if (!loggerNames.contains("global")) {
+            throw new RuntimeException("global" +
+                    " not found in " + loggerNames);
+        }
+        for (Logger l : loggers) {
+            if (!loggerNames.contains(l.getName())) {
+                throw new RuntimeException(l.getName() +
+                        " not found in " + loggerNames);
+            }
+        }
+        System.out.println("Got all expected logger names");
+    }
+
+
+    public static void main(String[] args) throws InterruptedException {
+        LogManager.getLogManager().addLogger(new TestLogger("com.foo.bar.zzz", null));
+        try {
+            Logger.getLogger(null);
+            throw new RuntimeException("Logger.getLogger(null) didn't throw expected NPE");
+        } catch (NullPointerException x) {
+            System.out.println("Got expected NullPointerException for Logger.getLogger(null)");
+        }
+        List<Logger> loggers = new CopyOnWriteArrayList<>();
+        loggers.add(Logger.getLogger("one.two.addMeAChild"));
+        loggers.add(Logger.getLogger("aaa.bbb.replaceMe"));
+        loggers.add(Logger.getLogger("bbb.aaa.addMeAChild"));
+        TestLogger test = (TestLogger)Logger.getLogger("com.foo.bar.zzz");
+        loggers.add(Logger.getLogger("ddd.aaa.addMeAChild"));
+
+        checkLoggerNames(loggers);
+
+        Thread loggerNamesThread = new Thread(() -> {
+            try {
+                while (!stop) {
+                    checkLoggerNames(loggers);
+                    Thread.sleep(10);
+                    if (!stop) {
+                        phaser.arriveAndAwaitAdvance();
+                    }
+                }
+            } catch (Throwable t) {
+                t.printStackTrace(System.err);
+                checkLoggerNamesFailed = t;
+            }
+        }, "loggerNames");
+
+        Thread resetThread = new Thread(() -> {
+            try {
+                System.out.println("Calling reset...");
+                LogManager.getLogManager().reset();
+                System.out.println("Reset done...");
+                System.out.println("Reset again...");
+                LogManager.getLogManager().reset();
+                System.out.println("Reset done...");
+            } catch(Throwable t) {
+                resetFailed = t;
+                System.err.println("Unexpected exception or error in reset Thread");
+                t.printStackTrace(System.err);
+            }
+        }, "reset");
+
+        resetThread.setDaemon(true);
+        resetThread.start();
+
+        System.out.println("Waiting for reset to get handlers");
+        test.sem.acquire();
+        try {
+            loggerNamesThread.start();
+            System.out.println("Reset has called getHandlers on " + test.getName());
+            int i = 0;
+            for (Enumeration<String> e = LogManager.getLogManager().getLoggerNames();
+                e.hasMoreElements();) {
+                String name = e.nextElement();
+                if (name.isEmpty()) continue;
+                if (name.endsWith(".addMeAChild")) {
+                    Logger l =  Logger.getLogger(name+".child");
+                    loggers.add(l);
+                    System.out.println("*** Added " + l.getName());
+                    i++;
+                } else if (name.endsWith("replaceMe")) {
+                    Logger l = Logger.getLogger(name);
+                    loggers.remove(l);
+                    l = Logger.getLogger(name.replace("replaceMe", "meReplaced"));
+                    loggers.add(l);
+                    System.gc();
+                    if (LogManager.getLogManager().getLogger(name) == null) {
+                        System.out.println("*** "+ name + " successfully replaced with " + l.getName());
+                    }
+                    i++;
+                } else {
+                    System.out.println("Nothing to do for logger: " + name);
+                }
+                phaser.arriveAndAwaitAdvance();
+                if (i >= 3 && i++ == 3) {
+                    System.out.println("Loggers are now: " +
+                            Collections.list(LogManager.getLogManager().getLoggerNames()));
+                    test.wait.release();
+                    test.sem.release();
+                    System.out.println("Joining " + resetThread);
+                    resetThread.join();
+                }
+            }
+        } catch (RuntimeException | InterruptedException | Error x) {
+            test.wait.release();
+            test.sem.release();
+            throw x;
+        } finally {
+            stop = true;
+            phaser.arriveAndDeregister();
+            loggerNamesThread.join();
+            loggers.clear();
+        }
+
+
+        if (resetFailed != null || checkLoggerNamesFailed != null) {
+            RuntimeException r = new RuntimeException("Some of the concurrent threads failed");
+            if (resetFailed != null) r.addSuppressed(resetFailed);
+            if (checkLoggerNamesFailed != null) r.addSuppressed(checkLoggerNamesFailed);
+            throw r;
+        }
+
+    }
+
+}