db85090553
Co-authored-by: Sean Mullan <mullan@openjdk.org> Co-authored-by: Alan Bateman <alanb@openjdk.org> Co-authored-by: Weijun Wang <weijun@openjdk.org> Co-authored-by: Aleksei Efimov <aefimov@openjdk.org> Co-authored-by: Brian Burkhalter <bpb@openjdk.org> Co-authored-by: Daniel Fuchs <dfuchs@openjdk.org> Co-authored-by: Harshitha Onkar <honkar@openjdk.org> Co-authored-by: Joe Wang <joehw@openjdk.org> Co-authored-by: Jorn Vernee <jvernee@openjdk.org> Co-authored-by: Justin Lu <jlu@openjdk.org> Co-authored-by: Kevin Walls <kevinw@openjdk.org> Co-authored-by: Lance Andersen <lancea@openjdk.org> Co-authored-by: Naoto Sato <naoto@openjdk.org> Co-authored-by: Roger Riggs <rriggs@openjdk.org> Co-authored-by: Brent Christian <bchristi@openjdk.org> Co-authored-by: Stuart Marks <smarks@openjdk.org> Co-authored-by: Ian Graves <igraves@openjdk.org> Co-authored-by: Phil Race <prr@openjdk.org> Co-authored-by: Erik Gahlin <egahlin@openjdk.org> Co-authored-by: Jaikiran Pai <jpai@openjdk.org> Reviewed-by: kevinw, aivanov, rriggs, lancea, coffeys, dfuchs, ihse, erikj, cjplummer, coleenp, naoto, mchung, prr, weijun, joehw, azvegint, psadhukhan, bchristi, sundar, attila
589 lines
24 KiB
Java
589 lines
24 KiB
Java
/*
|
|
* Copyright (c) 2013, 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
|
|
* 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.lang.management.ManagementFactory;
|
|
import java.lang.management.ThreadInfo;
|
|
import java.util.ArrayList;
|
|
import java.util.List;
|
|
import java.util.ListResourceBundle;
|
|
import java.util.Objects;
|
|
import java.util.ResourceBundle;
|
|
import java.util.concurrent.Callable;
|
|
import java.util.concurrent.ExecutorService;
|
|
import java.util.concurrent.Executors;
|
|
import java.util.concurrent.FutureTask;
|
|
import java.util.concurrent.atomic.AtomicLong;
|
|
import java.util.logging.Handler;
|
|
import java.util.logging.Level;
|
|
import java.util.logging.LogRecord;
|
|
import java.util.logging.Logger;
|
|
|
|
/**
|
|
* @test
|
|
* @bug 8029281 8028763
|
|
* @summary Attempts to detect synchronization issues with getResourceBundle()
|
|
* and getResourceBundleName(). It might also detect issues in the way
|
|
* that the logger tree is cleaned up after a logger has been garbage
|
|
* collected. This test helped find the root cause of 8029092, so if
|
|
* this test fails one might also expect failures in
|
|
* java/util/logging/Logger/logrb/TestLogrbResourceBundle.java and
|
|
* java/util/logging/Logger/setResourceBundle/TestSetResourceBundle.java.
|
|
* Note that this is a best effort test. Running it in a loop to
|
|
* reproduce intermittent issues can be a good idea.
|
|
* @modules java.logging
|
|
* java.management
|
|
* @run main/othervm TestLoggerBundleSync
|
|
* @author danielfuchs
|
|
*/
|
|
public class TestLoggerBundleSync {
|
|
|
|
static final boolean VERBOSE = false;
|
|
static volatile Exception thrown = null;
|
|
static volatile boolean goOn = true;
|
|
|
|
static final int READERS = 3;
|
|
static final long TIME = 4 * 1000; // 4 sec.
|
|
static final long STEP = 1 * 1000; // message every 1 sec.
|
|
static final int LCOUNT = 50; // change bundle 50 times...
|
|
static final AtomicLong ignoreLogCount = new AtomicLong(0);
|
|
static final AtomicLong setRBcount = new AtomicLong(0);
|
|
static final AtomicLong setRBNameCount = new AtomicLong(0);
|
|
static final AtomicLong getRBcount = new AtomicLong(0);
|
|
static final AtomicLong checkCount = new AtomicLong(0);
|
|
static final AtomicLong nextLong = new AtomicLong(0);
|
|
|
|
public static class MyBundle extends ListResourceBundle {
|
|
@Override
|
|
protected Object[][] getContents() {
|
|
return new Object[][] {
|
|
{"dummy", "foo"}
|
|
};
|
|
}
|
|
}
|
|
|
|
public static final class MyBundle1 extends MyBundle { };
|
|
public static final class MyBundle2 extends MyBundle { };
|
|
public static final class MyBundle3 extends MyBundle { };
|
|
|
|
|
|
public static final class LoggerRB {
|
|
public final String resourceBundleName;
|
|
public final ResourceBundle userBundle;
|
|
public LoggerRB(String name, ResourceBundle bundle) {
|
|
resourceBundleName = name;
|
|
userBundle = bundle;
|
|
}
|
|
}
|
|
|
|
static final List<Class<? extends ResourceBundle>> classes = new ArrayList<>();
|
|
static {
|
|
classes.add(MyBundle1.class);
|
|
classes.add(MyBundle2.class);
|
|
classes.add(MyBundle3.class);
|
|
}
|
|
|
|
|
|
/**
|
|
* The test starts a number of threads that will attempt to concurrently
|
|
* set resource bundles on Logger, and verifies the consistency of the
|
|
* obtained results.
|
|
*
|
|
* This is a best effort test.
|
|
*
|
|
* @param args the command line arguments
|
|
*/
|
|
public static void main(String[] args) throws Exception {
|
|
|
|
try {
|
|
test();
|
|
} finally {
|
|
SetRB.executor.shutdownNow();
|
|
SetRBName.executor.shutdownNow();
|
|
}
|
|
}
|
|
|
|
/**
|
|
* Starts all threads, wait 15secs, then stops all threads.
|
|
* @throws Exception if a deadlock was detected or an error occurred.
|
|
*/
|
|
public static void test() throws Exception {
|
|
goOn = true;
|
|
thrown = null;
|
|
long sGetRBCount = getRBcount.get();
|
|
long sSetRBCount = setRBcount.get();
|
|
long sSetRBNameCount = setRBNameCount.get();
|
|
long sCheckCount = checkCount.get();
|
|
long sNextLong = nextLong.get();
|
|
long sIgnoreLogCount = ignoreLogCount.get();
|
|
List<Thread> threads = new ArrayList<>();
|
|
for (Class<? extends ResourceBundle> type : classes) {
|
|
threads.add(new SetRB(type));
|
|
threads.add(new SetRBName(type));
|
|
}
|
|
for (int i =0 ; i < READERS ; i++) {
|
|
threads.add(new GetRB());
|
|
}
|
|
threads.add(new DeadlockDetector());
|
|
threads.add(0, new Stopper(TIME));
|
|
for (Thread t : threads) {
|
|
t.start();
|
|
}
|
|
for (Thread t : threads) {
|
|
try {
|
|
t.join();
|
|
} catch (Exception x) {
|
|
fail(x);
|
|
}
|
|
}
|
|
if (thrown != null) {
|
|
throw thrown;
|
|
}
|
|
System.out.println("Passed: " + (nextLong.longValue() - sNextLong)
|
|
+ " unique loggers created");
|
|
System.out.println("\t " +(getRBcount.get() - sGetRBCount)
|
|
+ " loggers tested by " + READERS + " Thread(s),");
|
|
System.out.println("\t " + (setRBcount.get() - sSetRBCount)
|
|
+ " resource bundles set by " + classes.size() + " Thread(s),");
|
|
System.out.println("\t " + (setRBNameCount.get() - sSetRBNameCount)
|
|
+ " resource bundle names set by " + classes.size() + " Thread(s),");
|
|
System.out.println("\t " + (ignoreLogCount.get() - sIgnoreLogCount)
|
|
+ " log messages emitted by other GetRB threads were ignored"
|
|
+ " to ensure MT test consistency,");
|
|
System.out.println("\t ThreadMXBean.findDeadlockedThreads called "
|
|
+ (checkCount.get() -sCheckCount) + " times by 1 Thread.");
|
|
|
|
}
|
|
|
|
static final class GetRB extends Thread {
|
|
final class MyHandler extends Handler {
|
|
volatile ResourceBundle rb;
|
|
volatile String rbName;
|
|
volatile int count = 0;
|
|
@Override
|
|
public synchronized void publish(LogRecord record) {
|
|
Object[] params = record.getParameters();
|
|
// Each GetRB thread has its own handler, but since they
|
|
// log into the same logger, each handler may receive
|
|
// messages emitted by other threads.
|
|
// This means that GetRB#2.handler may receive a message
|
|
// emitted by GetRB#1 at a time where the resource bundle
|
|
// was still null.
|
|
// To avoid falling into this trap, the GetRB thread passes
|
|
// 'this' as argument to the messages it logs - which does
|
|
// allow us here to ignore messages that where not emitted
|
|
// by our own GetRB.this thread...
|
|
if (params.length == 1) {
|
|
if (params[0] == GetRB.this) {
|
|
// The message was emitted by our thread.
|
|
count++;
|
|
rb = record.getResourceBundle();
|
|
rbName = record.getResourceBundleName();
|
|
} else {
|
|
// The message was emitted by another thread: just
|
|
// ignore it, as it may have been emitted at a time
|
|
// where the resource bundle was still null, and
|
|
// processing it may overwrite the 'rb' and 'rbName'
|
|
// recorded from the message emitted by our own thread.
|
|
if (VERBOSE) {
|
|
System.out.println("Ignoring message logged by " + params[0]);
|
|
}
|
|
ignoreLogCount.incrementAndGet();
|
|
}
|
|
} else {
|
|
ignoreLogCount.incrementAndGet();
|
|
System.err.println("Unexpected message received");
|
|
}
|
|
}
|
|
|
|
void reset() {
|
|
rbName = null;
|
|
rb = null;
|
|
}
|
|
|
|
@Override
|
|
public void flush() {
|
|
}
|
|
|
|
@Override
|
|
public void close() throws SecurityException {
|
|
}
|
|
};
|
|
final MyHandler handler = new MyHandler();
|
|
|
|
@Override
|
|
public void run() {
|
|
try {
|
|
handler.setLevel(Level.FINEST);
|
|
while (goOn) {
|
|
Logger l;
|
|
Logger foo = Logger.getLogger("foo");
|
|
Logger bar = Logger.getLogger("foo.bar");
|
|
for (long i=0; i < nextLong.longValue() + 100 ; i++) {
|
|
if (!goOn) break;
|
|
l = Logger.getLogger("foo.bar.l"+i);
|
|
final ResourceBundle b = l.getResourceBundle();
|
|
final String name = l.getResourceBundleName();
|
|
if (b != null) {
|
|
if (!name.equals(b.getBaseBundleName())) {
|
|
throw new RuntimeException("Unexpected bundle name: "
|
|
+b.getBaseBundleName());
|
|
}
|
|
}
|
|
Logger ll = Logger.getLogger(l.getName()+".bie.bye");
|
|
ResourceBundle hrb;
|
|
String hrbName;
|
|
if (handler.getLevel() != Level.FINEST) {
|
|
throw new RuntimeException("Handler level is not finest: "
|
|
+ handler.getLevel());
|
|
}
|
|
final int countBefore = handler.count;
|
|
handler.reset();
|
|
ll.setLevel(Level.FINEST);
|
|
ll.addHandler(handler);
|
|
ll.log(Level.FINE, "dummy {0}", this);
|
|
ll.removeHandler(handler);
|
|
final int countAfter = handler.count;
|
|
if (countBefore == countAfter) {
|
|
throw new RuntimeException("Handler not called for "
|
|
+ ll.getName() + "("+ countAfter +")");
|
|
}
|
|
hrb = handler.rb;
|
|
hrbName = handler.rbName;
|
|
if (name != null) {
|
|
// if name is not null, then it implies that it
|
|
// won't change, since setResourceBundle() cannot
|
|
// replace a non null name.
|
|
// Since we never set the resource bundle on 'll',
|
|
// then ll must inherit its resource bundle [name]
|
|
// from l - and therefor we should find it in
|
|
// handler.rb/handler.rbName
|
|
if (!name.equals(hrbName)) {
|
|
throw new RuntimeException("Unexpected bundle name: "
|
|
+hrbName);
|
|
}
|
|
// here we know that hrbName is not null so hrb
|
|
// should not be null either.
|
|
if (!name.equals(hrb.getBaseBundleName())) {
|
|
throw new RuntimeException("Unexpected bundle name: "
|
|
+hrb.getBaseBundleName());
|
|
}
|
|
}
|
|
|
|
// Make sure to refer to 'l' explicitly in order to
|
|
// prevent eager garbage collecting before the end of
|
|
// the test (JDK-8030192)
|
|
if (!ll.getName().startsWith(l.getName())) {
|
|
throw new RuntimeException("Logger " + ll.getName()
|
|
+ "does not start with expected prefix "
|
|
+ l.getName());
|
|
}
|
|
|
|
getRBcount.incrementAndGet();
|
|
if (!goOn) break;
|
|
Thread.sleep(1);
|
|
}
|
|
}
|
|
} catch (Exception x) {
|
|
fail(x);
|
|
}
|
|
}
|
|
}
|
|
|
|
static final class SetRB extends Thread {
|
|
final Class<? extends ResourceBundle> type;
|
|
static final ExecutorService executor = Executors.newSingleThreadExecutor();
|
|
static final class CheckRBTask implements Callable<Exception> {
|
|
final Logger logger;
|
|
volatile String rbName;
|
|
volatile ResourceBundle rb;
|
|
|
|
public CheckRBTask(Logger logger) {
|
|
this.logger = logger;
|
|
}
|
|
|
|
@Override
|
|
public Exception call() throws Exception {
|
|
try {
|
|
final String name = logger.getResourceBundleName();
|
|
if (!Objects.equals(name, rbName)) {
|
|
throw new RuntimeException("Unexpected rbname for "
|
|
+ logger.getName() + ": " + name);
|
|
}
|
|
final ResourceBundle b = logger.getResourceBundle();
|
|
if (b != rb) {
|
|
throw new RuntimeException("Unexpected rb for "
|
|
+ logger.getName() + ": " + b);
|
|
}
|
|
} catch(Exception x) {
|
|
return x;
|
|
}
|
|
return null;
|
|
}
|
|
|
|
public void check() throws Exception {
|
|
final FutureTask<Exception> futureTask = new FutureTask<>(this);
|
|
executor.submit(futureTask);
|
|
Exception x = futureTask.get();
|
|
if ( x != null) {
|
|
throw new RuntimeException("Check failed: "+x,x);
|
|
}
|
|
}
|
|
}
|
|
SetRB(Class<? extends ResourceBundle> type) {
|
|
super("SetRB["+type.getSimpleName()+"]");
|
|
this.type = type;
|
|
}
|
|
@Override
|
|
public void run() {
|
|
try {
|
|
while (goOn) {
|
|
Logger l;
|
|
Logger foo = Logger.getLogger("foo");
|
|
Logger bar = Logger.getLogger("foo.bar");
|
|
l = Logger.getLogger("foo.bar.l"+nextLong.incrementAndGet());
|
|
final CheckRBTask checkTask = new CheckRBTask(l);
|
|
checkTask.check();
|
|
|
|
for (int i=0; i < LCOUNT ; i++) {
|
|
if (!goOn) break;
|
|
|
|
ResourceBundle b = ResourceBundle.getBundle(type.getName());
|
|
try {
|
|
l.setResourceBundle(b);
|
|
checkTask.rb = b;
|
|
checkTask.rbName = type.getName();
|
|
checkTask.check();
|
|
if (!goOn) break;
|
|
|
|
String name = l.getResourceBundleName();
|
|
ResourceBundle bb = l.getResourceBundle();
|
|
if (!type.getName().equals(name)) {
|
|
throw new RuntimeException(this.getName()
|
|
+ ": Unexpected name: "+name);
|
|
}
|
|
if (!b.getBaseBundleName().equals(name)) {
|
|
throw new RuntimeException(this.getName()
|
|
+ ": Unexpected base name: " +
|
|
b.getBaseBundleName());
|
|
}
|
|
if (b != bb) {
|
|
throw new RuntimeException(this.getName()
|
|
+ ": Unexpected bundle: "+bb);
|
|
}
|
|
setRBcount.incrementAndGet();
|
|
} catch (IllegalArgumentException x) {
|
|
final String name = l.getResourceBundleName();
|
|
if (!name.startsWith(MyBundle.class.getName())) {
|
|
throw new RuntimeException(this.getName()
|
|
+ ": Unexpected name: "+name, x);
|
|
} else if (type.getName().equals(name)) {
|
|
throw new RuntimeException(this.getName()
|
|
+ ": Unexpected exception for "+name, x);
|
|
}
|
|
throw x;
|
|
}
|
|
l.fine("I'm fine");
|
|
if (!goOn) break;
|
|
Thread.sleep(1);
|
|
}
|
|
}
|
|
} catch (Exception x) {
|
|
fail(x);
|
|
}
|
|
}
|
|
}
|
|
|
|
static final class SetRBName extends Thread {
|
|
int nexti = 0;
|
|
final Class<? extends ResourceBundle> type;
|
|
static final ExecutorService executor = Executors.newSingleThreadExecutor();
|
|
static final class CheckRBNameTask implements Callable<Exception> {
|
|
final Logger logger;
|
|
volatile String rbName;
|
|
|
|
public CheckRBNameTask(Logger logger) {
|
|
this.logger = logger;
|
|
}
|
|
|
|
@Override
|
|
public Exception call() throws Exception {
|
|
try {
|
|
final String name = logger.getResourceBundleName();
|
|
if (!Objects.equals(name, rbName)) {
|
|
throw new RuntimeException("Unexpected rbname for "
|
|
+ logger.getName() + ": " + name);
|
|
}
|
|
final ResourceBundle b = logger.getResourceBundle();
|
|
if (!Objects.equals(b == null ? null : b.getBaseBundleName(), rbName)) {
|
|
throw new RuntimeException("Unexpected base name for "
|
|
+ logger.getName() + ": " + b.getBaseBundleName());
|
|
}
|
|
} catch(Exception x) {
|
|
return x;
|
|
}
|
|
return null;
|
|
}
|
|
|
|
public void check() throws Exception {
|
|
final FutureTask<Exception> futureTask = new FutureTask<>(this);
|
|
executor.submit(futureTask);
|
|
Exception x = futureTask.get();
|
|
if ( x != null) {
|
|
throw new RuntimeException("Check failed: "+x,x);
|
|
}
|
|
}
|
|
|
|
}
|
|
SetRBName(Class<? extends ResourceBundle> type) {
|
|
super("SetRB["+type.getSimpleName()+"]");
|
|
this.type = type;
|
|
}
|
|
@Override
|
|
public void run() {
|
|
try {
|
|
while (goOn) {
|
|
Logger foo = Logger.getLogger("foo");
|
|
Logger bar = Logger.getLogger("foo.bar");
|
|
Logger l = Logger.getLogger("foo.bar.l"+nextLong.incrementAndGet());
|
|
final CheckRBNameTask checkTask = new CheckRBNameTask(l);
|
|
checkTask.check();
|
|
|
|
for (int i=0; i < LCOUNT ; i++) {
|
|
if (!goOn) break;
|
|
|
|
try {
|
|
Logger l2 = Logger.getLogger(l.getName(), type.getName());
|
|
if (l2 != l) {
|
|
System.err.println("**** ERROR WITH "+l.getName());
|
|
throw new RuntimeException("l2 != l ["
|
|
+ l2 + "(" + l2.getName() + ") != "
|
|
+ l + "(" + l.getName() + ")]");
|
|
}
|
|
checkTask.rbName = type.getName();
|
|
checkTask.check();
|
|
if (!goOn) break;
|
|
|
|
String name = l.getResourceBundleName();
|
|
ResourceBundle bb = l.getResourceBundle();
|
|
if (!type.getName().equals(name)) {
|
|
throw new RuntimeException(this.getName()
|
|
+ ": Unexpected name: "+name);
|
|
}
|
|
if (!bb.getBaseBundleName().equals(name)) {
|
|
throw new RuntimeException(this.getName()
|
|
+ ": Unexpected base name: "
|
|
+ bb.getBaseBundleName());
|
|
}
|
|
setRBNameCount.incrementAndGet();
|
|
} catch (IllegalArgumentException x) {
|
|
final String name = l.getResourceBundleName();
|
|
if (!name.startsWith(MyBundle.class.getName())) {
|
|
throw new RuntimeException(this.getName()
|
|
+ ": Unexpected name: "+name, x);
|
|
} else if (type.getName().equals(name)) {
|
|
throw new RuntimeException(this.getName()
|
|
+ ": Unexpected exception for "+name, x);
|
|
}
|
|
throw x;
|
|
}
|
|
l.fine("I'm fine");
|
|
if (!goOn) break;
|
|
Thread.sleep(1);
|
|
}
|
|
}
|
|
} catch (Exception x) {
|
|
fail(x);
|
|
}
|
|
}
|
|
}
|
|
|
|
static final class DeadlockDetector extends Thread {
|
|
|
|
@Override
|
|
public void run() {
|
|
while(goOn) {
|
|
try {
|
|
long[] ids = ManagementFactory.getThreadMXBean().findDeadlockedThreads();
|
|
checkCount.incrementAndGet();
|
|
ids = ids == null ? new long[0] : ids;
|
|
if (ids.length == 1) {
|
|
throw new RuntimeException("Found 1 deadlocked thread: "+ids[0]);
|
|
} else if (ids.length > 0) {
|
|
ThreadInfo[] infos = ManagementFactory.getThreadMXBean().getThreadInfo(ids);
|
|
System.err.println("Found "+ids.length+" deadlocked threads: ");
|
|
for (ThreadInfo inf : infos) {
|
|
System.err.println(inf.toString());
|
|
}
|
|
throw new RuntimeException("Found "+ids.length+" deadlocked threads");
|
|
}
|
|
Thread.sleep(100);
|
|
} catch(InterruptedException | RuntimeException x) {
|
|
fail(x);
|
|
}
|
|
}
|
|
}
|
|
|
|
}
|
|
|
|
static final class Stopper extends Thread {
|
|
long start;
|
|
long time;
|
|
|
|
Stopper(long time) {
|
|
start = System.currentTimeMillis();
|
|
this.time = time;
|
|
}
|
|
|
|
@Override
|
|
public void run() {
|
|
try {
|
|
long rest, previous;
|
|
previous = time;
|
|
while (goOn && (rest = start - System.currentTimeMillis() + time) > 0) {
|
|
if (previous == time || previous - rest >= STEP) {
|
|
Logger.getLogger("remaining").info(String.valueOf(rest)+"ms remaining...");
|
|
previous = rest == time ? rest -1 : rest;
|
|
System.gc();
|
|
}
|
|
if (goOn == false) break;
|
|
Thread.sleep(Math.min(rest, 100));
|
|
}
|
|
System.out.println(System.currentTimeMillis() - start
|
|
+ " ms elapsed ("+time+ " requested)");
|
|
goOn = false;
|
|
} catch(InterruptedException | RuntimeException x) {
|
|
fail(x);
|
|
}
|
|
}
|
|
|
|
}
|
|
|
|
static void fail(Exception x) {
|
|
x.printStackTrace();
|
|
if (thrown == null) {
|
|
thrown = x;
|
|
}
|
|
goOn = false;
|
|
}
|
|
}
|