openjdk/test/jdk/java/util/logging/LoggingDeadlock5.java
2025-04-24 19:18:13 +00:00

216 lines
8.4 KiB
Java

/*
* 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.
* @library /test/lib
* @modules java.base/sun.util.logging
* java.logging
* @run main/othervm LoggingDeadlock5
*/
import jdk.test.lib.Utils;
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.
// This can be called without arguments in one of the threads.
Object[] parameters = record.getParameters();
if (parameters != null) {
for (Object p : parameters) {
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 {
// Since this is used to self-test for an expected deadlock, it will
// delay the test by at least this duration (so being overly large is
// a potential issue). The deadlock is set up so it should occur almost
// immediately (if it occurs), but tests are run under very high loads
// in higher tiers, so it's necessary to be a bit pessimistic here.
private final static Duration JOIN_WAIT =
Duration.ofMillis(Utils.adjustTimeout(2000));
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;
}
}