8349206: j.u.l.Handler classes create deadlock risk via synchronized publish() method

Reviewed-by: dfuchs, smarks

Author: david-beaumont

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

@@ -87,6 +87,12 @@ public ConsoleHandler() {
      * The logging request was made initially to a {@code Logger} object,
      * which initialized the {@code LogRecord} and forwarded it here.
      *
+     * @implSpec This method is not synchronized, and subclasses must not define
+     * overridden {@code publish()} methods to be {@code synchronized} if they
+     * call {@code super.publish()} or format user arguments. See the
+     * {@linkplain Handler##threadSafety discussion in java.util.logging.Handler}
+     * for more information.
+     *
      * @param  record  description of the log event. A null record is
      *                 silently ignored and is not published
      */

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

@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2000, 2024, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2000, 2025, 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
@@ -739,11 +739,14 @@ private synchronized void rotate() {
      *                 silently ignored and is not published
      */
     @Override
-    public synchronized void publish(LogRecord record) {
-        if (!isLoggable(record)) {
-            return;
-        }
+    public void publish(LogRecord record) {
         super.publish(record);
+    }
+
+    @Override
+    void synchronousPostWriteHook() {
+        // no need to synchronize here, this method is called from within a
+        // synchronized block.
         flush();
         if (limit > 0 && (meter.written >= limit || meter.written < 0)) {
             rotate();

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

@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2000, 2024, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2000, 2025, 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
@@ -43,10 +43,25 @@
  * and {@code Level}.  See the specific documentation for each concrete
  * {@code Handler} class.
  *
+ * <h2><a id=threadSafety>Thread Safety and Deadlock Risk in Handlers</a></h2>
+ *
+ * Implementations of {@code Handler} should be thread-safe. Handlers are
+ * expected to be invoked concurrently from arbitrary threads. However,
+ * over-use of synchronization may result in unwanted thread contention,
+ * performance issues or even deadlocking.
+ * <p>
+ * In particular, subclasses should avoid acquiring locks around code which
+ * calls back to arbitrary user-supplied objects, especially during log record
+ * formatting. Holding a lock around any such callbacks creates a deadlock risk
+ * between logging code and user code.
+ * <p>
+ * As such, general purpose {@code Handler} subclasses should not synchronize
+ * their {@link #publish(LogRecord)} methods, or call {@code super.publish()}
+ * while holding locks, since these are typically expected to need to process
+ * and format user-supplied arguments.
  *
  * @since 1.4
  */
-
 public abstract class Handler {
     private static final int offValue = Level.OFF.intValue();
 
@@ -123,6 +138,10 @@ protected Handler() { }
      * <p>
      * The {@code Handler}  is responsible for formatting the message, when and
      * if necessary.  The formatting should include localization.
+     * <p>
+     * @apiNote To avoid the risk of deadlock, implementations of this method
+     * should avoid holding any locks while calling out to application code,
+     * such as the formatting of {@code LogRecord}.
      *
      * @param  record  description of the log event. A null record is
      *                 silently ignored and is not published

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

@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2000, 2024, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2000, 2025, 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
@@ -168,14 +168,17 @@ public synchronized void close() {
     /**
      * Format and publish a {@code LogRecord}.
      *
+     * @implSpec This method is not synchronized, and subclasses must not define
+     * overridden {@code publish()} methods to be {@code synchronized} if they
+     * call {@code super.publish()} or format user arguments. See the
+     * {@linkplain Handler##threadSafety discussion in java.util.logging.Handler}
+     * for more information.
+     *
      * @param  record  description of the log event. A null record is
      *                 silently ignored and is not published
      */
     @Override
-    public synchronized void publish(LogRecord record) {
-        if (!isLoggable(record)) {
-            return;
-        }
+    public void publish(LogRecord record) {
         super.publish(record);
         flush();
     }

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

@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2000, 2024, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2000, 2025, 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
@@ -180,17 +180,31 @@ public synchronized void setEncoding(String encoding)
      * {@code OutputStream}, the {@code Formatter}'s "head" string is
      * written to the stream before the {@code LogRecord} is written.
      *
+     * @implSpec This method avoids acquiring locks during {@code LogRecord}
+     * formatting, but {@code this} instance is synchronized when writing to the
+     * output stream. To avoid deadlock risk, subclasses must not hold locks
+     * while calling {@code super.publish()}. Specifically, subclasses must
+     * not define the overridden {@code publish()} method to be
+     * {@code synchronized} if they call {@code super.publish()}.
+     *
      * @param  record  description of the log event. A null record is
      *                 silently ignored and is not published
      */
     @Override
-    public synchronized void publish(LogRecord record) {
-       if (!isLoggable(record)) {
+    public void publish(LogRecord record) {
+        if (!isLoggable(record)) {
             return;
         }
+        // Read once for consistency (whether in or outside the locked region
+        // is not important).
+        Formatter formatter = getFormatter();
+        // JDK-8349206: To avoid deadlock risk, it is essential that the handler
+        // is not locked while formatting the log record. Methods such as
+        // reportError() and isLoggable() are defined to be thread safe, so we
+        // can restrict locking to just writing the message.
         String msg;
         try {
-            msg = getFormatter().format(record);
+            msg = formatter.format(record);
         } catch (Exception ex) {
             // We don't want to throw an exception here, but we
             // report the exception to any registered ErrorManager.
@@ -199,19 +213,33 @@ public synchronized void publish(LogRecord record) {
         }
 
         try {
-            Writer writer = this.writer;
-            if (!doneHeader) {
-                writer.write(getFormatter().getHead(this));
-                doneHeader = true;
+            synchronized(this) {
+                Writer writer = this.writer;
+                if (!doneHeader) {
+                    writer.write(formatter.getHead(this));
+                    doneHeader = true;
+                }
+                writer.write(msg);
+                synchronousPostWriteHook();
             }
-            writer.write(msg);
         } catch (Exception ex) {
             // We don't want to throw an exception here, but we
             // report the exception to any registered ErrorManager.
             reportError(null, ex, ErrorManager.WRITE_FAILURE);
         }
     }
 
+    /**
+     * Overridden by other handlers in this package to facilitate synchronous
+     * post-write behaviour. If other handlers need similar functionality, it
+     * might be feasible to make this method protected (see JDK-8349206), but
+     * please find a better name if you do ;).
+     */
+    void synchronousPostWriteHook() {
+        // Empty by default. We could do:
+        //    assert Thread.holdsLock(this);
+        // but this is already covered by unit tests.
+    }
 
     /**
      * Check if this {@code Handler} would actually log a given {@code LogRecord}.
@@ -249,15 +277,17 @@ public synchronized void flush() {
         }
     }
 
+    // Called synchronously with "this" handler instance locked.
     private void flushAndClose() {
         Writer writer = this.writer;
         if (writer != null) {
+            Formatter formatter = getFormatter();
             try {
                 if (!doneHeader) {
-                    writer.write(getFormatter().getHead(this));
+                    writer.write(formatter.getHead(this));
                     doneHeader = true;
                 }
-                writer.write(getFormatter().getTail(this));
+                writer.write(formatter.getTail(this));
                 writer.flush();
                 writer.close();
             } catch (Exception ex) {

test/jdk/java/util/logging/Handler/StreamHandlerLockingTest.java

@@ -0,0 +1,105 @@
+/*
+ * Copyright (c) 2025, 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.
+ */
+
+/*
+ * @test
+ * @bug     8349206
+ * @summary j.u.l.Handler classes create deadlock risk via synchronized publish() method.
+ * @modules java.base/sun.util.logging
+ *          java.logging
+ * @build java.logging/java.util.logging.TestStreamHandler
+ * @run main/othervm StreamHandlerLockingTest
+ */
+
+import java.io.ByteArrayOutputStream;
+import java.io.IOException;
+import java.util.logging.Formatter;
+import java.util.logging.Handler;
+import java.util.logging.Level;
+import java.util.logging.LogRecord;
+import java.util.logging.TestStreamHandler;
+
+public class StreamHandlerLockingTest {
+    static class TestFormatter extends Formatter {
+        final Handler handler;
+
+        TestFormatter(Handler handler) {
+            this.handler = handler;
+        }
+
+        @Override
+        public String format(LogRecord record) {
+            if (Thread.holdsLock(handler)) {
+                throw new AssertionError("format() was called with handler locked (bad).");
+            }
+            return record.getMessage() + "\n";
+        }
+
+        @Override
+        public String getHead(Handler h) {
+            // This is currently true, and not easy to make unsynchronized.
+            if (!Thread.holdsLock(handler)) {
+                throw new AssertionError("getHead() expected to be called with handler locked.");
+            }
+            return "--HEAD--\n";
+        }
+
+        @Override
+        public String getTail(Handler h) {
+            // This is currently true, and not easy to make unsynchronized.
+            if (!Thread.holdsLock(handler)) {
+                throw new AssertionError("getTail() expected to be called with handler locked.");
+            }
+            return "--TAIL--\n";
+        }
+    }
+
+    private static final String EXPECTED_LOG =
+            String.join("\n","--HEAD--", "Hello World", "Some more logging...", "And we're done!", "--TAIL--", "");
+
+    public static void main(String[] args) throws IOException {
+        ByteArrayOutputStream out = new ByteArrayOutputStream();
+        TestStreamHandler handler = new TestStreamHandler(out);
+        TestFormatter formatter = new TestFormatter(handler);
+        handler.setFormatter(formatter);
+
+        handler.publish(log("Hello World"));
+        handler.publish(log("Some more logging..."));
+        handler.publish(log("And we're done!"));
+        handler.close();
+
+        // Post write callback should have happened once per publish call (with lock held).
+        if (handler.callbackCount != 3) {
+            throw new AssertionError("Unexpected callback count: " + handler.callbackCount);
+        }
+
+        String logged = out.toString("UTF-8");
+        if (!EXPECTED_LOG.equals(logged)) {
+            throw new AssertionError("Unexpected log contents: " + logged);
+        }
+    }
+
+    static LogRecord log(String msg) {
+        return new LogRecord(Level.INFO, msg);
+    }
+}

test/jdk/java/util/logging/Handler/java.logging/java/util/logging/TestStreamHandler.java

@@ -0,0 +1,54 @@
+/*
+ * Copyright (c) 2025, 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.
+ */
+
+package java.util.logging;
+
+import java.io.OutputStream;
+import java.io.UnsupportedEncodingException;
+
+/**
+ * A trivial UTF-8 stream handler subclass class to capture whether the
+ * (package protected) post-write callback method is synchronized.
+ */
+public class TestStreamHandler extends StreamHandler {
+
+    public int callbackCount = 0;
+
+    public TestStreamHandler(OutputStream out) {
+        setOutputStream(out);
+        try {
+            setEncoding("UTF-8");
+        } catch (UnsupportedEncodingException e) {
+            throw new RuntimeException(e);
+        }
+    }
+
+    @Override
+    void synchronousPostWriteHook() {
+        if (!Thread.holdsLock(this)) {
+            throw new AssertionError(
+                    String.format("Post write callback [index=%d] was invoked without handler locked.", callbackCount));
+        }
+        callbackCount++;
+    }
+}