Repository: logging-log4j2 Updated Branches: refs/heads/master 81d12ad14 -> 93e97932c
[LOG4J2-2212]Unnecessary contention in CopyOnWriteSortedArrayThreadContextMap. [LOG4J2-2213] Unnecessary contention in GarbageFreeSortedArrayThreadContextMap. Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/93e97932 Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/93e97932 Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/93e97932 Branch: refs/heads/master Commit: 93e97932c871a94486b8dc1c16f6ae3a77184871 Parents: 81d12ad Author: Gary Gregory <[email protected]> Authored: Tue Jan 23 14:20:14 2018 -0700 Committer: Gary Gregory <[email protected]> Committed: Tue Jan 23 14:20:14 2018 -0700 ---------------------------------------------------------------------- .../org/apache/logging/log4j/ThreadContext.java | 1 + .../CopyOnWriteSortedArrayThreadContextMap.java | 21 ++++++++--- .../GarbageFreeSortedArrayThreadContextMap.java | 23 ++++++++++-- .../log4j/spi/ThreadContextMapFactory.java | 39 ++++++++++++++++---- .../log4j/ThreadContextInheritanceTest.java | 8 +++- .../logging/log4j/core/LoggerContext.java | 7 ++++ src/changes/changes.xml | 11 ++++++ 7 files changed, 92 insertions(+), 18 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/93e97932/log4j-api/src/main/java/org/apache/logging/log4j/ThreadContext.java ---------------------------------------------------------------------- diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/ThreadContext.java b/log4j-api/src/main/java/org/apache/logging/log4j/ThreadContext.java index fc018b9..c4ae445 100644 --- a/log4j-api/src/main/java/org/apache/logging/log4j/ThreadContext.java +++ b/log4j-api/src/main/java/org/apache/logging/log4j/ThreadContext.java @@ -211,6 +211,7 @@ public final class ThreadContext { * <em>Consider private, used for testing.</em> */ static void init() { + ThreadContextMapFactory.init(); contextMap = null; final PropertiesUtil managerProps = PropertiesUtil.getProperties(); disableAll = managerProps.getBooleanProperty(DISABLE_ALL); http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/93e97932/log4j-api/src/main/java/org/apache/logging/log4j/spi/CopyOnWriteSortedArrayThreadContextMap.java ---------------------------------------------------------------------- diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/spi/CopyOnWriteSortedArrayThreadContextMap.java b/log4j-api/src/main/java/org/apache/logging/log4j/spi/CopyOnWriteSortedArrayThreadContextMap.java index d5e466f..fd94566 100644 --- a/log4j-api/src/main/java/org/apache/logging/log4j/spi/CopyOnWriteSortedArrayThreadContextMap.java +++ b/log4j-api/src/main/java/org/apache/logging/log4j/spi/CopyOnWriteSortedArrayThreadContextMap.java @@ -53,9 +53,23 @@ class CopyOnWriteSortedArrayThreadContextMap implements ReadOnlyThreadContextMap protected static final String PROPERTY_NAME_INITIAL_CAPACITY = "log4j2.ThreadContext.initial.capacity"; private static final StringMap EMPTY_CONTEXT_DATA = new SortedArrayStringMap(1); + + private static volatile int InitialCapacity; + private static volatile boolean InheritableMap; + /** + * Initializes static variables based on system properties. Normally called when this class is initialized by the VM + * and when Log4j is reconfigured. + */ + static void init() { + final PropertiesUtil properties = PropertiesUtil.getProperties(); + InitialCapacity = properties.getIntegerProperty(PROPERTY_NAME_INITIAL_CAPACITY, DEFAULT_INITIAL_CAPACITY); + InheritableMap = properties.getBooleanProperty(INHERITABLE_MAP); + } + static { EMPTY_CONTEXT_DATA.freeze(); + init(); } private final ThreadLocal<StringMap> localMap; @@ -67,9 +81,7 @@ class CopyOnWriteSortedArrayThreadContextMap implements ReadOnlyThreadContextMap // LOG4J2-479: by default, use a plain ThreadLocal, only use InheritableThreadLocal if configured. // (This method is package protected for JUnit tests.) private ThreadLocal<StringMap> createThreadLocalMap() { - final PropertiesUtil managerProps = PropertiesUtil.getProperties(); - final boolean inheritable = managerProps.getBooleanProperty(INHERITABLE_MAP); - if (inheritable) { + if (InheritableMap) { return new InheritableThreadLocal<StringMap>() { @Override protected StringMap childValue(final StringMap parentValue) { @@ -94,8 +106,7 @@ class CopyOnWriteSortedArrayThreadContextMap implements ReadOnlyThreadContextMap * @return an implementation of the {@code StringMap} used to back this thread context map */ protected StringMap createStringMap() { - return new SortedArrayStringMap(PropertiesUtil.getProperties().getIntegerProperty( - PROPERTY_NAME_INITIAL_CAPACITY, DEFAULT_INITIAL_CAPACITY)); + return new SortedArrayStringMap(InitialCapacity); } /** http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/93e97932/log4j-api/src/main/java/org/apache/logging/log4j/spi/GarbageFreeSortedArrayThreadContextMap.java ---------------------------------------------------------------------- diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/spi/GarbageFreeSortedArrayThreadContextMap.java b/log4j-api/src/main/java/org/apache/logging/log4j/spi/GarbageFreeSortedArrayThreadContextMap.java index f11fd66..d695b9c 100644 --- a/log4j-api/src/main/java/org/apache/logging/log4j/spi/GarbageFreeSortedArrayThreadContextMap.java +++ b/log4j-api/src/main/java/org/apache/logging/log4j/spi/GarbageFreeSortedArrayThreadContextMap.java @@ -53,6 +53,23 @@ class GarbageFreeSortedArrayThreadContextMap implements ReadOnlyThreadContextMap protected static final String PROPERTY_NAME_INITIAL_CAPACITY = "log4j2.ThreadContext.initial.capacity"; protected final ThreadLocal<StringMap> localMap; + + private static volatile int InitialCapacity; + private static volatile boolean InheritableMap; + + /** + * Initializes static variables based on system properties. Normally called when this class is initialized by the VM + * and when Log4j is reconfigured. + */ + static void init() { + final PropertiesUtil properties = PropertiesUtil.getProperties(); + InitialCapacity = properties.getIntegerProperty(PROPERTY_NAME_INITIAL_CAPACITY, DEFAULT_INITIAL_CAPACITY); + InheritableMap = properties.getBooleanProperty(INHERITABLE_MAP); + } + + static { + init(); + } public GarbageFreeSortedArrayThreadContextMap() { this.localMap = createThreadLocalMap(); @@ -62,8 +79,7 @@ class GarbageFreeSortedArrayThreadContextMap implements ReadOnlyThreadContextMap // (This method is package protected for JUnit tests.) private ThreadLocal<StringMap> createThreadLocalMap() { final PropertiesUtil managerProps = PropertiesUtil.getProperties(); - final boolean inheritable = managerProps.getBooleanProperty(INHERITABLE_MAP); - if (inheritable) { + if (InheritableMap) { return new InheritableThreadLocal<StringMap>() { @Override protected StringMap childValue(final StringMap parentValue) { @@ -83,8 +99,7 @@ class GarbageFreeSortedArrayThreadContextMap implements ReadOnlyThreadContextMap * @return an implementation of the {@code StringMap} used to back this thread context map */ protected StringMap createStringMap() { - return new SortedArrayStringMap(PropertiesUtil.getProperties().getIntegerProperty( - PROPERTY_NAME_INITIAL_CAPACITY, DEFAULT_INITIAL_CAPACITY)); + return new SortedArrayStringMap(InitialCapacity); } /** http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/93e97932/log4j-api/src/main/java/org/apache/logging/log4j/spi/ThreadContextMapFactory.java ---------------------------------------------------------------------- diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/spi/ThreadContextMapFactory.java b/log4j-api/src/main/java/org/apache/logging/log4j/spi/ThreadContextMapFactory.java index 47187dc..05c0e2d 100644 --- a/log4j-api/src/main/java/org/apache/logging/log4j/spi/ThreadContextMapFactory.java +++ b/log4j-api/src/main/java/org/apache/logging/log4j/spi/ThreadContextMapFactory.java @@ -49,25 +49,50 @@ public final class ThreadContextMapFactory { private static final Logger LOGGER = StatusLogger.getLogger(); private static final String THREAD_CONTEXT_KEY = "log4j2.threadContextMap"; private static final String GC_FREE_THREAD_CONTEXT_KEY = "log4j2.garbagefree.threadContextMap"; + + private static boolean GcFreeThreadContextKey; + private static String ThreadContextMapName; + static { + initPrivate(); + } + + /** + * Initializes static variables based on system properties. Normally called when this class is initialized by the VM + * and when Log4j is reconfigured. + */ + public static void init() { + CopyOnWriteSortedArrayThreadContextMap.init(); + GarbageFreeSortedArrayThreadContextMap.init(); + initPrivate(); + } + + /** + * Initializes static variables based on system properties. Normally called when this class is initialized by the VM + * and when Log4j is reconfigured. + */ + private static void initPrivate() { + final PropertiesUtil properties = PropertiesUtil.getProperties(); + ThreadContextMapName = properties.getStringProperty(THREAD_CONTEXT_KEY); + GcFreeThreadContextKey = properties.getBooleanProperty(GC_FREE_THREAD_CONTEXT_KEY); + } + private ThreadContextMapFactory() { } public static ThreadContextMap createThreadContextMap() { - final PropertiesUtil managerProps = PropertiesUtil.getProperties(); - final String threadContextMapName = managerProps.getStringProperty(THREAD_CONTEXT_KEY); final ClassLoader cl = ProviderUtil.findClassLoader(); ThreadContextMap result = null; - if (threadContextMapName != null) { + if (ThreadContextMapName != null) { try { - final Class<?> clazz = cl.loadClass(threadContextMapName); + final Class<?> clazz = cl.loadClass(ThreadContextMapName); if (ThreadContextMap.class.isAssignableFrom(clazz)) { result = (ThreadContextMap) clazz.newInstance(); } } catch (final ClassNotFoundException cnfe) { - LOGGER.error("Unable to locate configured ThreadContextMap {}", threadContextMapName); + LOGGER.error("Unable to locate configured ThreadContextMap {}", ThreadContextMapName); } catch (final Exception ex) { - LOGGER.error("Unable to create configured ThreadContextMap {}", threadContextMapName, ex); + LOGGER.error("Unable to create configured ThreadContextMap {}", ThreadContextMapName, ex); } } if (result == null && ProviderUtil.hasProviders() && LogManager.getFactory() != null) { //LOG4J2-1658 @@ -96,7 +121,7 @@ public final class ThreadContextMapFactory { private static ThreadContextMap createDefaultThreadContextMap() { if (Constants.ENABLE_THREADLOCALS) { - if (PropertiesUtil.getProperties().getBooleanProperty(GC_FREE_THREAD_CONTEXT_KEY)) { + if (GcFreeThreadContextKey) { return new GarbageFreeSortedArrayThreadContextMap(); } return new CopyOnWriteSortedArrayThreadContextMap(); http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/93e97932/log4j-api/src/test/java/org/apache/logging/log4j/ThreadContextInheritanceTest.java ---------------------------------------------------------------------- diff --git a/log4j-api/src/test/java/org/apache/logging/log4j/ThreadContextInheritanceTest.java b/log4j-api/src/test/java/org/apache/logging/log4j/ThreadContextInheritanceTest.java index 9c46e3f..a2e5fce 100644 --- a/log4j-api/src/test/java/org/apache/logging/log4j/ThreadContextInheritanceTest.java +++ b/log4j-api/src/test/java/org/apache/logging/log4j/ThreadContextInheritanceTest.java @@ -16,13 +16,16 @@ */ package org.apache.logging.log4j; +import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertFalse; +import static org.junit.Assert.assertNull; +import static org.junit.Assert.assertTrue; + import org.apache.logging.log4j.spi.DefaultThreadContextMap; import org.junit.AfterClass; import org.junit.BeforeClass; import org.junit.Test; -import static org.junit.Assert.*; - /** * Tests {@link ThreadContext}. */ @@ -54,6 +57,7 @@ public class ThreadContextInheritanceTest { @Test public void testInheritanceSwitchedOn() throws Exception { System.setProperty(DefaultThreadContextMap.INHERITABLE_MAP, "true"); + ThreadContext.init(); try { ThreadContext.clearMap(); ThreadContext.put("Greeting", "Hello"); http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/93e97932/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 cd15dce..8234024 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 @@ -49,9 +49,11 @@ import org.apache.logging.log4j.spi.AbstractLogger; import org.apache.logging.log4j.spi.LoggerContextFactory; import org.apache.logging.log4j.spi.LoggerRegistry; import org.apache.logging.log4j.spi.Terminable; +import org.apache.logging.log4j.spi.ThreadContextMapFactory; import org.apache.logging.log4j.util.LoaderUtil; import org.apache.logging.log4j.util.PropertiesUtil; + /** * The LoggerContext is the anchor for the logging system. It maintains a list of all the loggers requested by * applications and a reference to the Configuration. The Configuration will contain the configured loggers, appenders, @@ -662,6 +664,7 @@ public class LoggerContext extends AbstractLifeCycle @Override public synchronized void onChange(final Reconfigurable reconfigurable) { LOGGER.debug("Reconfiguration started for context {} ({})", contextName, this); + initApiModule(); final Configuration newConfig = reconfigurable.reconfigure(); if (newConfig != null) { setConfiguration(newConfig); @@ -671,6 +674,10 @@ public class LoggerContext extends AbstractLifeCycle } } + private void initApiModule() { + ThreadContextMapFactory.init(); // Or make public and call ThreadContext.init() which calls ThreadContextMapFactory.init(). + } + // LOG4J2-151: changed visibility from private to protected protected Logger newInstance(final LoggerContext ctx, final String name, final MessageFactory messageFactory) { return new Logger(ctx, name, messageFactory); http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/93e97932/src/changes/changes.xml ---------------------------------------------------------------------- diff --git a/src/changes/changes.xml b/src/changes/changes.xml index b2f05d5..c918d0d 100644 --- a/src/changes/changes.xml +++ b/src/changes/changes.xml @@ -131,6 +131,17 @@ <action issue="LOG4J2-2210" dev="ggregory" type="update" due-to="Björn Kautler"> Fix error log message for Script which says ScriptFile instead. </action> + <action issue="LOG4J2-2212" dev="ggregory" type="update" due-to="Daniel Feist, Gary Gregory"> + Unnecessary contention in CopyOnWriteSortedArrayThreadContextMap. + </action> + <action issue="LOG4J2-2213" dev="ggregory" type="update" due-to="Daniel Feist, Gary Gregory"> + Unnecessary contention in GarbageFreeSortedArrayThreadContextMap. + </action> + <!-- + <action issue="LOG4J2-2205" dev="ggregory" type="update" due-to="Björn Kautler"> + New module log4j-mongodb3: Remove use of deprecated MongoDB APIs and code to the Java driver version 3 API. + </action> + --> </release> <release version="2.10.0" date="2017-11-18" description="GA Release 2.10.0"> <action issue="LOG4J2-2120" dev="mikes" type="add" due-to="Carter Douglas Kozak ">
