[LOG4J2-1644] Inefficient locking in AbstractLoggerAdapter. Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/7114c91c Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/7114c91c Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/7114c91c
Branch: refs/heads/LOG4J2-1390 Commit: 7114c91cc6e974cb5a7627dd9646143143366c81 Parents: 22369cc Author: Tim Gokcen <hexe...@gmail.com> Authored: Fri Oct 21 13:02:59 2016 -0700 Committer: Gary Gregory <ggreg...@apache.org> Committed: Fri Oct 21 13:02:59 2016 -0700 ---------------------------------------------------------------------- .../log4j/spi/AbstractLoggerAdapter.java | 31 ++++- .../logging/log4j/spi/LoggerAdapterTest.java | 126 +++++++++++++++++++ src/changes/changes.xml | 3 + 3 files changed, 154 insertions(+), 6 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/7114c91c/log4j-api/src/main/java/org/apache/logging/log4j/spi/AbstractLoggerAdapter.java ---------------------------------------------------------------------- diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/spi/AbstractLoggerAdapter.java b/log4j-api/src/main/java/org/apache/logging/log4j/spi/AbstractLoggerAdapter.java index 3c6c84f..33c8745 100644 --- a/log4j-api/src/main/java/org/apache/logging/log4j/spi/AbstractLoggerAdapter.java +++ b/log4j-api/src/main/java/org/apache/logging/log4j/spi/AbstractLoggerAdapter.java @@ -20,6 +20,8 @@ import java.util.Map; import java.util.WeakHashMap; import java.util.concurrent.ConcurrentHashMap; import java.util.concurrent.ConcurrentMap; +import java.util.concurrent.locks.ReadWriteLock; +import java.util.concurrent.locks.ReentrantReadWriteLock; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.util.LoaderUtil; @@ -37,6 +39,8 @@ public abstract class AbstractLoggerAdapter<L> implements LoggerAdapter<L> { */ protected final Map<LoggerContext, ConcurrentMap<String, L>> registry = new WeakHashMap<>(); + private final ReadWriteLock lock = new ReentrantReadWriteLock (true); + @Override public L getLogger(final String name) { final LoggerContext context = getContext(); @@ -56,13 +60,28 @@ public abstract class AbstractLoggerAdapter<L> implements LoggerAdapter<L> { * @return the map of loggers for the given LoggerContext */ public ConcurrentMap<String, L> getLoggersInContext(final LoggerContext context) { - synchronized (registry) { - ConcurrentMap<String, L> loggers = registry.get(context); - if (loggers == null) { - loggers = new ConcurrentHashMap<>(); - registry.put(context, loggers); - } + ConcurrentMap<String, L> loggers; + lock.readLock ().lock (); + try { + loggers = registry.get (context); + } finally { + lock.readLock ().unlock (); + } + + if (loggers != null) { return loggers; + } else { + lock.writeLock ().lock (); + try { + loggers = registry.get (context); + if (loggers == null) { + loggers = new ConcurrentHashMap<> (); + registry.put (context, loggers); + } + return loggers; + } finally { + lock.writeLock ().unlock (); + } } } http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/7114c91c/log4j-api/src/test/java/org/apache/logging/log4j/spi/LoggerAdapterTest.java ---------------------------------------------------------------------- diff --git a/log4j-api/src/test/java/org/apache/logging/log4j/spi/LoggerAdapterTest.java b/log4j-api/src/test/java/org/apache/logging/log4j/spi/LoggerAdapterTest.java new file mode 100644 index 0000000..b04fe6f --- /dev/null +++ b/log4j-api/src/test/java/org/apache/logging/log4j/spi/LoggerAdapterTest.java @@ -0,0 +1,126 @@ +/* + * 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. + */ +package org.apache.logging.log4j.spi; + +import org.apache.logging.log4j.simple.SimpleLoggerContext; +import org.junit.Test; + +import java.util.Map; +import java.util.concurrent.CountDownLatch; +import java.util.logging.Logger; + +import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertSame; + +/** + * Created by pavel.sivolobtc...@uxpsystems.com on 2016-10-19. + */ +public class LoggerAdapterTest { + + private class RunnableThreadTest implements Runnable { + private AbstractLoggerAdapter<Logger> adapter; + private LoggerContext context; + private CountDownLatch doneSignal; + private int index; + private Map<String, Logger> resultMap; + + private CountDownLatch startSignal; + + public RunnableThreadTest(int index, TestLoggerAdapter adapter, LoggerContext context, + CountDownLatch startSignal, CountDownLatch doneSignal) { + this.adapter = adapter; + this.context = context; + this.startSignal = startSignal; + this.doneSignal = doneSignal; + this.index = index; + } + + public Map<String, Logger> getResultMap() { + return resultMap; + } + + @Override + public void run() { + try { + startSignal.await(); + resultMap = adapter.getLoggersInContext(context); + resultMap.put(String.valueOf(index), new TestLogger()); + doneSignal.countDown(); + } + catch (Exception e) { + e.printStackTrace(); + } + } + + } + + private static class TestLogger extends Logger { + public TestLogger() { + super("test", null); + } + } + + private static class TestLoggerAdapter extends AbstractLoggerAdapter<Logger> { + + @Override + protected LoggerContext getContext() { + return null; + } + + @Override + protected Logger newLogger(String name, LoggerContext context) { + return null; + } + } + + /** + * Testing synchronization in the getLoggersInContext() method + */ + @Test + public synchronized void testGetLoggersInContextSynch() throws Exception { + TestLoggerAdapter adapter = new TestLoggerAdapter(); + + int num = 500; + + CountDownLatch startSignal = new CountDownLatch(1); + CountDownLatch doneSignal = new CountDownLatch(num); + + RunnableThreadTest[] instances = new RunnableThreadTest[num]; + LoggerContext lastUsedContext = null; + for (int i = 0; i < num; i++) { + if (i % 2 == 0) { + //every other time create a new context + lastUsedContext = new SimpleLoggerContext(); + } + RunnableThreadTest runnable = new RunnableThreadTest(i, adapter, lastUsedContext, startSignal, doneSignal); + Thread thread = new Thread(runnable); + thread.start(); + instances[i] = runnable; + } + + startSignal.countDown(); + doneSignal.await(); + + for (int i = 0; i < num; i = i + 2) { + //maps for the same context should be the same instance + Map<String, Logger> resultMap1 = instances[i].getResultMap(); + Map<String, Logger> resultMap2 = instances[i + 1].getResultMap(); + assertSame("not the same map for instances" + i + " and " + (i + 1) + ":", resultMap1, resultMap2); + assertEquals(2, resultMap1.size()); + } + } +} \ No newline at end of file http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/7114c91c/src/changes/changes.xml ---------------------------------------------------------------------- diff --git a/src/changes/changes.xml b/src/changes/changes.xml index 2922511..1c63572 100644 --- a/src/changes/changes.xml +++ b/src/changes/changes.xml @@ -33,6 +33,9 @@ <action issue="LOG4J2-1639" dev="ggregory" type="fix" due-to="Sridhar Gopinath"> Fix MemoryMappedFileAppender.createAppender() Javadoc for immediateFlush. </action> + <action issue="LOG4J2-1644" dev="ggregory" type="update" due-to="Tim Gokcen, Pavel Sivolobtchik"> + Inefficient locking in AbstractLoggerAdapter. + </action> <action issue="LOG4J2-1641" dev="ggregory" type="update"> Update JeroMQ from 0.3.5 to 0.3.6. </action>