1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204 205 206 207 208 209 210 211 212 213 214 215
|
/*
* 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;
}
}
|