8077846: improve locking strategy for readConfiguration(), reset(), and initializeGlobalHandlers()
Co-authored-by: Daniel Fuchs <daniel.fuchs@oracle.com> Reviewed-by: dholmes, alanb, mchung
This commit is contained in:
parent
cbe55b316e
commit
30bcd97f81
@ -33,6 +33,7 @@ import java.lang.ref.ReferenceQueue;
|
|||||||
import java.lang.ref.WeakReference;
|
import java.lang.ref.WeakReference;
|
||||||
import java.util.concurrent.ConcurrentHashMap;
|
import java.util.concurrent.ConcurrentHashMap;
|
||||||
import java.util.concurrent.CopyOnWriteArrayList;
|
import java.util.concurrent.CopyOnWriteArrayList;
|
||||||
|
import java.util.concurrent.locks.ReentrantLock;
|
||||||
import sun.misc.JavaAWTAccess;
|
import sun.misc.JavaAWTAccess;
|
||||||
import sun.misc.ManagedLocalsThread;
|
import sun.misc.ManagedLocalsThread;
|
||||||
import sun.misc.SharedSecrets;
|
import sun.misc.SharedSecrets;
|
||||||
@ -180,10 +181,16 @@ public class LogManager {
|
|||||||
// initialization has been done)
|
// initialization has been done)
|
||||||
private volatile boolean readPrimordialConfiguration;
|
private volatile boolean readPrimordialConfiguration;
|
||||||
// Have we initialized global (root) handlers yet?
|
// Have we initialized global (root) handlers yet?
|
||||||
// This gets set to false in readConfiguration
|
// This gets set to STATE_UNINITIALIZED in readConfiguration
|
||||||
private boolean initializedGlobalHandlers = true;
|
private static final int
|
||||||
// True if JVM death is imminent and the exit hook has been called.
|
STATE_INITIALIZED = 0, // initial state
|
||||||
private boolean deathImminent;
|
STATE_INITIALIZING = 1,
|
||||||
|
STATE_READING_CONFIG = 2,
|
||||||
|
STATE_UNINITIALIZED = 3,
|
||||||
|
STATE_SHUTDOWN = 4; // terminal state
|
||||||
|
private volatile int globalHandlersState; // = STATE_INITIALIZED;
|
||||||
|
// A concurrency lock for reset(), readConfiguration() and Cleaner.
|
||||||
|
private final ReentrantLock configurationLock = new ReentrantLock();
|
||||||
|
|
||||||
// This list contains the loggers for which some handlers have been
|
// This list contains the loggers for which some handlers have been
|
||||||
// explicitly configured in the configuration file.
|
// explicitly configured in the configuration file.
|
||||||
@ -264,13 +271,12 @@ public class LogManager {
|
|||||||
// before synchronized block. Otherwise deadlocks are possible.
|
// before synchronized block. Otherwise deadlocks are possible.
|
||||||
LogManager mgr = manager;
|
LogManager mgr = manager;
|
||||||
|
|
||||||
// If the global handlers haven't been initialized yet, we
|
// set globalHandlersState to STATE_SHUTDOWN atomically so that
|
||||||
// don't want to initialize them just so we can close them!
|
// no attempts are made to (re)initialize the handlers or (re)read
|
||||||
synchronized (LogManager.this) {
|
// the configuration again. This is terminal state.
|
||||||
// Note that death is imminent.
|
configurationLock.lock();
|
||||||
deathImminent = true;
|
globalHandlersState = STATE_SHUTDOWN;
|
||||||
initializedGlobalHandlers = true;
|
configurationLock.unlock();
|
||||||
}
|
|
||||||
|
|
||||||
// Do a reset to close all active handlers.
|
// Do a reset to close all active handlers.
|
||||||
reset();
|
reset();
|
||||||
@ -1314,8 +1320,14 @@ public class LogManager {
|
|||||||
|
|
||||||
public void reset() throws SecurityException {
|
public void reset() throws SecurityException {
|
||||||
checkPermission();
|
checkPermission();
|
||||||
|
|
||||||
List<CloseOnReset> persistent;
|
List<CloseOnReset> persistent;
|
||||||
synchronized (this) {
|
|
||||||
|
// We don't want reset() and readConfiguration()
|
||||||
|
// to run in parallel
|
||||||
|
configurationLock.lock();
|
||||||
|
try {
|
||||||
|
// install new empty properties
|
||||||
props = new Properties();
|
props = new Properties();
|
||||||
// make sure we keep the loggers persistent until reset is done.
|
// make sure we keep the loggers persistent until reset is done.
|
||||||
// Those are the loggers for which we previously created a
|
// Those are the loggers for which we previously created a
|
||||||
@ -1323,26 +1335,41 @@ public class LogManager {
|
|||||||
// from being gc'ed until those handlers are closed.
|
// from being gc'ed until those handlers are closed.
|
||||||
persistent = new ArrayList<>(closeOnResetLoggers);
|
persistent = new ArrayList<>(closeOnResetLoggers);
|
||||||
closeOnResetLoggers.clear();
|
closeOnResetLoggers.clear();
|
||||||
// Since we are doing a reset we no longer want to initialize
|
|
||||||
// the global handlers, if they haven't been initialized yet.
|
// if reset has been called from shutdown-hook (Cleaner),
|
||||||
initializedGlobalHandlers = true;
|
// or if reset has been called from readConfiguration() which
|
||||||
}
|
// already holds the lock and will change the state itself,
|
||||||
for (LoggerContext cx : contexts()) {
|
// then do not change state here...
|
||||||
Enumeration<String> enum_ = cx.getLoggerNames();
|
if (globalHandlersState != STATE_SHUTDOWN &&
|
||||||
while (enum_.hasMoreElements()) {
|
globalHandlersState != STATE_READING_CONFIG) {
|
||||||
String name = enum_.nextElement();
|
// ...else user called reset()...
|
||||||
Logger logger = cx.findLogger(name);
|
// Since we are doing a reset we no longer want to initialize
|
||||||
if (logger != null) {
|
// the global handlers, if they haven't been initialized yet.
|
||||||
resetLogger(logger);
|
globalHandlersState = STATE_INITIALIZED;
|
||||||
}
|
|
||||||
}
|
}
|
||||||
|
|
||||||
|
for (LoggerContext cx : contexts()) {
|
||||||
|
resetLoggerContext(cx);
|
||||||
|
}
|
||||||
|
|
||||||
|
persistent.clear();
|
||||||
|
} finally {
|
||||||
|
configurationLock.unlock();
|
||||||
}
|
}
|
||||||
persistent.clear();
|
|
||||||
}
|
}
|
||||||
|
|
||||||
// Private method to reset an individual target logger.
|
private void resetLoggerContext(LoggerContext cx) {
|
||||||
private void resetLogger(Logger logger) {
|
Enumeration<String> enum_ = cx.getLoggerNames();
|
||||||
// Close all the Logger's handlers.
|
while (enum_.hasMoreElements()) {
|
||||||
|
String name = enum_.nextElement();
|
||||||
|
Logger logger = cx.findLogger(name);
|
||||||
|
if (logger != null) {
|
||||||
|
resetLogger(logger);
|
||||||
|
}
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
private void closeHandlers(Logger logger) {
|
||||||
Handler[] targets = logger.getHandlers();
|
Handler[] targets = logger.getHandlers();
|
||||||
for (Handler h : targets) {
|
for (Handler h : targets) {
|
||||||
logger.removeHandler(h);
|
logger.removeHandler(h);
|
||||||
@ -1352,6 +1379,14 @@ public class LogManager {
|
|||||||
// Problems closing a handler? Keep going...
|
// Problems closing a handler? Keep going...
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
// Private method to reset an individual target logger.
|
||||||
|
private void resetLogger(Logger logger) {
|
||||||
|
// Close all the Logger handlers.
|
||||||
|
closeHandlers(logger);
|
||||||
|
|
||||||
|
// Reset Logger level
|
||||||
String name = logger.getName();
|
String name = logger.getName();
|
||||||
if (name != null && name.equals("")) {
|
if (name != null && name.equals("")) {
|
||||||
// This is the root logger.
|
// This is the root logger.
|
||||||
@ -1408,48 +1443,74 @@ public class LogManager {
|
|||||||
*/
|
*/
|
||||||
public void readConfiguration(InputStream ins) throws IOException, SecurityException {
|
public void readConfiguration(InputStream ins) throws IOException, SecurityException {
|
||||||
checkPermission();
|
checkPermission();
|
||||||
reset();
|
|
||||||
|
|
||||||
// Load the properties
|
// We don't want reset() and readConfiguration() to run
|
||||||
|
// in parallel.
|
||||||
|
configurationLock.lock();
|
||||||
try {
|
try {
|
||||||
props.load(ins);
|
if (globalHandlersState == STATE_SHUTDOWN) {
|
||||||
} catch (IllegalArgumentException x) {
|
// already in terminal state: don't even bother
|
||||||
// props.load may throw an IllegalArgumentException if the stream
|
// to read the configuration
|
||||||
// contains malformed Unicode escape sequences.
|
return;
|
||||||
// We wrap that in an IOException as readConfiguration is
|
}
|
||||||
// specified to throw IOException if there are problems reading
|
|
||||||
// from the stream.
|
|
||||||
// Note: new IOException(x.getMessage(), x) allow us to get a more
|
|
||||||
// concise error message than new IOException(x);
|
|
||||||
throw new IOException(x.getMessage(), x);
|
|
||||||
}
|
|
||||||
|
|
||||||
// Instantiate new configuration objects.
|
// change state to STATE_READING_CONFIG to signal reset() to not change it
|
||||||
String names[] = parseClassNames("config");
|
globalHandlersState = STATE_READING_CONFIG;
|
||||||
|
|
||||||
for (String word : names) {
|
|
||||||
try {
|
try {
|
||||||
Class<?> clz = ClassLoader.getSystemClassLoader().loadClass(word);
|
// reset configuration which leaves globalHandlersState at STATE_READING_CONFIG
|
||||||
clz.newInstance();
|
// so that while reading configuration, any ongoing logging requests block and
|
||||||
} catch (Exception ex) {
|
// wait for the outcome (see the end of this try statement)
|
||||||
System.err.println("Can't load config class \"" + word + "\"");
|
reset();
|
||||||
System.err.println("" + ex);
|
|
||||||
// ex.printStackTrace();
|
try {
|
||||||
|
// Load the properties
|
||||||
|
props.load(ins);
|
||||||
|
} catch (IllegalArgumentException x) {
|
||||||
|
// props.load may throw an IllegalArgumentException if the stream
|
||||||
|
// contains malformed Unicode escape sequences.
|
||||||
|
// We wrap that in an IOException as readConfiguration is
|
||||||
|
// specified to throw IOException if there are problems reading
|
||||||
|
// from the stream.
|
||||||
|
// Note: new IOException(x.getMessage(), x) allow us to get a more
|
||||||
|
// concise error message than new IOException(x);
|
||||||
|
throw new IOException(x.getMessage(), x);
|
||||||
|
}
|
||||||
|
|
||||||
|
// Instantiate new configuration objects.
|
||||||
|
String names[] = parseClassNames("config");
|
||||||
|
|
||||||
|
for (String word : names) {
|
||||||
|
try {
|
||||||
|
Class<?> clz = ClassLoader.getSystemClassLoader().loadClass(word);
|
||||||
|
clz.newInstance();
|
||||||
|
} catch (Exception ex) {
|
||||||
|
System.err.println("Can't load config class \"" + word + "\"");
|
||||||
|
System.err.println("" + ex);
|
||||||
|
// ex.printStackTrace();
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
// Set levels on any pre-existing loggers, based on the new properties.
|
||||||
|
setLevelsOnExistingLoggers();
|
||||||
|
|
||||||
|
// Note that we need to reinitialize global handles when
|
||||||
|
// they are first referenced.
|
||||||
|
globalHandlersState = STATE_UNINITIALIZED;
|
||||||
|
} catch (Throwable t) {
|
||||||
|
// If there were any trouble, then set state to STATE_INITIALIZED
|
||||||
|
// so that no global handlers reinitialization is performed on not fully
|
||||||
|
// initialized configuration.
|
||||||
|
globalHandlersState = STATE_INITIALIZED;
|
||||||
|
// re-throw
|
||||||
|
throw t;
|
||||||
}
|
}
|
||||||
}
|
|
||||||
|
|
||||||
// Set levels on any pre-existing loggers, based on the new properties.
|
|
||||||
setLevelsOnExistingLoggers();
|
|
||||||
|
|
||||||
try {
|
|
||||||
invokeConfigurationListeners();
|
|
||||||
} finally {
|
} finally {
|
||||||
// Note that we need to reinitialize global handles when
|
configurationLock.unlock();
|
||||||
// they are first referenced.
|
|
||||||
synchronized (this) {
|
|
||||||
initializedGlobalHandlers = false;
|
|
||||||
}
|
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// should be called out of lock to avoid dead-lock situations
|
||||||
|
// when user code is involved
|
||||||
|
invokeConfigurationListeners();
|
||||||
}
|
}
|
||||||
|
|
||||||
/**
|
/**
|
||||||
@ -1576,20 +1637,41 @@ public class LogManager {
|
|||||||
// Private method to load the global handlers.
|
// Private method to load the global handlers.
|
||||||
// We do the real work lazily, when the global handlers
|
// We do the real work lazily, when the global handlers
|
||||||
// are first used.
|
// are first used.
|
||||||
private synchronized void initializeGlobalHandlers() {
|
private void initializeGlobalHandlers() {
|
||||||
if (initializedGlobalHandlers) {
|
int state = globalHandlersState;
|
||||||
|
if (state == STATE_INITIALIZED ||
|
||||||
|
state == STATE_SHUTDOWN) {
|
||||||
|
// Nothing to do: return.
|
||||||
return;
|
return;
|
||||||
}
|
}
|
||||||
|
|
||||||
initializedGlobalHandlers = true;
|
// If we have not initialized global handlers yet (or need to
|
||||||
|
// reinitialize them), lets do it now (this case is indicated by
|
||||||
if (deathImminent) {
|
// globalHandlersState == STATE_UNINITIALIZED).
|
||||||
// Aaargh...
|
// If we are in the process of initializing global handlers we
|
||||||
// The VM is shutting down and our exit hook has been called.
|
// also need to lock & wait (this case is indicated by
|
||||||
// Avoid allocating global handlers.
|
// globalHandlersState == STATE_INITIALIZING).
|
||||||
return;
|
// If we are in the process of reading configuration we also need to
|
||||||
|
// wait to see what the outcome will be (this case
|
||||||
|
// is indicated by globalHandlersState == STATE_READING_CONFIG)
|
||||||
|
// So in either case we need to wait for the lock.
|
||||||
|
configurationLock.lock();
|
||||||
|
try {
|
||||||
|
if (globalHandlersState != STATE_UNINITIALIZED) {
|
||||||
|
return; // recursive call or nothing to do
|
||||||
|
}
|
||||||
|
// set globalHandlersState to STATE_INITIALIZING first to avoid
|
||||||
|
// getting an infinite recursion when loadLoggerHandlers(...)
|
||||||
|
// is going to call addHandler(...)
|
||||||
|
globalHandlersState = STATE_INITIALIZING;
|
||||||
|
try {
|
||||||
|
loadLoggerHandlers(rootLogger, null, "handlers");
|
||||||
|
} finally {
|
||||||
|
globalHandlersState = STATE_INITIALIZED;
|
||||||
|
}
|
||||||
|
} finally {
|
||||||
|
configurationLock.unlock();
|
||||||
}
|
}
|
||||||
loadLoggerHandlers(rootLogger, null, "handlers");
|
|
||||||
}
|
}
|
||||||
|
|
||||||
static final Permission controlPermission = new LoggingPermission("control", null);
|
static final Permission controlPermission = new LoggingPermission("control", null);
|
||||||
@ -1684,7 +1766,7 @@ public class LogManager {
|
|||||||
|
|
||||||
// Private method to be called when the configuration has
|
// Private method to be called when the configuration has
|
||||||
// changed to apply any level settings to any pre-existing loggers.
|
// changed to apply any level settings to any pre-existing loggers.
|
||||||
synchronized private void setLevelsOnExistingLoggers() {
|
private void setLevelsOnExistingLoggers() {
|
||||||
Enumeration<?> enum_ = props.propertyNames();
|
Enumeration<?> enum_ = props.propertyNames();
|
||||||
while (enum_.hasMoreElements()) {
|
while (enum_.hasMoreElements()) {
|
||||||
String key = (String)enum_.nextElement();
|
String key = (String)enum_.nextElement();
|
||||||
|
@ -0,0 +1,457 @@
|
|||||||
|
/*
|
||||||
|
* Copyright (c) 2015, 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.io.File;
|
||||||
|
import java.io.IOException;
|
||||||
|
import java.lang.management.LockInfo;
|
||||||
|
import java.lang.management.ManagementFactory;
|
||||||
|
import java.lang.management.MonitorInfo;
|
||||||
|
import java.lang.management.ThreadInfo;
|
||||||
|
import java.security.Permission;
|
||||||
|
import java.security.Policy;
|
||||||
|
import java.security.ProtectionDomain;
|
||||||
|
import java.util.ArrayList;
|
||||||
|
import java.util.List;
|
||||||
|
import java.util.concurrent.atomic.AtomicLong;
|
||||||
|
import java.util.logging.Level;
|
||||||
|
import java.util.logging.LogManager;
|
||||||
|
import java.util.logging.Logger;
|
||||||
|
|
||||||
|
|
||||||
|
/**
|
||||||
|
* @test
|
||||||
|
* @bug 8077846
|
||||||
|
* @key randomness
|
||||||
|
* @summary Test that using a reentrant configuration lock does not introduce
|
||||||
|
* new synchronization issues in Logger and LogManager. This test
|
||||||
|
* focuses more particularly on potential deadlock in
|
||||||
|
* drainLoggerRefQueueBounded / readConfiguration / reset
|
||||||
|
* todo: add at randomness
|
||||||
|
* @run main/othervm TestConfigurationLock
|
||||||
|
* @author danielfuchs
|
||||||
|
*/
|
||||||
|
// This test is a best effort to try & detect issues. The test itself will run
|
||||||
|
// for 8secs. This might be unsufficient to detect issues.
|
||||||
|
// To get a greater confidence it is recommended to run this test in a loop:
|
||||||
|
// e.g. use something like:
|
||||||
|
// $ while jtreg -jdk:$JDK -verbose:all \
|
||||||
|
// test/java/util/logging/TestConfigurationLock.java ; \
|
||||||
|
// do echo Running test again ; done
|
||||||
|
// and let it run for a few hours...
|
||||||
|
//
|
||||||
|
public class TestConfigurationLock {
|
||||||
|
|
||||||
|
static volatile Exception thrown = null;
|
||||||
|
static volatile boolean goOn = true;
|
||||||
|
static volatile boolean deadlock = false;
|
||||||
|
|
||||||
|
static final double CONFSYNCTHRESHOLD = 0.3;
|
||||||
|
static final double LOGSYNCTHRESHOLD = 0.3;
|
||||||
|
static final int RESETERS = 0;
|
||||||
|
static final int READERS = 3;
|
||||||
|
static final int LOGGERS = 4;
|
||||||
|
static final long TIME = 8 * 1000; // 8 sec.
|
||||||
|
static final long STEP = 1 * 1000; // message every 1 sec.
|
||||||
|
static final int LCOUNT = 50; // 50 loggers created in a row...
|
||||||
|
static final AtomicLong nextLogger = new AtomicLong(0);
|
||||||
|
static final AtomicLong resetCount = new AtomicLong(0);
|
||||||
|
static final AtomicLong readCount = new AtomicLong(0);
|
||||||
|
static final AtomicLong checkCount = new AtomicLong(0);
|
||||||
|
|
||||||
|
static final String BLAH = "blah";
|
||||||
|
|
||||||
|
static Object fakeConfExternalLock() {
|
||||||
|
return LogManager.getLogManager();
|
||||||
|
}
|
||||||
|
|
||||||
|
static Object fakeLogExternalLock() {
|
||||||
|
return LogManager.getLogManager();
|
||||||
|
}
|
||||||
|
|
||||||
|
|
||||||
|
/**
|
||||||
|
* This test will run both with and without a security manager.
|
||||||
|
*
|
||||||
|
* The test starts a number of threads that will call
|
||||||
|
* LogManager.reset() concurrently (ResetConf), and a number of threads
|
||||||
|
* that will call readConfiguration() (ReadConf), and then starts a
|
||||||
|
* number of threads that will create new loggers concurrently
|
||||||
|
* (AddLogger), and finally two additional threads:
|
||||||
|
* - one (Stopper) that will stop the test after 4secs (TIME ms),
|
||||||
|
* - and one DeadlockDetector that will attempt to detect deadlocks.
|
||||||
|
* If after 4secs no deadlock was detected and no exception was thrown
|
||||||
|
* then the test is considered a success and passes.
|
||||||
|
*
|
||||||
|
* This procedure is done twice: once without a security manager and once
|
||||||
|
* again with a security manager - which means the test takes ~8secs to
|
||||||
|
* run.
|
||||||
|
*
|
||||||
|
* Note that 8sec may not be enough to detect issues if there are some.
|
||||||
|
* This is a best effort test.
|
||||||
|
*
|
||||||
|
* @param args the command line arguments
|
||||||
|
* @throws java.lang.Exception if the test fails
|
||||||
|
*/
|
||||||
|
public static void main(String[] args) throws Exception {
|
||||||
|
|
||||||
|
File conf = new File(System.getProperty("test.src", "./src"),
|
||||||
|
TestConfigurationLock.class.getSimpleName() + ".properties");
|
||||||
|
if (!conf.canRead()) {
|
||||||
|
throw new IOException("Can't read config file: " + conf.getAbsolutePath());
|
||||||
|
}
|
||||||
|
System.setProperty("java.util.logging.config.file", conf.getAbsolutePath());
|
||||||
|
// test without security
|
||||||
|
System.out.println("No security");
|
||||||
|
test();
|
||||||
|
|
||||||
|
// test with security
|
||||||
|
System.out.println("\nWith security");
|
||||||
|
Policy.setPolicy(new Policy() {
|
||||||
|
@Override
|
||||||
|
public boolean implies(ProtectionDomain domain, Permission permission) {
|
||||||
|
if (super.implies(domain, permission)) return true;
|
||||||
|
// System.out.println("Granting " + permission);
|
||||||
|
return true; // all permissions
|
||||||
|
}
|
||||||
|
});
|
||||||
|
System.setSecurityManager(new SecurityManager());
|
||||||
|
test();
|
||||||
|
}
|
||||||
|
|
||||||
|
|
||||||
|
/**
|
||||||
|
* Starts all threads, wait 4secs, 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 sNextLogger = nextLogger.get();
|
||||||
|
long sUpdateCount = resetCount.get();
|
||||||
|
long sReadCount = readCount.get();
|
||||||
|
long sCheckCount = checkCount.get();
|
||||||
|
List<Thread> threads = new ArrayList<>();
|
||||||
|
for (int i = 0; i<RESETERS; i++) {
|
||||||
|
threads.add(new ResetConf());
|
||||||
|
}
|
||||||
|
for (int i = 0; i<READERS; i++) {
|
||||||
|
threads.add(new ReadConf());
|
||||||
|
}
|
||||||
|
for (int i = 0; i<LOGGERS; i++) {
|
||||||
|
threads.add(new AddLogger());
|
||||||
|
}
|
||||||
|
threads.add(0, new Stopper(TIME));
|
||||||
|
threads.stream().forEach(Thread::start);
|
||||||
|
|
||||||
|
Thread deadLockDetector = new DeadlockDetector();
|
||||||
|
deadLockDetector.start();
|
||||||
|
deadLockDetector.join();
|
||||||
|
|
||||||
|
if (!deadlock) {
|
||||||
|
threads.stream().forEach(TestConfigurationLock::join);
|
||||||
|
} else {
|
||||||
|
System.err.println("Deadlock found: exiting forcibly.");
|
||||||
|
Runtime.getRuntime().halt(-1);
|
||||||
|
}
|
||||||
|
|
||||||
|
if (thrown != null) {
|
||||||
|
throw thrown;
|
||||||
|
}
|
||||||
|
System.out.println("Passed: " + (nextLogger.get() - sNextLogger)
|
||||||
|
+ " loggers created by " + LOGGERS + " Thread(s),");
|
||||||
|
System.out.println("\t LogManager.reset() called "
|
||||||
|
+ (resetCount.get() - sUpdateCount) + " times by " + RESETERS
|
||||||
|
+ " Thread(s).");
|
||||||
|
System.out.println("\t LogManager.readConfiguration() called "
|
||||||
|
+ (readCount.get() - sReadCount) + " times by " + READERS
|
||||||
|
+ " Thread(s).");
|
||||||
|
System.out.println("\t ThreadMXBean.findDeadlockedThreads called "
|
||||||
|
+ (checkCount.get() -sCheckCount) + " times by 1 Thread.");
|
||||||
|
|
||||||
|
}
|
||||||
|
|
||||||
|
static void join(Thread t) {
|
||||||
|
try {
|
||||||
|
t.join();
|
||||||
|
} catch (Exception x) {
|
||||||
|
fail(x);
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
final static class ResetConf extends Thread {
|
||||||
|
|
||||||
|
public ResetConf() {
|
||||||
|
setDaemon(true);
|
||||||
|
}
|
||||||
|
|
||||||
|
@Override
|
||||||
|
public void run() {
|
||||||
|
while (goOn) {
|
||||||
|
try {
|
||||||
|
if (Math.random() > CONFSYNCTHRESHOLD) {
|
||||||
|
// calling reset while holding a lock can increase
|
||||||
|
// deadlock probability...
|
||||||
|
synchronized(fakeConfExternalLock()) {
|
||||||
|
LogManager.getLogManager().reset();
|
||||||
|
}
|
||||||
|
} else {
|
||||||
|
LogManager.getLogManager().reset();
|
||||||
|
}
|
||||||
|
Logger blah = Logger.getLogger(BLAH);
|
||||||
|
blah.setLevel(Level.FINEST);
|
||||||
|
blah.fine(BLAH);
|
||||||
|
resetCount.incrementAndGet();
|
||||||
|
pause(1);
|
||||||
|
} catch (Exception x) {
|
||||||
|
fail(x);
|
||||||
|
}
|
||||||
|
}
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
final static class ReadConf extends Thread {
|
||||||
|
|
||||||
|
public ReadConf() {
|
||||||
|
setDaemon(true);
|
||||||
|
}
|
||||||
|
|
||||||
|
@Override
|
||||||
|
public void run() {
|
||||||
|
while (goOn) {
|
||||||
|
try {
|
||||||
|
if (Math.random() > CONFSYNCTHRESHOLD) {
|
||||||
|
// calling readConfiguration while holding a lock can
|
||||||
|
// increase deadlock probability...
|
||||||
|
synchronized(fakeConfExternalLock()) {
|
||||||
|
LogManager.getLogManager().readConfiguration();
|
||||||
|
}
|
||||||
|
} else {
|
||||||
|
LogManager.getLogManager().readConfiguration();
|
||||||
|
}
|
||||||
|
Logger blah = Logger.getLogger(BLAH);
|
||||||
|
blah.setLevel(Level.FINEST);
|
||||||
|
blah.fine(BLAH);
|
||||||
|
readCount.incrementAndGet();
|
||||||
|
pause(1);
|
||||||
|
} catch (Exception x) {
|
||||||
|
fail(x);
|
||||||
|
}
|
||||||
|
}
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
final static class AddLogger extends Thread {
|
||||||
|
|
||||||
|
public AddLogger() {
|
||||||
|
setDaemon(true);
|
||||||
|
}
|
||||||
|
|
||||||
|
@Override
|
||||||
|
public void run() {
|
||||||
|
try {
|
||||||
|
while (goOn) {
|
||||||
|
Logger l;
|
||||||
|
Logger foo = Logger.getLogger("foo");
|
||||||
|
Logger bar = Logger.getLogger("foo.bar");
|
||||||
|
for (int i=0; i < LCOUNT ; i++) {
|
||||||
|
LogManager manager = LogManager.getLogManager();
|
||||||
|
if (Math.random() > LOGSYNCTHRESHOLD) {
|
||||||
|
synchronized(fakeLogExternalLock()) {
|
||||||
|
l = Logger.getLogger("foo.bar.l"+nextLogger.incrementAndGet());
|
||||||
|
}
|
||||||
|
} else {
|
||||||
|
l = Logger.getLogger("foo.bar.l"+nextLogger.incrementAndGet());
|
||||||
|
}
|
||||||
|
l.setLevel(Level.FINEST);
|
||||||
|
l.fine("I'm fine");
|
||||||
|
if (!goOn) break;
|
||||||
|
pause(1);
|
||||||
|
}
|
||||||
|
}
|
||||||
|
} catch (InterruptedException | RuntimeException x ) {
|
||||||
|
fail(x);
|
||||||
|
}
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
final static class DeadlockDetector extends Thread {
|
||||||
|
|
||||||
|
@Override
|
||||||
|
public void run() {
|
||||||
|
boolean deadlock = false;
|
||||||
|
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) {
|
||||||
|
deadlock = true;
|
||||||
|
ThreadInfo[] infos = ManagementFactory.getThreadMXBean()
|
||||||
|
.getThreadInfo(ids, true, true);
|
||||||
|
System.err.println("Found "+ids.length+" deadlocked threads: ");
|
||||||
|
for (ThreadInfo inf : infos) {
|
||||||
|
System.err.println(asString(inf));
|
||||||
|
}
|
||||||
|
throw new RuntimeException("Found "+ids.length+" deadlocked threads");
|
||||||
|
}
|
||||||
|
pause(100);
|
||||||
|
} catch(InterruptedException | RuntimeException x) {
|
||||||
|
if (deadlock) deadlock(x);
|
||||||
|
else fail(x);
|
||||||
|
}
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
}
|
||||||
|
|
||||||
|
static final class Stopper extends Thread {
|
||||||
|
long start;
|
||||||
|
long time;
|
||||||
|
|
||||||
|
Stopper(long time) {
|
||||||
|
start = System.currentTimeMillis();
|
||||||
|
this.time = time;
|
||||||
|
setDaemon(true);
|
||||||
|
}
|
||||||
|
|
||||||
|
@Override
|
||||||
|
public void run() {
|
||||||
|
try {
|
||||||
|
long rest, previous;
|
||||||
|
int msgCount = 0;
|
||||||
|
previous = time;
|
||||||
|
Logger logger = Logger.getLogger("remaining");
|
||||||
|
while (goOn && (rest = start - System.currentTimeMillis() + time) > 0) {
|
||||||
|
if (previous == time || previous - rest >= STEP) {
|
||||||
|
logger.log(Level.INFO, "{0}ms remaining...", String.valueOf(rest));
|
||||||
|
msgCount++;
|
||||||
|
previous = rest == time ? rest -1 : rest;
|
||||||
|
System.gc();
|
||||||
|
}
|
||||||
|
if (goOn == false) break;
|
||||||
|
pause(Math.min(rest, 100));
|
||||||
|
}
|
||||||
|
System.err.println(this + ": " + msgCount + " messages.");
|
||||||
|
System.err.flush();
|
||||||
|
System.out.println(System.currentTimeMillis() - start
|
||||||
|
+ " ms elapsed ("+time+ " requested)");
|
||||||
|
goOn = false;
|
||||||
|
} catch(InterruptedException | RuntimeException x) {
|
||||||
|
fail(x);
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
}
|
||||||
|
|
||||||
|
// ThreadInfo.toString() only prints 8 frames...
|
||||||
|
static String asString(ThreadInfo inf) {
|
||||||
|
StringBuilder sb = new StringBuilder();
|
||||||
|
sb.append("\"").append(inf.getThreadName()).append("\"")
|
||||||
|
.append(inf.isDaemon() ? " daemon" : "")
|
||||||
|
.append(" prio=").append(inf.getPriority())
|
||||||
|
.append(" Id=").append(inf.getThreadId())
|
||||||
|
.append(" ").append(inf.getThreadState());
|
||||||
|
if (inf.getLockName() != null) {
|
||||||
|
sb.append(" on ").append(inf.getLockName());
|
||||||
|
}
|
||||||
|
if (inf.getLockOwnerName() != null) {
|
||||||
|
sb.append(" owned by \"").append(inf.getLockOwnerName())
|
||||||
|
.append("\" Id=").append(inf.getLockOwnerId());
|
||||||
|
}
|
||||||
|
if (inf.isSuspended()) {
|
||||||
|
sb.append(" (suspended)");
|
||||||
|
}
|
||||||
|
if (inf.isInNative()) {
|
||||||
|
sb.append(" (in native)");
|
||||||
|
}
|
||||||
|
sb.append('\n');
|
||||||
|
int i = 0;
|
||||||
|
StackTraceElement[] stackTrace = inf.getStackTrace();
|
||||||
|
for (; i < stackTrace.length; i++) {
|
||||||
|
StackTraceElement ste = stackTrace[i];
|
||||||
|
sb.append("\tat ").append(ste.toString());
|
||||||
|
sb.append('\n');
|
||||||
|
if (i == 0 && inf.getLockInfo() != null) {
|
||||||
|
Thread.State ts = inf.getThreadState();
|
||||||
|
switch (ts) {
|
||||||
|
case BLOCKED:
|
||||||
|
sb.append("\t- blocked on ").append(inf.getLockInfo());
|
||||||
|
sb.append('\n');
|
||||||
|
break;
|
||||||
|
case WAITING:
|
||||||
|
sb.append("\t- waiting on ").append(inf.getLockInfo());
|
||||||
|
sb.append('\n');
|
||||||
|
break;
|
||||||
|
case TIMED_WAITING:
|
||||||
|
sb.append("\t- waiting on ").append(inf.getLockInfo());
|
||||||
|
sb.append('\n');
|
||||||
|
break;
|
||||||
|
default:
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
for (MonitorInfo mi : inf.getLockedMonitors()) {
|
||||||
|
if (mi.getLockedStackDepth() == i) {
|
||||||
|
sb.append("\t- locked ").append(mi);
|
||||||
|
sb.append('\n');
|
||||||
|
}
|
||||||
|
}
|
||||||
|
}
|
||||||
|
if (i < stackTrace.length) {
|
||||||
|
sb.append("\t...");
|
||||||
|
sb.append('\n');
|
||||||
|
}
|
||||||
|
|
||||||
|
LockInfo[] locks = inf.getLockedSynchronizers();
|
||||||
|
if (locks.length > 0) {
|
||||||
|
sb.append("\n\tNumber of locked synchronizers = ").append(locks.length);
|
||||||
|
sb.append('\n');
|
||||||
|
for (LockInfo li : locks) {
|
||||||
|
sb.append("\t- ").append(li);
|
||||||
|
sb.append('\n');
|
||||||
|
}
|
||||||
|
}
|
||||||
|
sb.append('\n');
|
||||||
|
return sb.toString();
|
||||||
|
}
|
||||||
|
|
||||||
|
static void pause(long millis) throws InterruptedException {
|
||||||
|
Thread.sleep(millis);
|
||||||
|
}
|
||||||
|
|
||||||
|
static void fail(Exception x) {
|
||||||
|
x.printStackTrace(System.err);
|
||||||
|
if (thrown == null) {
|
||||||
|
thrown = x;
|
||||||
|
}
|
||||||
|
goOn = false;
|
||||||
|
}
|
||||||
|
|
||||||
|
static void deadlock(Exception x) {
|
||||||
|
deadlock = true;
|
||||||
|
System.out.flush();
|
||||||
|
fail(x);
|
||||||
|
System.err.flush();
|
||||||
|
}
|
||||||
|
}
|
@ -0,0 +1,22 @@
|
|||||||
|
########################################################################
|
||||||
|
# Logging configuration property file for TestConfigurationLock.java #
|
||||||
|
########################################################################
|
||||||
|
|
||||||
|
handlers= java.util.logging.ConsoleHandler
|
||||||
|
|
||||||
|
.level= INFO
|
||||||
|
|
||||||
|
java.util.logging.FileHandler.pattern = %h/java%u.log
|
||||||
|
java.util.logging.FileHandler.limit = 50000
|
||||||
|
java.util.logging.FileHandler.count = 1
|
||||||
|
java.util.logging.FileHandler.formatter = java.util.logging.XMLFormatter
|
||||||
|
|
||||||
|
java.util.logging.ConsoleHandler.level = INFO
|
||||||
|
java.util.logging.ConsoleHandler.formatter = java.util.logging.SimpleFormatter
|
||||||
|
|
||||||
|
blah.level = FINE
|
||||||
|
foo.bar.l10.level = INFO
|
||||||
|
foo.bar.l100.level = INFO
|
||||||
|
foo.bar.l1000.level = INFO
|
||||||
|
|
||||||
|
|
Loading…
x
Reference in New Issue
Block a user