Disallow setting logger factory twice

Motivation:

InternalLoggerFactory either sets a default logger factory
implementation based on the logging implementations on the classpath, or
applications can set a logger factory explicitly. If applications wait
too long to set the logger factory, Netty will have already set a logger
factory leading to some objects using one logging implementation and
other objets using another logging implementation. This can happen too
if the application tries to set the logger factory twice, which is
likely a bug in the application. Yet, the Javadocs for
InternalLoggerFactory warn against this saying that
InternalLoggerFactory#setLoggerFactory "should be called as early as
possible and shouldn't be called more than once". Instead, Netty should
guard against this.

Modications:

We replace the logger factory field with an atomic reference on which we
can do CAS operations to safely guard against it being set twice. We
also add an internal holder class that captures the static interface of
InternalLoggerFactory that can aid in testing.

Result:

The logging factory can not be set twice, and applications that want to
set the logging factory must do it before any Netty classes are
initialized (or the default logger factory will be set).
This commit is contained in:
Jason Tedor 2016-12-05 08:19:51 -05:00 committed by Norman Maurer
parent 24b39bc287
commit 3c92f2b64a
2 changed files with 265 additions and 55 deletions

View File

@ -16,24 +16,64 @@
package io.netty.util.internal.logging;
import java.util.concurrent.atomic.AtomicReference;
/**
* Creates an {@link InternalLogger} or changes the default factory
* implementation. This factory allows you to choose what logging framework
* Netty should use. The default factory is {@link Slf4JLoggerFactory}. If SLF4J
* is not available, {@link Log4JLoggerFactory} is used. If Log4J is not available,
* {@link JdkLoggerFactory} is used. You can change it to your preferred
* logging framework before other Netty classes are loaded:
* <pre>
* {@link InternalLoggerFactory}.setDefaultFactory({@link Log4JLoggerFactory}.INSTANCE);
* </pre>
* Please note that the new default factory is effective only for the classes
* which were loaded after the default factory is changed. Therefore,
* {@link #setDefaultFactory(InternalLoggerFactory)} should be called as early
* as possible and shouldn't be called more than once.
* Creates {@link InternalLogger}s. This factory allows you to choose what logging framework Netty should use. The
* default factory is {@link Slf4JLoggerFactory}. If SLF4J is not available, {@link Log4JLoggerFactory} is used. If
* Log4J is not available, {@link JdkLoggerFactory} is used. You can change it to your preferred logging framework
* before other Netty classes are loaded via {@link #setDefaultFactory(InternalLoggerFactory)}. If you want to change
* the logger factory, {@link #setDefaultFactory(InternalLoggerFactory)} must be invoked before any other Netty classes
* are loaded. Note that {@link #setDefaultFactory(InternalLoggerFactory)}} can not be invoked more than once.
*/
public abstract class InternalLoggerFactory {
private static volatile InternalLoggerFactory defaultFactory;
private static final InternalLoggerFactoryHolder HOLDER = new InternalLoggerFactoryHolder();
/**
* This class holds a reference to the {@link InternalLoggerFactory}. The raison d'être for this class is primarily
* to aid in testing.
*/
static final class InternalLoggerFactoryHolder {
private final AtomicReference<InternalLoggerFactory> reference;
InternalLoggerFactoryHolder() {
this(null);
}
InternalLoggerFactoryHolder(final InternalLoggerFactory holder) {
this.reference = new AtomicReference<InternalLoggerFactory>(holder);
}
InternalLoggerFactory getFactory() {
if (reference.get() == null) {
reference.compareAndSet(null, newDefaultFactory(InternalLoggerFactory.class.getName()));
}
return reference.get();
}
void setFactory(final InternalLoggerFactory factory) {
if (factory == null) {
throw new NullPointerException("factory");
}
if (!reference.compareAndSet(null, factory)) {
throw new IllegalStateException(
"factory is already set to [" + reference.get() + "], rejecting [" + factory + "]");
}
}
InternalLogger getInstance(final Class<?> clazz) {
return getInstance(clazz.getName());
}
InternalLogger getInstance(final String name) {
return newInstance(name);
}
InternalLogger newInstance(String name) {
return getFactory().newInstance(name);
}
}
@SuppressWarnings("UnusedCatchParameter")
private static InternalLoggerFactory newDefaultFactory(String name) {
@ -54,38 +94,35 @@ public abstract class InternalLoggerFactory {
}
/**
* Returns the default factory. The initial default factory is
* {@link JdkLoggerFactory}.
* Get the default factory that was either initialized automatically based on logging implementations on the
* classpath, or set explicitly via {@link #setDefaultFactory(InternalLoggerFactory)}.
*/
public static InternalLoggerFactory getDefaultFactory() {
if (defaultFactory == null) {
defaultFactory = newDefaultFactory(InternalLoggerFactory.class.getName());
}
return defaultFactory;
return HOLDER.getFactory();
}
/**
* Changes the default factory.
* Set the default factory. This method must be invoked before the default factory is initialized via
* {@link #getDefaultFactory()}, and can not be invoked multiple times.
*
* @param defaultFactory a non-null implementation of {@link InternalLoggerFactory}
*/
public static void setDefaultFactory(InternalLoggerFactory defaultFactory) {
if (defaultFactory == null) {
throw new NullPointerException("defaultFactory");
}
InternalLoggerFactory.defaultFactory = defaultFactory;
HOLDER.setFactory(defaultFactory);
}
/**
* Creates a new logger instance with the name of the specified class.
*/
public static InternalLogger getInstance(Class<?> clazz) {
return getInstance(clazz.getName());
return HOLDER.getInstance(clazz);
}
/**
* Creates a new logger instance with the specified name.
*/
public static InternalLogger getInstance(String name) {
return getDefaultFactory().newInstance(name);
return HOLDER.getInstance(name);
}
/**

View File

@ -13,49 +13,63 @@
* License for the specific language governing permissions and limitations
* under the License.
*/
package io.netty.util.internal.logging;
import org.junit.After;
import org.junit.Before;
import org.junit.Test;
import static org.easymock.EasyMock.*;
import static org.junit.Assert.*;
import java.util.concurrent.BrokenBarrierException;
import java.util.concurrent.CyclicBarrier;
import java.util.concurrent.atomic.AtomicBoolean;
import java.util.concurrent.atomic.AtomicReference;
import static org.easymock.EasyMock.createMock;
import static org.easymock.EasyMock.createStrictMock;
import static org.easymock.EasyMock.expect;
import static org.easymock.EasyMock.replay;
import static org.easymock.EasyMock.reset;
import static org.easymock.EasyMock.verify;
import static org.hamcrest.CoreMatchers.containsString;
import static org.junit.Assert.assertFalse;
import static org.junit.Assert.assertNotNull;
import static org.junit.Assert.assertNotSame;
import static org.junit.Assert.assertSame;
import static org.junit.Assert.assertThat;
import static org.junit.Assert.assertTrue;
import static org.junit.Assert.fail;
public class InternalLoggerFactoryTest {
private static final Exception e = new Exception();
private InternalLoggerFactory oldLoggerFactory;
private InternalLoggerFactory.InternalLoggerFactoryHolder holder;
private InternalLogger mock;
@Before
public void init() {
oldLoggerFactory = InternalLoggerFactory.getDefaultFactory();
InternalLoggerFactory mockFactory = createMock(InternalLoggerFactory.class);
final InternalLoggerFactory mockFactory = createMock(InternalLoggerFactory.class);
mock = createStrictMock(InternalLogger.class);
expect(mockFactory.newInstance("mock")).andReturn(mock).anyTimes();
replay(mockFactory);
InternalLoggerFactory.setDefaultFactory(mockFactory);
holder = new InternalLoggerFactory.InternalLoggerFactoryHolder(mockFactory);
}
@After
public void destroy() {
reset(mock);
InternalLoggerFactory.setDefaultFactory(oldLoggerFactory);
}
@Test(expected = NullPointerException.class)
public void shouldNotAllowNullDefaultFactory() {
InternalLoggerFactory.setDefaultFactory(null);
holder.setFactory(null);
}
@Test
public void shouldGetInstance() {
InternalLoggerFactory.setDefaultFactory(oldLoggerFactory);
final String helloWorld = "Hello, world!";
String helloWorld = "Hello, world!";
InternalLogger one = InternalLoggerFactory.getInstance("helloWorld");
InternalLogger two = InternalLoggerFactory.getInstance(helloWorld.getClass());
final InternalLogger one = InternalLoggerFactory.getInstance("helloWorld");
final InternalLogger two = InternalLoggerFactory.getInstance(helloWorld.getClass());
assertNotNull(one);
assertNotNull(two);
@ -67,7 +81,7 @@ public class InternalLoggerFactoryTest {
expect(mock.isTraceEnabled()).andReturn(true);
replay(mock);
InternalLogger logger = InternalLoggerFactory.getInstance("mock");
final InternalLogger logger = holder.getInstance("mock");
assertTrue(logger.isTraceEnabled());
verify(mock);
}
@ -77,7 +91,7 @@ public class InternalLoggerFactoryTest {
expect(mock.isDebugEnabled()).andReturn(true);
replay(mock);
InternalLogger logger = InternalLoggerFactory.getInstance("mock");
final InternalLogger logger = holder.getInstance("mock");
assertTrue(logger.isDebugEnabled());
verify(mock);
}
@ -87,7 +101,7 @@ public class InternalLoggerFactoryTest {
expect(mock.isInfoEnabled()).andReturn(true);
replay(mock);
InternalLogger logger = InternalLoggerFactory.getInstance("mock");
final InternalLogger logger = holder.getInstance("mock");
assertTrue(logger.isInfoEnabled());
verify(mock);
}
@ -97,7 +111,7 @@ public class InternalLoggerFactoryTest {
expect(mock.isWarnEnabled()).andReturn(true);
replay(mock);
InternalLogger logger = InternalLoggerFactory.getInstance("mock");
final InternalLogger logger = holder.getInstance("mock");
assertTrue(logger.isWarnEnabled());
verify(mock);
}
@ -107,7 +121,7 @@ public class InternalLoggerFactoryTest {
expect(mock.isErrorEnabled()).andReturn(true);
replay(mock);
InternalLogger logger = InternalLoggerFactory.getInstance("mock");
final InternalLogger logger = holder.getInstance("mock");
assertTrue(logger.isErrorEnabled());
verify(mock);
}
@ -117,7 +131,7 @@ public class InternalLoggerFactoryTest {
mock.trace("a");
replay(mock);
InternalLogger logger = InternalLoggerFactory.getInstance("mock");
final InternalLogger logger = holder.getInstance("mock");
logger.trace("a");
verify(mock);
}
@ -127,7 +141,7 @@ public class InternalLoggerFactoryTest {
mock.trace("a", e);
replay(mock);
InternalLogger logger = InternalLoggerFactory.getInstance("mock");
final InternalLogger logger = holder.getInstance("mock");
logger.trace("a", e);
verify(mock);
}
@ -137,7 +151,7 @@ public class InternalLoggerFactoryTest {
mock.debug("a");
replay(mock);
InternalLogger logger = InternalLoggerFactory.getInstance("mock");
final InternalLogger logger = holder.getInstance("mock");
logger.debug("a");
verify(mock);
}
@ -147,7 +161,7 @@ public class InternalLoggerFactoryTest {
mock.debug("a", e);
replay(mock);
InternalLogger logger = InternalLoggerFactory.getInstance("mock");
final InternalLogger logger = holder.getInstance("mock");
logger.debug("a", e);
verify(mock);
}
@ -157,7 +171,7 @@ public class InternalLoggerFactoryTest {
mock.info("a");
replay(mock);
InternalLogger logger = InternalLoggerFactory.getInstance("mock");
final InternalLogger logger = holder.getInstance("mock");
logger.info("a");
verify(mock);
}
@ -167,7 +181,7 @@ public class InternalLoggerFactoryTest {
mock.info("a", e);
replay(mock);
InternalLogger logger = InternalLoggerFactory.getInstance("mock");
final InternalLogger logger = holder.getInstance("mock");
logger.info("a", e);
verify(mock);
}
@ -177,7 +191,7 @@ public class InternalLoggerFactoryTest {
mock.warn("a");
replay(mock);
InternalLogger logger = InternalLoggerFactory.getInstance("mock");
final InternalLogger logger = holder.getInstance("mock");
logger.warn("a");
verify(mock);
}
@ -187,7 +201,7 @@ public class InternalLoggerFactoryTest {
mock.warn("a", e);
replay(mock);
InternalLogger logger = InternalLoggerFactory.getInstance("mock");
final InternalLogger logger = holder.getInstance("mock");
logger.warn("a", e);
verify(mock);
}
@ -197,7 +211,7 @@ public class InternalLoggerFactoryTest {
mock.error("a");
replay(mock);
InternalLogger logger = InternalLoggerFactory.getInstance("mock");
final InternalLogger logger = holder.getInstance("mock");
logger.error("a");
verify(mock);
}
@ -207,8 +221,167 @@ public class InternalLoggerFactoryTest {
mock.error("a", e);
replay(mock);
InternalLogger logger = InternalLoggerFactory.getInstance("mock");
final InternalLogger logger = holder.getInstance("mock");
logger.error("a", e);
verify(mock);
}
@Test
public void shouldNotAllowToSetFactoryTwice() {
try {
holder.setFactory(createMock(InternalLoggerFactory.class));
fail("should have thrown IllegalStateException");
} catch (final IllegalStateException e) {
assertThat(e.getMessage(), containsString("factory is already set"));
}
try {
final InternalLoggerFactory.InternalLoggerFactoryHolder implicit =
new InternalLoggerFactory.InternalLoggerFactoryHolder();
implicit.getFactory(); // force initialization
implicit.setFactory(createMock(InternalLoggerFactory.class));
fail("should have thrown IllegalStateException");
} catch (final IllegalStateException e) {
assertThat(e.getMessage(), containsString("factory is already set"));
}
}
@Test
public void raceGetAndGet() throws BrokenBarrierException, InterruptedException {
final CyclicBarrier barrier = new CyclicBarrier(3);
final InternalLoggerFactory.InternalLoggerFactoryHolder holder =
new InternalLoggerFactory.InternalLoggerFactoryHolder();
final AtomicReference<InternalLoggerFactory> firstReference = new AtomicReference<InternalLoggerFactory>();
final AtomicReference<InternalLoggerFactory> secondReference = new AtomicReference<InternalLoggerFactory>();
final Thread firstGet = getThread(firstReference, holder, barrier);
final Thread secondGet = getThread(secondReference, holder, barrier);
firstGet.start();
secondGet.start();
// start the two get threads
barrier.await();
// wait for the two get threads to complete
barrier.await();
if (holder.getFactory() == firstReference.get()) {
assertSame(holder.getFactory(), secondReference.get());
} else if (holder.getFactory() == secondReference.get()) {
assertSame(holder.getFactory(), firstReference.get());
} else {
fail("holder should have been set by one of the get threads");
}
}
@Test
public void raceGetAndSet() throws BrokenBarrierException, InterruptedException {
final CyclicBarrier barrier = new CyclicBarrier(3);
final InternalLoggerFactory.InternalLoggerFactoryHolder holder =
new InternalLoggerFactory.InternalLoggerFactoryHolder();
final InternalLoggerFactory internalLoggerFactory = createMock(InternalLoggerFactory.class);
final AtomicReference<InternalLoggerFactory> reference = new AtomicReference<InternalLoggerFactory>();
final Thread get = getThread(reference, holder, barrier);
final AtomicBoolean setSuccess = new AtomicBoolean();
final Thread set = setThread(internalLoggerFactory, holder, setSuccess, barrier);
get.start();
set.start();
// start the get and set threads
barrier.await();
// wait for the get and set threads to complete
barrier.await();
if (setSuccess.get()) {
assertSame(internalLoggerFactory, reference.get());
assertSame(internalLoggerFactory, holder.getFactory());
} else {
assertNotSame(internalLoggerFactory, reference.get());
assertNotSame(internalLoggerFactory, holder.getFactory());
assertSame(holder.getFactory(), reference.get());
}
}
@Test
public void raceSetAndSet() throws BrokenBarrierException, InterruptedException {
final CyclicBarrier barrier = new CyclicBarrier(3);
final InternalLoggerFactory.InternalLoggerFactoryHolder holder =
new InternalLoggerFactory.InternalLoggerFactoryHolder();
final InternalLoggerFactory first = createMock(InternalLoggerFactory.class);
final InternalLoggerFactory second = createMock(InternalLoggerFactory.class);
final AtomicBoolean firstSetSuccess = new AtomicBoolean();
final Thread firstSet = setThread(first, holder, firstSetSuccess, barrier);
final AtomicBoolean secondSetSuccess = new AtomicBoolean();
final Thread secondSet = setThread(second, holder, secondSetSuccess, barrier);
firstSet.start();
secondSet.start();
// start the two set threads
barrier.await();
// wait for the two set threads to complete
barrier.await();
assertTrue(firstSetSuccess.get() || secondSetSuccess.get());
if (firstSetSuccess.get()) {
assertFalse(secondSetSuccess.get());
assertSame(first, holder.getFactory());
} else {
assertFalse(firstSetSuccess.get());
assertSame(second, holder.getFactory());
}
}
private static Thread getThread(
final AtomicReference<InternalLoggerFactory> reference,
final InternalLoggerFactory.InternalLoggerFactoryHolder holder,
final CyclicBarrier barrier) {
return new Thread(new Runnable() {
@Override
public void run() {
awaitUnchecked(barrier);
reference.set(holder.getFactory());
awaitUnchecked(barrier);
}
});
}
private static Thread setThread(
final InternalLoggerFactory internalLoggerFactory,
final InternalLoggerFactory.InternalLoggerFactoryHolder holder,
final AtomicBoolean setSuccess,
final CyclicBarrier barrier) {
return new Thread(new Runnable() {
@Override
public void run() {
awaitUnchecked(barrier);
boolean success = true;
try {
holder.setFactory(internalLoggerFactory);
} catch (final IllegalStateException e) {
success = false;
assertThat(e.getMessage(), containsString("factory is already set"));
} finally {
setSuccess.set(success);
awaitUnchecked(barrier);
}
}
});
}
private static void awaitUnchecked(final CyclicBarrier barrier) {
try {
barrier.await();
} catch (final InterruptedException exception) {
throw new IllegalStateException(exception);
} catch (final BrokenBarrierException exception) {
throw new IllegalStateException(exception);
}
}
}