From 14189140a0e07ab1cac8b91b49a787143870890e Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=E6=9D=A8=E6=B5=A9?= Date: Fri, 8 Sep 2017 21:17:28 +0800 Subject: [PATCH] log in PatternLayout (%F:%L)%c.%M Motivation: When Log4j2Logger is used with PatternLayout (%F:%L)%c.%M, the log message incorrect shows: (Log4J2Logger.java:73)io.netty.util.internal.PlatformDependent0.debug .... Modification: Extend AbstractLogger Result: Fixes [#7186]. --- .../util/internal/logging/Log4J2Logger.java | 164 ++++------- .../logging/AbstractInternalLoggerTest.java | 150 ++++++++++ .../internal/logging/Log4J2LoggerTest.java | 258 +++++------------- 3 files changed, 267 insertions(+), 305 deletions(-) create mode 100644 common/src/test/java/io/netty/util/internal/logging/AbstractInternalLoggerTest.java diff --git a/common/src/main/java/io/netty/util/internal/logging/Log4J2Logger.java b/common/src/main/java/io/netty/util/internal/logging/Log4J2Logger.java index 64bdfed2e0..8ed2fdf48d 100644 --- a/common/src/main/java/io/netty/util/internal/logging/Log4J2Logger.java +++ b/common/src/main/java/io/netty/util/internal/logging/Log4J2Logger.java @@ -15,166 +15,102 @@ */ package io.netty.util.internal.logging; -import org.apache.logging.log4j.Logger; -final class Log4J2Logger extends AbstractInternalLogger { +import org.apache.logging.log4j.Level; +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.spi.ExtendedLogger; +import org.apache.logging.log4j.spi.ExtendedLoggerWrapper; + +class Log4J2Logger extends ExtendedLoggerWrapper implements InternalLogger { private static final long serialVersionUID = 5485418394879791397L; - private final transient Logger logger; + /** {@linkplain AbstractInternalLogger#EXCEPTION_MESSAGE} */ + private static final String EXCEPTION_MESSAGE = "Unexpected exception:"; Log4J2Logger(Logger logger) { - super(logger.getName()); - this.logger = logger; + super((ExtendedLogger) logger, logger.getName(), logger.getMessageFactory()); } @Override - public boolean isTraceEnabled() { - return logger.isTraceEnabled(); + public String name() { + return getName(); } @Override - public void trace(String msg) { - logger.trace(msg); + public void trace(Throwable t) { + log(Level.TRACE, EXCEPTION_MESSAGE, t); } @Override - public void trace(String format, Object arg) { - logger.trace(format, arg); + public void debug(Throwable t) { + log(Level.DEBUG, EXCEPTION_MESSAGE, t); } @Override - public void trace(String format, Object argA, Object argB) { - logger.trace(format, argA, argB); + public void info(Throwable t) { + log(Level.INFO, EXCEPTION_MESSAGE, t); } @Override - public void trace(String format, Object... arguments) { - logger.trace(format, arguments); + public void warn(Throwable t) { + log(Level.WARN, EXCEPTION_MESSAGE, t); } @Override - public void trace(String msg, Throwable t) { - logger.trace(msg, t); + public void error(Throwable t) { + log(Level.ERROR, EXCEPTION_MESSAGE, t); } @Override - public boolean isDebugEnabled() { - return logger.isDebugEnabled(); + public boolean isEnabled(InternalLogLevel level) { + return isEnabled(toLevel(level)); } @Override - public void debug(String msg) { - logger.debug(msg); + public void log(InternalLogLevel level, String msg) { + log(toLevel(level), msg); } @Override - public void debug(String format, Object arg) { - logger.debug(format, arg); + public void log(InternalLogLevel level, String format, Object arg) { + log(toLevel(level), format, arg); } @Override - public void debug(String format, Object argA, Object argB) { - logger.debug(format, argA, argB); + public void log(InternalLogLevel level, String format, Object argA, Object argB) { + log(toLevel(level), format, argA, argB); } @Override - public void debug(String format, Object... arguments) { - logger.debug(format, arguments); + public void log(InternalLogLevel level, String format, Object... arguments) { + log(toLevel(level), format, arguments); } @Override - public void debug(String msg, Throwable t) { - logger.debug(msg, t); + public void log(InternalLogLevel level, String msg, Throwable t) { + log(toLevel(level), msg, t); } @Override - public boolean isInfoEnabled() { - return logger.isInfoEnabled(); + public void log(InternalLogLevel level, Throwable t) { + log(toLevel(level), EXCEPTION_MESSAGE, t); } - @Override - public void info(String msg) { - logger.info(msg); - } - - @Override - public void info(String format, Object arg) { - logger.info(format, arg); - } - - @Override - public void info(String format, Object argA, Object argB) { - logger.info(format, argA, argB); - } - - @Override - public void info(String format, Object... arguments) { - logger.info(format, arguments); - } - - @Override - public void info(String msg, Throwable t) { - logger.info(msg, t); - } - - @Override - public boolean isWarnEnabled() { - return logger.isWarnEnabled(); - } - - @Override - public void warn(String msg) { - logger.warn(msg); - } - - @Override - public void warn(String format, Object arg) { - logger.warn(format, arg); - } - - @Override - public void warn(String format, Object... arguments) { - logger.warn(format, arguments); - } - - @Override - public void warn(String format, Object argA, Object argB) { - logger.warn(format, argA, argB); - } - - @Override - public void warn(String msg, Throwable t) { - logger.warn(msg, t); - } - - @Override - public boolean isErrorEnabled() { - return logger.isErrorEnabled(); - } - - @Override - public void error(String msg) { - logger.error(msg); - } - - @Override - public void error(String format, Object arg) { - logger.error(format, arg); - } - - @Override - public void error(String format, Object argA, Object argB) { - logger.error(format, argA, argB); - } - - @Override - public void error(String format, Object... arguments) { - logger.error(format, arguments); - } - - @Override - public void error(String msg, Throwable t) { - logger.error(msg, t); + protected Level toLevel(InternalLogLevel level) { + switch (level) { + case INFO: + return Level.INFO; + case DEBUG: + return Level.DEBUG; + case WARN: + return Level.WARN; + case ERROR: + return Level.ERROR; + case TRACE: + return Level.TRACE; + default: + throw new Error(); + } } } diff --git a/common/src/test/java/io/netty/util/internal/logging/AbstractInternalLoggerTest.java b/common/src/test/java/io/netty/util/internal/logging/AbstractInternalLoggerTest.java new file mode 100644 index 0000000000..9a395eab25 --- /dev/null +++ b/common/src/test/java/io/netty/util/internal/logging/AbstractInternalLoggerTest.java @@ -0,0 +1,150 @@ +/* + * Copyright 2017 The Netty Project + * + * The Netty Project 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 io.netty.util.internal.logging; + +import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertFalse; +import static org.junit.Assert.assertTrue; + +import java.lang.reflect.Method; +import java.util.HashMap; +import java.util.Map; + +import org.junit.Test; + +/** + * We only need to test methods defined by {@link InternaLogger}. + */ +public abstract class AbstractInternalLoggerTest { + protected String loggerName = "foo"; + protected T mockLog; + protected InternalLogger logger; + protected final Map result = new HashMap(); + + @SuppressWarnings("unchecked") + protected V getResult(String key) { + return (V) result.get(key); + } + + @Test + public void testName() { + assertEquals(loggerName, logger.name()); + } + + @Test + public void testAllLevel() throws Exception { + testLevel(InternalLogLevel.TRACE); + testLevel(InternalLogLevel.DEBUG); + testLevel(InternalLogLevel.INFO); + testLevel(InternalLogLevel.WARN); + testLevel(InternalLogLevel.ERROR); + } + + protected void testLevel(InternalLogLevel level) throws Exception { + result.clear(); + + String format1 = "a={}", format2 = "a={}, b= {}", format3 = "a={}, b= {}, c= {}"; + String msg = "a test message from Junit"; + Exception ex = new Exception("a test Exception from Junit"); + + Class clazz = InternalLogger.class; + String levelName = level.name(), logMethod = levelName.toLowerCase(); + Method isXXEnabled = clazz + .getMethod("is" + levelName.charAt(0) + levelName.substring(1).toLowerCase() + "Enabled"); + + // when level log is disabled + setLevelEnable(level, false); + assertFalse((Boolean) isXXEnabled.invoke(logger)); + + // test xx(msg) + clazz.getMethod(logMethod, String.class).invoke(logger, msg); + assertTrue(result.isEmpty()); + + // test xx(format, arg) + clazz.getMethod(logMethod, String.class, Object.class).invoke(logger, format1, msg); + assertTrue(result.isEmpty()); + + // test xx(format, argA, argB) + clazz.getMethod(logMethod, String.class, Object.class, Object.class).invoke(logger, format2, msg, msg); + assertTrue(result.isEmpty()); + + // test xx(format, ...arguments) + clazz.getMethod(logMethod, String.class, Object[].class).invoke(logger, format3, + new Object[] { msg, msg, msg }); + assertTrue(result.isEmpty()); + + // test xx(format, ...arguments), the last argument is Throwable + clazz.getMethod(logMethod, String.class, Object[].class).invoke(logger, format3, + new Object[] { msg, msg, msg, ex }); + assertTrue(result.isEmpty()); + + // test xx(msg, Throwable) + clazz.getMethod(logMethod, String.class, Throwable.class).invoke(logger, msg, ex); + assertTrue(result.isEmpty()); + + // test xx(Throwable) + clazz.getMethod(logMethod, Throwable.class).invoke(logger, ex); + assertTrue(result.isEmpty()); + + // when level log is enabled + setLevelEnable(level, true); + assertTrue((Boolean) isXXEnabled.invoke(logger)); + + // test xx(msg) + result.clear(); + clazz.getMethod(logMethod, String.class).invoke(logger, msg); + assertResult(level, null, null, msg); + + // test xx(format, arg) + result.clear(); + clazz.getMethod(logMethod, String.class, Object.class).invoke(logger, format1, msg); + assertResult(level, format1, null, msg); + + // test xx(format, argA, argB) + result.clear(); + clazz.getMethod(logMethod, String.class, Object.class, Object.class).invoke(logger, format2, msg, msg); + assertResult(level, format2, null, msg, msg); + + // test xx(format, ...arguments) + result.clear(); + clazz.getMethod(logMethod, String.class, Object[].class).invoke(logger, format3, + new Object[] { msg, msg, msg }); + assertResult(level, format3, null, msg, msg, msg); + + // test xx(format, ...arguments), the last argument is Throwable + result.clear(); + clazz.getMethod(logMethod, String.class, Object[].class).invoke(logger, format3, + new Object[] { msg, msg, msg, ex }); + assertResult(level, format3, ex, msg, msg, msg, ex); + + // test xx(msg, Throwable) + result.clear(); + clazz.getMethod(logMethod, String.class, Throwable.class).invoke(logger, msg, ex); + assertResult(level, null, ex, msg); + + // test xx(Throwable) + result.clear(); + clazz.getMethod(logMethod, Throwable.class).invoke(logger, ex); + assertResult(level, null, ex); + } + + /** a just default code, you can override to fix {@linkplain #mockLog} */ + protected void assertResult(InternalLogLevel level, String format, Throwable t, Object... args) { + assertFalse(result.isEmpty()); + } + + protected abstract void setLevelEnable(InternalLogLevel level, boolean enable) throws Exception; +} diff --git a/common/src/test/java/io/netty/util/internal/logging/Log4J2LoggerTest.java b/common/src/test/java/io/netty/util/internal/logging/Log4J2LoggerTest.java index 93cf453a7b..99c42ed845 100644 --- a/common/src/test/java/io/netty/util/internal/logging/Log4J2LoggerTest.java +++ b/common/src/test/java/io/netty/util/internal/logging/Log4J2LoggerTest.java @@ -15,211 +15,87 @@ */ package io.netty.util.internal.logging; -import org.junit.Test; +import static org.junit.Assert.assertEquals; + +import java.lang.reflect.Field; +import java.lang.reflect.Method; +import java.util.Arrays; + +import org.apache.logging.log4j.Level; +import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.Marker; +import org.apache.logging.log4j.message.Message; +import org.apache.logging.log4j.spi.ExtendedLoggerWrapper; +import org.hamcrest.CoreMatchers; +import org.junit.Assume; +import org.junit.Test; -import static org.junit.Assert.assertTrue; -import static org.mockito.Mockito.*; +import io.netty.util.internal.ReflectionUtil; -public class Log4J2LoggerTest { - private static final Exception e = new Exception(); +/** + * {@linkplain Log4J2Logger} extends {@linkplain ExtendedLoggerWrapper} implements {@linkplain InternalLogger}.
+ * {@linkplain ExtendedLoggerWrapper} is Log4j2 wrapper class to support wrapped loggers, + * so There is no need to test it's method.
+ * We only need to test the netty's {@linkplain InternalLogger} interface method.
+ * It's meaning that we only need to test the Override method in the {@linkplain Log4J2Logger}. + */ +public class Log4J2LoggerTest extends AbstractInternalLoggerTest { - @Test - public void testIsTraceEnabled() { - Logger mock = mock(Logger.class); + { + mockLog = LogManager.getLogger(loggerName); + logger = new Log4J2Logger(mockLog) { + private static final long serialVersionUID = 1L; - when(mock.getName()).thenReturn("foo"); - when(mock.isTraceEnabled()).thenReturn(true); - InternalLogger logger = new Log4J2Logger(mock); - assertTrue(logger.isTraceEnabled()); - - verify(mock).getName(); - verify(mock).isTraceEnabled(); + @Override + public void logMessage(String fqcn, Level level, Marker marker, Message message, Throwable t) { + result.put("level", level.name()); + result.put("t", t); + super.logMessage(fqcn, level, marker, message, t); + }; + }; } @Test - public void testIsDebugEnabled() { - Logger mock = mock(Logger.class); - - when(mock.getName()).thenReturn("foo"); - when(mock.isDebugEnabled()).thenReturn(true); - - InternalLogger logger = new Log4J2Logger(mock); - assertTrue(logger.isDebugEnabled()); - - verify(mock).getName(); - verify(mock).isDebugEnabled(); + public void testEXCEPTION_MESSAGE() { + assertEquals(getFieldValue(AbstractInternalLogger.class, "EXCEPTION_MESSAGE"), + getFieldValue(Log4J2Logger.class, "EXCEPTION_MESSAGE")); } - @Test - public void testIsInfoEnabled() { - Logger mock = mock(Logger.class); - - when(mock.getName()).thenReturn("foo"); - when(mock.isInfoEnabled()).thenReturn(true); - - InternalLogger logger = new Log4J2Logger(mock); - assertTrue(logger.isInfoEnabled()); - - verify(mock).getName(); - verify(mock).isInfoEnabled(); + @SuppressWarnings("unchecked") + private static T getFieldValue(Class clazz, String fieldName) { + try { + Field field = clazz.getDeclaredField(fieldName); + if (!field.isAccessible()) { + Assume.assumeThat(ReflectionUtil.trySetAccessible(field), CoreMatchers.nullValue()); + } + return (T) field.get(AbstractInternalLogger.class); + } catch (ReflectiveOperationException e) { + throw new IllegalStateException(e); + } } - @Test - public void testIsWarnEnabled() { - Logger mock = mock(Logger.class); + @Override + protected void setLevelEnable(InternalLogLevel level, boolean enable) throws Exception { + Level targetLevel = Level.valueOf(level.name()); + if (!enable) { + Level[] levels = Level.values(); + Arrays.sort(levels); + int pos = Arrays.binarySearch(levels, targetLevel); + targetLevel = levels[pos - 1]; + } - when(mock.getName()).thenReturn("foo"); - when(mock.isWarnEnabled()).thenReturn(true); - - InternalLogger logger = new Log4J2Logger(mock); - assertTrue(logger.isWarnEnabled()); - - verify(mock).getName(); - verify(mock).isWarnEnabled(); + Method method = mockLog.getClass().getDeclaredMethod("setLevel", Level.class); + if (!method.isAccessible()) { + Assume.assumeThat(ReflectionUtil.trySetAccessible(method), CoreMatchers.nullValue()); + } + method.invoke(mockLog, targetLevel); } - @Test - public void testIsErrorEnabled() { - Logger mock = mock(Logger.class); - - when(mock.getName()).thenReturn("foo"); - when(mock.isErrorEnabled()).thenReturn(true); - - InternalLogger logger = new Log4J2Logger(mock); - assertTrue(logger.isErrorEnabled()); - - verify(mock).getName(); - verify(mock).isErrorEnabled(); - } - - @Test - public void testTrace() { - Logger mock = mock(Logger.class); - - when(mock.getName()).thenReturn("foo"); - - InternalLogger logger = new Log4J2Logger(mock); - logger.trace("a"); - - verify(mock).getName(); - verify(mock).trace("a"); - } - - @Test - public void testTraceWithException() { - Logger mock = mock(Logger.class); - - when(mock.getName()).thenReturn("foo"); - - InternalLogger logger = new Log4J2Logger(mock); - logger.trace("a", e); - - verify(mock).getName(); - verify(mock).trace("a", e); - } - - @Test - public void testDebug() { - Logger mock = mock(Logger.class); - - when(mock.getName()).thenReturn("foo"); - - InternalLogger logger = new Log4J2Logger(mock); - logger.debug("a"); - - verify(mock).getName(); - verify(mock).debug("a"); - } - - @Test - public void testDebugWithException() { - Logger mock = mock(Logger.class); - - when(mock.getName()).thenReturn("foo"); - - InternalLogger logger = new Log4J2Logger(mock); - logger.debug("a", e); - - verify(mock).getName(); - verify(mock).debug("a", e); - } - - @Test - public void testInfo() { - Logger mock = mock(Logger.class); - - when(mock.getName()).thenReturn("foo"); - - InternalLogger logger = new Log4J2Logger(mock); - logger.info("a"); - - verify(mock).getName(); - verify(mock).info("a"); - } - - @Test - public void testInfoWithException() { - Logger mock = mock(Logger.class); - - when(mock.getName()).thenReturn("foo"); - - InternalLogger logger = new Log4J2Logger(mock); - logger.info("a", e); - - verify(mock).getName(); - verify(mock).info("a", e); - } - - @Test - public void testWarn() { - Logger mock = mock(Logger.class); - - when(mock.getName()).thenReturn("foo"); - - InternalLogger logger = new Log4J2Logger(mock); - logger.warn("a"); - - verify(mock).getName(); - verify(mock).warn("a"); - } - - @Test - public void testWarnWithException() { - Logger mock = mock(Logger.class); - - when(mock.getName()).thenReturn("foo"); - - InternalLogger logger = new Log4J2Logger(mock); - logger.warn("a", e); - - verify(mock).getName(); - verify(mock).warn("a", e); - } - - @Test - public void testError() { - Logger mock = mock(Logger.class); - - when(mock.getName()).thenReturn("foo"); - - InternalLogger logger = new Log4J2Logger(mock); - logger.error("a"); - - verify(mock).getName(); - verify(mock).error("a"); - } - - @Test - public void testErrorWithException() { - Logger mock = mock(Logger.class); - - when(mock.getName()).thenReturn("foo"); - - InternalLogger logger = new Log4J2Logger(mock); - logger.error("a", e); - - verify(mock).getName(); - verify(mock).error("a", e); + @Override + protected void assertResult(InternalLogLevel level, String format, Throwable t, Object... args) { + super.assertResult(level, format, t, args); + assertEquals(t, result.get("t")); + assertEquals(level.name(), result.get("level")); } }