Repository: logging-log4j2 Updated Branches: refs/heads/master 3cee912e3 -> 044470e92
LOG4J2-993 - Deadlock occurs if appender thread creates a new Logger during reconfiguration Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/044470e9 Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/044470e9 Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/044470e9 Branch: refs/heads/master Commit: 044470e925d2e649fca396d7fdf829431f13ccce Parents: 3cee912 Author: Ralph Goers <[email protected]> Authored: Sun Apr 12 10:08:39 2015 -0700 Committer: Ralph Goers <[email protected]> Committed: Sun Apr 12 10:08:39 2015 -0700 ---------------------------------------------------------------------- .../logging/log4j/core/LoggerContext.java | 81 ++++++++++++-------- .../apache/logging/log4j/core/DeadlockTest.java | 20 +++++ .../log4j/test/appender/DeadlockAppender.java | 65 ++++++++++++++++ .../src/test/resources/log4j-deadlock.xml | 30 ++++++++ src/changes/changes.xml | 3 + 5 files changed, 165 insertions(+), 34 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/044470e9/log4j-core/src/main/java/org/apache/logging/log4j/core/LoggerContext.java ---------------------------------------------------------------------- diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/LoggerContext.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/LoggerContext.java index 140317e..fd33844 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/LoggerContext.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/LoggerContext.java @@ -70,7 +70,7 @@ public class LoggerContext extends AbstractLifeCycle implements org.apache.loggi private volatile Configuration config = new DefaultConfiguration(); private Object externalContext; private final String name; - private URI configLocation; + private volatile URI configLocation; private Cancellable shutdownCallback; private final Lock configLock = new ReentrantLock(); @@ -343,36 +343,41 @@ public class LoggerContext extends AbstractLifeCycle implements org.apache.loggi * @param config The new Configuration. * @return The previous Configuration. */ - private synchronized Configuration setConfiguration(final Configuration config) { + private Configuration setConfiguration(final Configuration config) { Assert.requireNonNull(config, "No Configuration was provided"); - final Configuration prev = this.config; - config.addListener(this); - final ConcurrentMap<String, String> map = config.getComponent(Configuration.CONTEXT_PROPERTIES); - - try { // LOG4J2-719 network access may throw android.os.NetworkOnMainThreadException - map.putIfAbsent("hostName", NetUtils.getLocalHostname()); - } catch (final Exception ex) { - LOGGER.debug("Ignoring {}, setting hostName to 'unknown'", ex.toString()); - map.putIfAbsent("hostName", "unknown"); - } - map.putIfAbsent("contextName", name); - config.start(); - this.config = config; - updateLoggers(); - if (prev != null) { - prev.removeListener(this); - prev.stop(); - } + configLock.lock(); + try { + final Configuration prev = this.config; + config.addListener(this); + final ConcurrentMap<String, String> map = config.getComponent(Configuration.CONTEXT_PROPERTIES); - firePropertyChangeEvent(new PropertyChangeEvent(this, PROPERTY_CONFIG, prev, config)); + try { // LOG4J2-719 network access may throw android.os.NetworkOnMainThreadException + map.putIfAbsent("hostName", NetUtils.getLocalHostname()); + } catch (final Exception ex) { + LOGGER.debug("Ignoring {}, setting hostName to 'unknown'", ex.toString()); + map.putIfAbsent("hostName", "unknown"); + } + map.putIfAbsent("contextName", name); + config.start(); + this.config = config; + updateLoggers(); + if (prev != null) { + prev.removeListener(this); + prev.stop(); + } - try { - Server.reregisterMBeansAfterReconfigure(); - } catch (final Throwable t) { - // LOG4J2-716: Android has no java.lang.management - LOGGER.error("Could not reconfigure JMX", t); + firePropertyChangeEvent(new PropertyChangeEvent(this, PROPERTY_CONFIG, prev, config)); + + try { + Server.reregisterMBeansAfterReconfigure(); + } catch (final Throwable t) { + // LOG4J2-716: Android has no java.lang.management + LOGGER.error("Could not reconfigure JMX", t); + } + return prev; + } finally { + configLock.unlock(); } - return prev; } private void firePropertyChangeEvent(final PropertyChangeEvent event) { @@ -396,7 +401,7 @@ public class LoggerContext extends AbstractLifeCycle implements org.apache.loggi * ConfigurationSource#getLocation() getLocation()} to get the actual source of the current configuration. * @return the initial configuration location or {@code null} */ - public synchronized URI getConfigLocation() { + public URI getConfigLocation() { return configLocation; } @@ -404,19 +409,20 @@ public class LoggerContext extends AbstractLifeCycle implements org.apache.loggi * Sets the configLocation to the specified value and reconfigures this context. * @param configLocation the location of the new configuration */ - public synchronized void setConfigLocation(final URI configLocation) { + public void setConfigLocation(final URI configLocation) { this.configLocation = configLocation; - reconfigure(); + + reconfigure(configLocation); } /** * Reconfigure the context. */ - public synchronized void reconfigure() { + private void reconfigure(final URI configURI) { final ClassLoader cl = ClassLoader.class.isInstance(externalContext) ? (ClassLoader) externalContext : null; LOGGER.debug("Reconfiguration started for context[name={}] at {} ({}) with optional ClassLoader: {}", name, - configLocation, this, cl); - final Configuration instance = ConfigurationFactory.getInstance().getConfiguration(name, configLocation, cl); + configURI, this, cl); + final Configuration instance = ConfigurationFactory.getInstance().getConfiguration(name, configURI, cl); setConfiguration(instance); /* * instance.start(); Configuration old = setConfiguration(instance); @@ -424,7 +430,14 @@ public class LoggerContext extends AbstractLifeCycle implements org.apache.loggi */ LOGGER.debug("Reconfiguration complete for context[name={}] at {} ({}) with optional ClassLoader: {}", name, - configLocation, this, cl); + configURI, this, cl); + } + + /** + * Reconfigure the context. + */ + public void reconfigure() { + reconfigure(configLocation); } /** http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/044470e9/log4j-core/src/test/java/org/apache/logging/log4j/core/DeadlockTest.java ---------------------------------------------------------------------- diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/core/DeadlockTest.java b/log4j-core/src/test/java/org/apache/logging/log4j/core/DeadlockTest.java new file mode 100644 index 0000000..1068198 --- /dev/null +++ b/log4j-core/src/test/java/org/apache/logging/log4j/core/DeadlockTest.java @@ -0,0 +1,20 @@ +package org.apache.logging.log4j.core; + +import org.apache.logging.log4j.junit.InitialLoggerContext; +import org.junit.ClassRule; +import org.junit.Test; + +/** + * + */ +public class DeadlockTest { + + private static final String CONFIG = "log4j-deadlock.xml"; + @ClassRule + public static InitialLoggerContext context = new InitialLoggerContext(CONFIG); + + @Test + public void deadlockOnReconfigure() { + context.getContext().reconfigure(); + } +} http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/044470e9/log4j-core/src/test/java/org/apache/logging/log4j/test/appender/DeadlockAppender.java ---------------------------------------------------------------------- diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/test/appender/DeadlockAppender.java b/log4j-core/src/test/java/org/apache/logging/log4j/test/appender/DeadlockAppender.java new file mode 100644 index 0000000..312aa2f --- /dev/null +++ b/log4j-core/src/test/java/org/apache/logging/log4j/test/appender/DeadlockAppender.java @@ -0,0 +1,65 @@ +package org.apache.logging.log4j.test.appender; + +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.LoggingException; +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.appender.AbstractAppender; +import org.apache.logging.log4j.core.config.plugins.Plugin; +import org.apache.logging.log4j.core.config.plugins.PluginAttribute; +import org.apache.logging.log4j.core.config.plugins.PluginFactory; + +/** + * + */ +@Plugin(name="Deadlock", category ="Core",elementType="appender",printObject=true) +public class DeadlockAppender extends AbstractAppender { + + private WorkerThread thread = null; + + private DeadlockAppender(final String name) { + super(name, null, null, false); + thread = new WorkerThread(); + } + + @Override + public void start() { + super.start(); + + } + + @Override + public void stop() { + super.stop(); + thread.start(); + try { + thread.join(); + } catch (Exception ex) { + System.out.println("Thread interrupted"); + } + } + + @Override + public void append(final LogEvent event) { + throw new LoggingException("Always fail"); + } + + @PluginFactory + public static DeadlockAppender createAppender(@PluginAttribute("name") final String name) { + if (name == null) { + LOGGER.error("A name for the Appender must be specified"); + return null; + } + + return new DeadlockAppender(name); + } + + private class WorkerThread extends Thread { + + @Override + public void run() { + Logger logger = LogManager.getLogger("org.apache.logging.log4j.test.WorkerThread"); + logger.debug("Worker is running"); + } + } +} http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/044470e9/log4j-core/src/test/resources/log4j-deadlock.xml ---------------------------------------------------------------------- diff --git a/log4j-core/src/test/resources/log4j-deadlock.xml b/log4j-core/src/test/resources/log4j-deadlock.xml new file mode 100644 index 0000000..e89fe41 --- /dev/null +++ b/log4j-core/src/test/resources/log4j-deadlock.xml @@ -0,0 +1,30 @@ +<?xml version="1.0" encoding="UTF-8"?> +<!-- + Licensed to the Apache Software Foundation (ASF) under one or more + contributor license agreements. See the NOTICE file distributed with + this work for additional information regarding copyright ownership. + The ASF licenses this file to You under the Apache License, Version 2.0 + (the "License"); you may not use this file except in compliance with + the License. You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + + Unless required by applicable law or agreed to in writing, software + distributed under the License is distributed on an "AS IS" BASIS, + WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + See the License for the specific language governing permissions and + limitations under the License. + +--> +<Configuration name="ConfigTest" status="OFF" monitorInterval="5"> + <Appenders> + <Deadlock name="deadlock"> + <PatternLayout pattern="%m%n"/> + </Deadlock> + </Appenders> + <Loggers> + <Root level="error"> + <AppenderRef ref="deadlock"/> + </Root> + </Loggers> +</Configuration> \ No newline at end of file http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/044470e9/src/changes/changes.xml ---------------------------------------------------------------------- diff --git a/src/changes/changes.xml b/src/changes/changes.xml index 5fc76de..667fd93 100644 --- a/src/changes/changes.xml +++ b/src/changes/changes.xml @@ -24,6 +24,9 @@ </properties> <body> <release version="2.3" date="2015-0?-??" description="GA Release 2.3"> + <action issue="LOG4J2-993" dev="rgoers" type="fix"> + Deadlock would occur if appender thread creates a new Logger during reconfiguration. + </action> <action issue="LOG4J2-991" dev="rpopma" type="fix" due-to="Ryan Rupp"> Async root logger config should default includeLocation to false. </action>
