Fix varargs parameter logging in LocationAwareSlf4JLogger (#8834)

Motivation

As pointed out by @91he in
https://github.com/netty/netty/pull/8595#issuecomment-459181794, there
is a remaining bug in LocationAwareSlf4JLogger following the updates
done in #8595. The logging methods which take a varargs message
parameter array should format using MessageFormatter.arrayFormat rather
than MessageFormatter.format.

Modifications

Change varargs param methods in LocationAwareSlf4JLogger to use
MessageFormatter.arrayFormat and extend unit test to cover these cases.

Results

Correct log output when logging messages with > 2 parameters when using
LocationAwareSlf4JLogger.
This commit is contained in:
Nick Hill 2019-02-01 22:03:03 -08:00 committed by Norman Maurer
parent 98aa5fbd66
commit 154d6e87f6
2 changed files with 20 additions and 10 deletions

View File

@ -79,7 +79,7 @@ final class LocationAwareSlf4JLogger extends AbstractInternalLogger {
@Override @Override
public void trace(String format, Object... argArray) { public void trace(String format, Object... argArray) {
if (isTraceEnabled()) { if (isTraceEnabled()) {
log(TRACE_INT, org.slf4j.helpers.MessageFormatter.format(format, argArray)); log(TRACE_INT, org.slf4j.helpers.MessageFormatter.arrayFormat(format, argArray));
} }
} }
@ -119,7 +119,7 @@ final class LocationAwareSlf4JLogger extends AbstractInternalLogger {
@Override @Override
public void debug(String format, Object... argArray) { public void debug(String format, Object... argArray) {
if (isDebugEnabled()) { if (isDebugEnabled()) {
log(DEBUG_INT, org.slf4j.helpers.MessageFormatter.format(format, argArray)); log(DEBUG_INT, org.slf4j.helpers.MessageFormatter.arrayFormat(format, argArray));
} }
} }
@ -159,7 +159,7 @@ final class LocationAwareSlf4JLogger extends AbstractInternalLogger {
@Override @Override
public void info(String format, Object... argArray) { public void info(String format, Object... argArray) {
if (isInfoEnabled()) { if (isInfoEnabled()) {
log(INFO_INT, org.slf4j.helpers.MessageFormatter.format(format, argArray)); log(INFO_INT, org.slf4j.helpers.MessageFormatter.arrayFormat(format, argArray));
} }
} }
@ -192,7 +192,7 @@ final class LocationAwareSlf4JLogger extends AbstractInternalLogger {
@Override @Override
public void warn(String format, Object... argArray) { public void warn(String format, Object... argArray) {
if (isWarnEnabled()) { if (isWarnEnabled()) {
log(WARN_INT, org.slf4j.helpers.MessageFormatter.format(format, argArray)); log(WARN_INT, org.slf4j.helpers.MessageFormatter.arrayFormat(format, argArray));
} }
} }
@ -239,7 +239,7 @@ final class LocationAwareSlf4JLogger extends AbstractInternalLogger {
@Override @Override
public void error(String format, Object... argArray) { public void error(String format, Object... argArray) {
if (isErrorEnabled()) { if (isErrorEnabled()) {
log(ERROR_INT, org.slf4j.helpers.MessageFormatter.format(format, argArray)); log(ERROR_INT, org.slf4j.helpers.MessageFormatter.arrayFormat(format, argArray));
} }
} }

View File

@ -71,46 +71,56 @@ public class Slf4JLoggerFactoryTest {
InternalLogger internalLogger = Slf4JLoggerFactory.wrapLogger(logger); InternalLogger internalLogger = Slf4JLoggerFactory.wrapLogger(logger);
internalLogger.debug("{}", "debug"); internalLogger.debug("{}", "debug");
internalLogger.debug("{} {}", "debug1", "debug2"); internalLogger.debug("{} {}", "debug1", "debug2");
internalLogger.debug("{} {} {}", "debug1", "debug2", "debug3");
internalLogger.error("{}", "error"); internalLogger.error("{}", "error");
internalLogger.error("{} {}", "error1", "error2"); internalLogger.error("{} {}", "error1", "error2");
internalLogger.error("{} {} {}", "error1", "error2", "error3");
internalLogger.info("{}", "info"); internalLogger.info("{}", "info");
internalLogger.info("{} {}", "info1", "info2"); internalLogger.info("{} {}", "info1", "info2");
internalLogger.info("{} {} {}", "info1", "info2", "info3");
internalLogger.trace("{}", "trace"); internalLogger.trace("{}", "trace");
internalLogger.trace("{} {}", "trace1", "trace2"); internalLogger.trace("{} {}", "trace1", "trace2");
internalLogger.trace("{} {} {}", "trace1", "trace2", "trace3");
internalLogger.warn("{}", "warn"); internalLogger.warn("{}", "warn");
internalLogger.warn("{} {}", "warn1", "warn2"); internalLogger.warn("{} {}", "warn1", "warn2");
internalLogger.warn("{} {} {}", "warn1", "warn2", "warn3");
verify(logger, times(2)).log(ArgumentMatchers.<Marker>isNull(), eq(LocationAwareSlf4JLogger.FQCN), verify(logger, times(3)).log(ArgumentMatchers.<Marker>isNull(), eq(LocationAwareSlf4JLogger.FQCN),
eq(LocationAwareLogger.DEBUG_INT), captor.capture(), any(Object[].class), eq(LocationAwareLogger.DEBUG_INT), captor.capture(), any(Object[].class),
ArgumentMatchers.<Throwable>isNull()); ArgumentMatchers.<Throwable>isNull());
verify(logger, times(2)).log(ArgumentMatchers.<Marker>isNull(), eq(LocationAwareSlf4JLogger.FQCN), verify(logger, times(3)).log(ArgumentMatchers.<Marker>isNull(), eq(LocationAwareSlf4JLogger.FQCN),
eq(LocationAwareLogger.ERROR_INT), captor.capture(), any(Object[].class), eq(LocationAwareLogger.ERROR_INT), captor.capture(), any(Object[].class),
ArgumentMatchers.<Throwable>isNull()); ArgumentMatchers.<Throwable>isNull());
verify(logger, times(2)).log(ArgumentMatchers.<Marker>isNull(), eq(LocationAwareSlf4JLogger.FQCN), verify(logger, times(3)).log(ArgumentMatchers.<Marker>isNull(), eq(LocationAwareSlf4JLogger.FQCN),
eq(LocationAwareLogger.INFO_INT), captor.capture(), any(Object[].class), eq(LocationAwareLogger.INFO_INT), captor.capture(), any(Object[].class),
ArgumentMatchers.<Throwable>isNull()); ArgumentMatchers.<Throwable>isNull());
verify(logger, times(2)).log(ArgumentMatchers.<Marker>isNull(), eq(LocationAwareSlf4JLogger.FQCN), verify(logger, times(3)).log(ArgumentMatchers.<Marker>isNull(), eq(LocationAwareSlf4JLogger.FQCN),
eq(LocationAwareLogger.TRACE_INT), captor.capture(), any(Object[].class), eq(LocationAwareLogger.TRACE_INT), captor.capture(), any(Object[].class),
ArgumentMatchers.<Throwable>isNull()); ArgumentMatchers.<Throwable>isNull());
verify(logger, times(2)).log(ArgumentMatchers.<Marker>isNull(), eq(LocationAwareSlf4JLogger.FQCN), verify(logger, times(3)).log(ArgumentMatchers.<Marker>isNull(), eq(LocationAwareSlf4JLogger.FQCN),
eq(LocationAwareLogger.WARN_INT), captor.capture(), any(Object[].class), eq(LocationAwareLogger.WARN_INT), captor.capture(), any(Object[].class),
ArgumentMatchers.<Throwable>isNull()); ArgumentMatchers.<Throwable>isNull());
Iterator<String> logMessages = captor.getAllValues().iterator(); Iterator<String> logMessages = captor.getAllValues().iterator();
assertEquals("debug", logMessages.next()); assertEquals("debug", logMessages.next());
assertEquals("debug1 debug2", logMessages.next()); assertEquals("debug1 debug2", logMessages.next());
assertEquals("debug1 debug2 debug3", logMessages.next());
assertEquals("error", logMessages.next()); assertEquals("error", logMessages.next());
assertEquals("error1 error2", logMessages.next()); assertEquals("error1 error2", logMessages.next());
assertEquals("error1 error2 error3", logMessages.next());
assertEquals("info", logMessages.next()); assertEquals("info", logMessages.next());
assertEquals("info1 info2", logMessages.next()); assertEquals("info1 info2", logMessages.next());
assertEquals("info1 info2 info3", logMessages.next());
assertEquals("trace", logMessages.next()); assertEquals("trace", logMessages.next());
assertEquals("trace1 trace2", logMessages.next()); assertEquals("trace1 trace2", logMessages.next());
assertEquals("trace1 trace2 trace3", logMessages.next());
assertEquals("warn", logMessages.next()); assertEquals("warn", logMessages.next());
assertEquals("warn1 warn2", logMessages.next()); assertEquals("warn1 warn2", logMessages.next());
assertEquals("warn1 warn2 warn3", logMessages.next());
assertFalse(logMessages.hasNext()); assertFalse(logMessages.hasNext());
} }
} }