andreacavalli/netty5
1
0
Fork 0
Code Issues Pull Requests Projects Releases Wiki Activity

LocationAwareSlf4jLogger does not correctly format log message. (#8595)

Browse Source 
Motivation:

We did miss to use MessageFormatter inside LocationAwareSlf4jLogger and so {} was not correctly replaced in log messages when using slf4j.
This regression was introduced by afe0767e9c.

Modifications:

- Make use of MessageFormatter
- Add unit test.

Result:

Fixes https://github.com/netty/netty/issues/8483.
This commit is contained in:
Norman Maurer 2018-11-27 11:44:27 +01:00
parent 2e0922d773
commit cb1090653f
2 changed files with 90 additions and 23 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

46
common/src/main/java/io/netty/util/internal/logging/LocationAwareSlf4JLogger.java
View File

@ -28,7 +28,7 @@ final class LocationAwareSlf4JLogger extends AbstractInternalLogger {
// IMPORTANT: All our log methods first check if the log level is enabled before call the wrapped // IMPORTANT: All our log methods first check if the log level is enabled before call the wrapped
// LocationAwareLogger.log(...) method. This is done to reduce GC creation that is caused by varargs. // LocationAwareLogger.log(...) method. This is done to reduce GC creation that is caused by varargs.
private static final String FQCN = LocationAwareSlf4JLogger.class.getName(); static final String FQCN = LocationAwareSlf4JLogger.class.getName();
private static final long serialVersionUID = -8292030083201538180L; private static final long serialVersionUID = -8292030083201538180L;
private final transient LocationAwareLogger logger; private final transient LocationAwareLogger logger;
@ -38,12 +38,16 @@ final class LocationAwareSlf4JLogger extends AbstractInternalLogger {
this.logger = logger; this.logger = logger;
} }
private void log(final int level, final String message, final Object... params) { private void log(final int level, final String message) {
logger.log(null, FQCN, level, message, params, null); logger.log(null, FQCN, level, message, null, null);
} }
private void log(final int level, final String message, Throwable throwable, final Object... params) { private void log(final int level, final String message, Throwable cause) {
logger.log(null, FQCN, level, message, params, throwable); logger.log(null, FQCN, level, message, null, cause);
}
private void log(final int level, final org.slf4j.helpers.FormattingTuple tuple) {
logger.log(null, FQCN, level, tuple.getMessage(), tuple.getArgArray(), tuple.getThrowable());
} }
@Override @Override
@ -54,28 +58,28 @@ final class LocationAwareSlf4JLogger extends AbstractInternalLogger {
@Override @Override
public void trace(String msg) { public void trace(String msg) {
if (isTraceEnabled()) { if (isTraceEnabled()) {
log(TRACE_INT, msg, null); log(TRACE_INT, msg);
} }
} }
@Override @Override
public void trace(String format, Object arg) { public void trace(String format, Object arg) {
if (isTraceEnabled()) { if (isTraceEnabled()) {
log(TRACE_INT, format, arg); log(TRACE_INT, org.slf4j.helpers.MessageFormatter.format(format, arg));
} }
} }
@Override @Override
public void trace(String format, Object argA, Object argB) { public void trace(String format, Object argA, Object argB) {
if (isTraceEnabled()) { if (isTraceEnabled()) {
log(TRACE_INT, format, argA, argB); log(TRACE_INT, org.slf4j.helpers.MessageFormatter.format(format, argA, argB));
} }
} }
@Override @Override
public void trace(String format, Object... argArray) { public void trace(String format, Object... argArray) {
if (isTraceEnabled()) { if (isTraceEnabled()) {
log(TRACE_INT, format, argArray); log(TRACE_INT, org.slf4j.helpers.MessageFormatter.format(format, argArray));
} }
} }
@ -101,21 +105,21 @@ final class LocationAwareSlf4JLogger extends AbstractInternalLogger {
@Override @Override
public void debug(String format, Object arg) { public void debug(String format, Object arg) {
if (isDebugEnabled()) { if (isDebugEnabled()) {
log(DEBUG_INT, format, arg); log(DEBUG_INT, org.slf4j.helpers.MessageFormatter.format(format, arg));
} }
} }
@Override @Override
public void debug(String format, Object argA, Object argB) { public void debug(String format, Object argA, Object argB) {
if (isDebugEnabled()) { if (isDebugEnabled()) {
log(DEBUG_INT, format, argA, argB); log(DEBUG_INT, org.slf4j.helpers.MessageFormatter.format(format, argA, argB));
} }
} }
@Override @Override
public void debug(String format, Object... argArray) { public void debug(String format, Object... argArray) {
if (isDebugEnabled()) { if (isDebugEnabled()) {
log(DEBUG_INT, format, argArray); log(DEBUG_INT, org.slf4j.helpers.MessageFormatter.format(format, argArray));
} }
} }
@ -141,21 +145,21 @@ final class LocationAwareSlf4JLogger extends AbstractInternalLogger {
@Override @Override
public void info(String format, Object arg) { public void info(String format, Object arg) {
if (isInfoEnabled()) { if (isInfoEnabled()) {
log(INFO_INT, format, arg); log(INFO_INT, org.slf4j.helpers.MessageFormatter.format(format, arg));
} }
} }
@Override @Override
public void info(String format, Object argA, Object argB) { public void info(String format, Object argA, Object argB) {
if (isInfoEnabled()) { if (isInfoEnabled()) {
log(INFO_INT, format, argA, argB); log(INFO_INT, org.slf4j.helpers.MessageFormatter.format(format, argA, argB));
} }
} }
@Override @Override
public void info(String format, Object... argArray) { public void info(String format, Object... argArray) {
if (isInfoEnabled()) { if (isInfoEnabled()) {
log(INFO_INT, format, argArray); log(INFO_INT, org.slf4j.helpers.MessageFormatter.format(format, argArray));
} }
} }
@ -181,21 +185,21 @@ final class LocationAwareSlf4JLogger extends AbstractInternalLogger {
@Override @Override
public void warn(String format, Object arg) { public void warn(String format, Object arg) {
if (isWarnEnabled()) { if (isWarnEnabled()) {
log(WARN_INT, format, arg); log(WARN_INT, org.slf4j.helpers.MessageFormatter.format(format, arg));
} }
} }
@Override @Override
public void warn(String format, Object... argArray) { public void warn(String format, Object... argArray) {
if (isWarnEnabled()) { if (isWarnEnabled()) {
log(WARN_INT, format, argArray); log(WARN_INT, org.slf4j.helpers.MessageFormatter.format(format, argArray));
} }
} }
@Override @Override
public void warn(String format, Object argA, Object argB) { public void warn(String format, Object argA, Object argB) {
if (isWarnEnabled()) { if (isWarnEnabled()) {
log(WARN_INT, format, argA, argB); log(WARN_INT, org.slf4j.helpers.MessageFormatter.format(format, argA, argB));
} }
} }
@ -221,21 +225,21 @@ final class LocationAwareSlf4JLogger extends AbstractInternalLogger {
@Override @Override
public void error(String format, Object arg) { public void error(String format, Object arg) {
if (isErrorEnabled()) { if (isErrorEnabled()) {
log(ERROR_INT, format, arg); log(ERROR_INT, org.slf4j.helpers.MessageFormatter.format(format, arg));
} }
} }
@Override @Override
public void error(String format, Object argA, Object argB) { public void error(String format, Object argA, Object argB) {
if (isErrorEnabled()) { if (isErrorEnabled()) {
log(ERROR_INT, format, argA, argB); log(ERROR_INT, org.slf4j.helpers.MessageFormatter.format(format, argA, argB));
} }
} }
@Override @Override
public void error(String format, Object... argArray) { public void error(String format, Object... argArray) {
if (isErrorEnabled()) { if (isErrorEnabled()) {
log(ERROR_INT, format, argArray); log(ERROR_INT, org.slf4j.helpers.MessageFormatter.format(format, argArray));
} }
} }

67
common/src/test/java/io/netty/util/internal/logging/Slf4JLoggerFactoryTest.java
View File

@ -16,13 +16,19 @@
package io.netty.util.internal.logging; package io.netty.util.internal.logging;
import org.junit.Test; import org.junit.Test;
import org.mockito.ArgumentCaptor;
import org.mockito.ArgumentMatchers;
import org.slf4j.Logger; import org.slf4j.Logger;
import org.slf4j.Marker;
import org.slf4j.spi.LocationAwareLogger; import org.slf4j.spi.LocationAwareLogger;
import java.util.Iterator;
import static org.junit.Assert.assertEquals; import static org.junit.Assert.assertEquals;
import static org.junit.Assert.assertFalse;
import static org.junit.Assert.assertTrue; import static org.junit.Assert.assertTrue;
import static org.mockito.Mockito.mock; import static org.mockito.ArgumentMatchers.*;
import static org.mockito.Mockito.when; import static org.mockito.Mockito.*;
public class Slf4JLoggerFactoryTest { public class Slf4JLoggerFactoryTest {
@ -50,4 +56,61 @@ public class Slf4JLoggerFactoryTest {
assertTrue(internalLogger instanceof LocationAwareSlf4JLogger); assertTrue(internalLogger instanceof LocationAwareSlf4JLogger);
assertEquals("testlogger", internalLogger.name()); assertEquals("testlogger", internalLogger.name());
} }
@Test
public void testFormatMessage() {
ArgumentCaptor<String> captor = ArgumentCaptor.forClass(String.class);
LocationAwareLogger logger = mock(LocationAwareLogger.class);
when(logger.isDebugEnabled()).thenReturn(true);
when(logger.isErrorEnabled()).thenReturn(true);
when(logger.isInfoEnabled()).thenReturn(true);
when(logger.isTraceEnabled()).thenReturn(true);
when(logger.isWarnEnabled()).thenReturn(true);
when(logger.getName()).thenReturn("testlogger");
InternalLogger internalLogger = Slf4JLoggerFactory.wrapLogger(logger);
internalLogger.debug("{}", "debug");
internalLogger.debug("{} {}", "debug1", "debug2");
internalLogger.error("{}", "error");
internalLogger.error("{} {}", "error1", "error2");
internalLogger.info("{}", "info");
internalLogger.info("{} {}", "info1", "info2");
internalLogger.trace("{}", "trace");
internalLogger.trace("{} {}", "trace1", "trace2");
internalLogger.warn("{}", "warn");
internalLogger.warn("{} {}", "warn1", "warn2");
verify(logger, times(2)).log(ArgumentMatchers.<Marker>isNull(), eq(LocationAwareSlf4JLogger.FQCN),
eq(LocationAwareLogger.DEBUG_INT), captor.capture(), any(Object[].class),
ArgumentMatchers.<Throwable>isNull());
verify(logger, times(2)).log(ArgumentMatchers.<Marker>isNull(), eq(LocationAwareSlf4JLogger.FQCN),
eq(LocationAwareLogger.ERROR_INT), captor.capture(), any(Object[].class),
ArgumentMatchers.<Throwable>isNull());
verify(logger, times(2)).log(ArgumentMatchers.<Marker>isNull(), eq(LocationAwareSlf4JLogger.FQCN),
eq(LocationAwareLogger.INFO_INT), captor.capture(), any(Object[].class),
ArgumentMatchers.<Throwable>isNull());
verify(logger, times(2)).log(ArgumentMatchers.<Marker>isNull(), eq(LocationAwareSlf4JLogger.FQCN),
eq(LocationAwareLogger.TRACE_INT), captor.capture(), any(Object[].class),
ArgumentMatchers.<Throwable>isNull());
verify(logger, times(2)).log(ArgumentMatchers.<Marker>isNull(), eq(LocationAwareSlf4JLogger.FQCN),
eq(LocationAwareLogger.WARN_INT), captor.capture(), any(Object[].class),
ArgumentMatchers.<Throwable>isNull());
Iterator<String> logMessages = captor.getAllValues().iterator();
assertEquals("debug", logMessages.next());
assertEquals("debug1 debug2", logMessages.next());
assertEquals("error", logMessages.next());
assertEquals("error1 error2", logMessages.next());
assertEquals("info", logMessages.next());
assertEquals("info1 info2", logMessages.next());
assertEquals("trace", logMessages.next());
assertEquals("trace1 trace2", logMessages.next());
assertEquals("warn", logMessages.next());
assertEquals("warn1 warn2", logMessages.next());
assertFalse(logMessages.hasNext());
}
} }