infernap12/jdk
1
0
Fork 0
mirror of https://github.com/openjdk/jdk.git synced 2026-01-28 12:09:14 +00:00
Code Issues Packages Projects Releases Wiki Activity

8353684: [BACKOUT] j.u.l.Handler classes create deadlock risk via synchronized publish() method

Browse Source 
Reviewed-by: dholmes
This commit is contained in:
Stuart Marks 2025-04-03 21:15:00 +00:00
parent ebcb9a8b12
commit 57df89c464
8 changed files with 23 additions and 445 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

6
src/java.logging/share/classes/java/util/logging/ConsoleHandler.java
View File

@ -87,12 +87,6 @@ public class ConsoleHandler extends StreamHandler {
* 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
*/

13
src/java.logging/share/classes/java/util/logging/FileHandler.java
View File

@ -1,5 +1,5 @@
/*
* Copyright (c) 2000, 2025, Oracle and/or its affiliates. All rights reserved.
* Copyright (c) 2000, 2024, 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,14 +739,11 @@ public class FileHandler extends StreamHandler {
* silently ignored and is not published
*/
@Override
public void publish(LogRecord record) {
public synchronized void publish(LogRecord record) {
if (!isLoggable(record)) {
return;
}
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();

23
src/java.logging/share/classes/java/util/logging/Handler.java
View File

@ -1,5 +1,5 @@
/*
* Copyright (c) 2000, 2025, Oracle and/or its affiliates. All rights reserved.
* Copyright (c) 2000, 2024, 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,25 +43,10 @@ import java.io.UnsupportedEncodingException;
* 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();
@ -138,10 +123,6 @@ public abstract class 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

13
src/java.logging/share/classes/java/util/logging/SocketHandler.java
View File

@ -1,5 +1,5 @@
/*
* Copyright (c) 2000, 2025, Oracle and/or its affiliates. All rights reserved.
* Copyright (c) 2000, 2024, 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,17 +168,14 @@ public class SocketHandler extends StreamHandler {
/**
* 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 void publish(LogRecord record) {
public synchronized void publish(LogRecord record) {
if (!isLoggable(record)) {
return;
}
super.publish(record);
flush();
}

52
src/java.logging/share/classes/java/util/logging/StreamHandler.java
View File

@ -1,5 +1,5 @@
/*
* Copyright (c) 2000, 2025, Oracle and/or its affiliates. All rights reserved.
* Copyright (c) 2000, 2024, 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,31 +180,17 @@ public class StreamHandler extends Handler {
* {@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 void publish(LogRecord record) {
if (!isLoggable(record)) {
public synchronized 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 = formatter.format(record);
msg = getFormatter().format(record);
} catch (Exception ex) {
// We don't want to throw an exception here, but we
// report the exception to any registered ErrorManager.
@ -213,15 +199,12 @@ public class StreamHandler extends Handler {
}
try {
synchronized(this) {
Writer writer = this.writer;
if (!doneHeader) {
writer.write(formatter.getHead(this));
doneHeader = true;
}
writer.write(msg);
synchronousPostWriteHook();
Writer writer = this.writer;
if (!doneHeader) {
writer.write(getFormatter().getHead(this));
doneHeader = true;
}
writer.write(msg);
} catch (Exception ex) {
// We don't want to throw an exception here, but we
// report the exception to any registered ErrorManager.
@ -229,17 +212,6 @@ public class StreamHandler extends Handler {
}
}
/**
* 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}.
@ -277,17 +249,15 @@ public class StreamHandler extends Handler {
}
}
// 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(formatter.getHead(this));
writer.write(getFormatter().getHead(this));
doneHeader = true;
}
writer.write(formatter.getTail(this));
writer.write(getFormatter().getTail(this));
writer.flush();
writer.close();
} catch (Exception ex) {

105
test/jdk/java/util/logging/Handler/StreamHandlerLockingTest.java
View File

@ -1,105 +0,0 @@
/*
* 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);
}
}

54
test/jdk/java/util/logging/Handler/java.logging/java/util/logging/TestStreamHandler.java
View File

@ -1,54 +0,0 @@
/*
* 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++;
}
}

202
test/jdk/java/util/logging/LoggingDeadlock5.java
View File

@ -1,202 +0,0 @@
/*
* 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
* @run main/othervm LoggingDeadlock5
*/
import java.io.ByteArrayOutputStream;
import java.io.IOException;
import java.io.UnsupportedEncodingException;
import java.nio.charset.StandardCharsets;
import java.time.Duration;
import java.util.concurrent.Semaphore;
import java.util.logging.FileHandler;
import java.util.logging.Formatter;
import java.util.logging.Handler;
import java.util.logging.Level;
import java.util.logging.LogRecord;
import java.util.logging.Logger;
import java.util.logging.StreamHandler;
/**
* This test verifies that logging Handler implementations no longer suffer
* from the deadlock risk outlined in JDK-8349206.
*
* <p>This test should reliably cause, and detect, deadlocks in a timely
* manner if the problem occurs, and SHOULD NOT time out.
*/
public class LoggingDeadlock5 {
private static final String UTF_8 = StandardCharsets.UTF_8.name();
// Formatter which calls toString() on all arguments.
private static final Formatter TEST_FORMATTER = new Formatter() {
@Override
public String format(LogRecord record) {
// All we care about is that our formatter will invoke toString() on user arguments.
for (Object p : record.getParameters()) {
var unused = p.toString();
}
return "<formatted string>";
}
};
// A handler which *should* cause a deadlock by synchronizing publish().
private static final Handler SELF_TEST_HANDLER = new Handler() {
@Override
public synchronized void publish(LogRecord record) {
TEST_FORMATTER.formatMessage(record);
}
@Override
public void flush() {
}
@Override
public void close() {
}
};
public static void main(String[] args) throws InterruptedException, IOException {
// Self test that deadlocks are correctly caught (and don't deadlock the test itself).
new DeadLocker(SELF_TEST_HANDLER).checkDeadlock(true);
// In theory, we should test SocketHandler here as well because, while
// it is just a subclass, it could be adding locking around the call to
// super.publish(). However, it is problematic in a test environment
// since it needs to open sockets. It is not being tested for now.
assertNoDeadlock(new StreamHandler(new ByteArrayOutputStream(0), TEST_FORMATTER));
// Single log file in current directory, no rotation. JTreg will delete
// temporary files after test completion.
assertNoDeadlock(new FileHandler("temp_log_file"));
// Any other problematic handler classes can be easily added here if
// they are simple enough to be constructed in a test environment.
}
static void assertNoDeadlock(Handler handler) throws InterruptedException, UnsupportedEncodingException {
try {
handler.setEncoding(UTF_8);
new DeadLocker(handler).checkDeadlock(false);
} finally {
// Handlers may have open resources, so must be closed.
handler.close();
}
}
private static class DeadLocker {
private final static Duration JOIN_WAIT = Duration.ofMillis(500);
private final Semaphore readyToDeadlock = new Semaphore(0);
private final Semaphore userLockIsHeld = new Semaphore(0);
private final Logger logger = Logger.getAnonymousLogger();
private final Handler handlerUnderTest;
private final Object userLock = new Object();
private boolean deadlockEncountered = true;
DeadLocker(Handler handlerUnderTest) {
this.handlerUnderTest = handlerUnderTest;
this.logger.setUseParentHandlers(false);
this.logger.addHandler(handlerUnderTest);
this.logger.setLevel(Level.INFO);
this.handlerUnderTest.setLevel(Level.INFO);
}
void checkDeadlock(boolean expectDeadlock) throws InterruptedException {
// Note: Even though the message format string isn't used in the
// test formatter, it must be a valid log format string (Logger
// detects if there are no "{n}" placeholders and skips calling
// the formatter otherwise).
Thread t1 = runAsDaemon(() -> logger.log(Level.INFO, "Hello {0}", new Argument()));
readyToDeadlock.acquireUninterruptibly();
// First thread is blocked until userLockIsHeld is released in t2.
Thread t2 = runAsDaemon(this::locksThenLogs);
// If deadlock occurs, the join() calls both return false.
int threadsBlocked = 0;
if (!t1.join(JOIN_WAIT)) {
threadsBlocked += 1;
}
if (!t2.join(JOIN_WAIT)) {
threadsBlocked += 1;
}
// These indicate test problems, not a failure of the code under test.
errorIf(threadsBlocked == 1, "Inconsistent number of blocked threads.");
errorIf(deadlockEncountered != (threadsBlocked == 2),
"Deadlock reporting should coincide with number of blocked threads.");
// This is the actual test assertion.
if (expectDeadlock != deadlockEncountered) {
String issue = expectDeadlock ? "Expected deadlock but none occurred" : "Unexpected deadlock";
throw new AssertionError(errorMsg(issue));
}
}
void locksThenLogs() {
synchronized (userLock) {
userLockIsHeld.release();
logger.log(Level.INFO, "This will cause a deadlock if the Handler locks!");
}
}
void calledFromToString() {
this.readyToDeadlock.release();
this.userLockIsHeld.acquireUninterruptibly();
synchronized (userLock) {
this.deadlockEncountered = false;
}
}
class Argument {
@Override
public String toString() {
calledFromToString();
return "<to string>";
}
}
String errorMsg(String msg) {
return String.format("Handler deadlock test [%s]: %s", handlerUnderTest.getClass().getName(), msg);
}
void errorIf(boolean condition, String msg) {
if (condition) {
throw new RuntimeException(errorMsg("TEST ERROR - " + msg));
}
}
}
static Thread runAsDaemon(Runnable job) {
Thread thread = new Thread(job);
thread.setDaemon(true);
thread.start();
return thread;
}
}