From 58ad52615345f6498f8d738d3fef129c3342cc96 Mon Sep 17 00:00:00 2001 From: "Piotr P. Karwasz" Date: Wed, 23 Oct 2024 08:50:43 +0200 Subject: [PATCH] Makes `SubstituteLogger` location aware Currently, `SubstituteLogger` neither supports location information from upstream callers nor passes location information to the delegated logger. This PR: - implements `LocationAwareLogger`, which allows upstream callers to pass location information both through the `LocationAwareLogger` API and the fluent API. - sets the correct caller boundary, when the classic API methods are invoked. --- .../org/slf4j/event/DefaultLoggingEvent.java | 4 +- .../org/slf4j/helpers/SubstituteLogger.java | 232 +++++++++++------- ...gerTest.java => SubstituteLoggerTest.java} | 86 ++++++- 3 files changed, 222 insertions(+), 100 deletions(-) rename slf4j-api/src/test/java/org/slf4j/helpers/{SubstitutableLoggerTest.java => SubstituteLoggerTest.java} (54%) diff --git a/slf4j-api/src/main/java/org/slf4j/event/DefaultLoggingEvent.java b/slf4j-api/src/main/java/org/slf4j/event/DefaultLoggingEvent.java index 5a1014386..0f5bd466c 100755 --- a/slf4j-api/src/main/java/org/slf4j/event/DefaultLoggingEvent.java +++ b/slf4j-api/src/main/java/org/slf4j/event/DefaultLoggingEvent.java @@ -52,7 +52,9 @@ public void addArgument(Object p) { } public void addArguments(Object... args) { - getNonNullArguments().addAll(Arrays.asList(args)); + if (args != null) { + getNonNullArguments().addAll(Arrays.asList(args)); + } } private List getNonNullArguments() { diff --git a/slf4j-api/src/main/java/org/slf4j/helpers/SubstituteLogger.java b/slf4j-api/src/main/java/org/slf4j/helpers/SubstituteLogger.java index b9e160d70..2278f019b 100644 --- a/slf4j-api/src/main/java/org/slf4j/helpers/SubstituteLogger.java +++ b/slf4j-api/src/main/java/org/slf4j/helpers/SubstituteLogger.java @@ -34,19 +34,23 @@ import org.slf4j.event.Level; import org.slf4j.event.LoggingEvent; import org.slf4j.event.SubstituteLoggingEvent; +import org.slf4j.spi.CallerBoundaryAware; +import org.slf4j.spi.LocationAwareLogger; import org.slf4j.spi.LoggingEventBuilder; /** * A logger implementation which logs via a delegate logger. By default, the delegate is a * {@link NOPLogger}. However, a different delegate can be set at any time. - * + * *

See also the relevant * error code documentation. * * @author Chetan Mehrotra * @author Ceki Gulcu */ -public class SubstituteLogger implements Logger { +public class SubstituteLogger implements LocationAwareLogger { + + private static final String SELF = SubstituteLogger.class.getName(); private final String name; private volatile Logger _delegate; @@ -90,27 +94,27 @@ public boolean isTraceEnabled() { @Override public void trace(String msg) { - delegate().trace(msg); + internalEventBuilder(Level.TRACE).log(msg); } @Override public void trace(String format, Object arg) { - delegate().trace(format, arg); + internalEventBuilder(Level.TRACE).log(format, arg); } @Override public void trace(String format, Object arg1, Object arg2) { - delegate().trace(format, arg1, arg2); + internalEventBuilder(Level.TRACE).log(format, arg1, arg2); } @Override public void trace(String format, Object... arguments) { - delegate().trace(format, arguments); - } - + internalEventBuilder(Level.TRACE).log(format, arguments); + } + @Override public void trace(String msg, Throwable t) { - delegate().trace(msg, t); + internalEventBuilder(Level.TRACE).setCause(t).log(msg); } @Override @@ -120,25 +124,25 @@ public boolean isTraceEnabled(Marker marker) { @Override public void trace(Marker marker, String msg) { - delegate().trace(marker, msg); + internalEventBuilder(marker, Level.TRACE).log(msg); } @Override public void trace(Marker marker, String format, Object arg) { - delegate().trace(marker, format, arg); + internalEventBuilder(marker, Level.TRACE).log(format, arg); } @Override public void trace(Marker marker, String format, Object arg1, Object arg2) { - delegate().trace(marker, format, arg1, arg2); + internalEventBuilder(marker, Level.TRACE).log(format, arg1, arg2); } @Override public void trace(Marker marker, String format, Object... arguments) { - delegate().trace(marker, format, arguments); + internalEventBuilder(marker, Level.TRACE).log(format, arguments); } @Override public void trace(Marker marker, String msg, Throwable t) { - delegate().trace(marker, msg, t); + internalEventBuilder(marker, Level.TRACE).setCause(t).log(msg); } @Override @@ -153,27 +157,27 @@ public boolean isDebugEnabled() { @Override public void debug(String msg) { - delegate().debug(msg); + internalEventBuilder(Level.DEBUG).log(msg); } @Override public void debug(String format, Object arg) { - delegate().debug(format, arg); + internalEventBuilder(Level.DEBUG).log(format, arg); } @Override public void debug(String format, Object arg1, Object arg2) { - delegate().debug(format, arg1, arg2); + internalEventBuilder(Level.DEBUG).log(format, arg1, arg2); } @Override public void debug(String format, Object... arguments) { - delegate().debug(format, arguments); + internalEventBuilder(Level.DEBUG).log(format, arguments); } @Override public void debug(String msg, Throwable t) { - delegate().debug(msg, t); + internalEventBuilder(Level.DEBUG).setCause(t).log(msg); } @Override @@ -183,232 +187,232 @@ public boolean isDebugEnabled(Marker marker) { @Override public void debug(Marker marker, String msg) { - delegate().debug(marker, msg); + internalEventBuilder(marker, Level.DEBUG).log(msg); } @Override public void debug(Marker marker, String format, Object arg) { - delegate().debug(marker, format, arg); + internalEventBuilder(marker, Level.DEBUG).log(format, arg); } @Override public void debug(Marker marker, String format, Object arg1, Object arg2) { - delegate().debug(marker, format, arg1, arg2); + internalEventBuilder(marker, Level.DEBUG).log(format, arg1, arg2); } @Override public void debug(Marker marker, String format, Object... arguments) { - delegate().debug(marker, format, arguments); + internalEventBuilder(marker, Level.DEBUG).log(format, arguments); } @Override public void debug(Marker marker, String msg, Throwable t) { - delegate().debug(marker, msg, t); + internalEventBuilder(marker, Level.DEBUG).setCause(t).log(msg); } @Override public LoggingEventBuilder atDebug() { return delegate().atDebug(); } - + @Override public boolean isInfoEnabled() { return delegate().isInfoEnabled(); } - + @Override public void info(String msg) { - delegate().info(msg); + internalEventBuilder(Level.INFO).log(msg); } - + @Override public void info(String format, Object arg) { - delegate().info(format, arg); + internalEventBuilder(Level.INFO).log(format, arg); } - + @Override public void info(String format, Object arg1, Object arg2) { - delegate().info(format, arg1, arg2); + internalEventBuilder(Level.INFO).log(format, arg1, arg2); } - + @Override public void info(String format, Object... arguments) { - delegate().info(format, arguments); + internalEventBuilder(Level.INFO).log(format, arguments); } - + @Override public void info(String msg, Throwable t) { - delegate().info(msg, t); + internalEventBuilder(Level.INFO).setCause(t).log(msg); } - + @Override public boolean isInfoEnabled(Marker marker) { return delegate().isInfoEnabled(marker); } - + @Override public void info(Marker marker, String msg) { - delegate().info(marker, msg); + internalEventBuilder(marker, Level.INFO).log(msg); } - + @Override public void info(Marker marker, String format, Object arg) { - delegate().info(marker, format, arg); + internalEventBuilder(marker, Level.INFO).log(format, arg); } - + @Override public void info(Marker marker, String format, Object arg1, Object arg2) { - delegate().info(marker, format, arg1, arg2); + internalEventBuilder(marker, Level.INFO).log(format, arg1, arg2); } - + @Override public void info(Marker marker, String format, Object... arguments) { - delegate().info(marker, format, arguments); + internalEventBuilder(marker, Level.INFO).log(format, arguments); } - + @Override public void info(Marker marker, String msg, Throwable t) { - delegate().info(marker, msg, t); + internalEventBuilder(marker, Level.INFO).setCause(t).log(msg); } - + @Override public LoggingEventBuilder atInfo() { return delegate().atInfo(); } - + @Override public boolean isWarnEnabled() { return delegate().isWarnEnabled(); } - + @Override public void warn(String msg) { - delegate().warn(msg); + internalEventBuilder(Level.WARN).log(msg); } - + @Override public void warn(String format, Object arg) { - delegate().warn(format, arg); + internalEventBuilder(Level.WARN).log(format, arg); } - + @Override public void warn(String format, Object arg1, Object arg2) { - delegate().warn(format, arg1, arg2); + internalEventBuilder(Level.WARN).log(format, arg1, arg2); } - + @Override public void warn(String format, Object... arguments) { - delegate().warn(format, arguments); + internalEventBuilder(Level.WARN).log(format, arguments); } - + @Override public void warn(String msg, Throwable t) { - delegate().warn(msg, t); + internalEventBuilder(Level.WARN).setCause(t).log(msg); } public boolean isWarnEnabled(Marker marker) { return delegate().isWarnEnabled(marker); } - + @Override public void warn(Marker marker, String msg) { - delegate().warn(marker, msg); + internalEventBuilder(marker, Level.WARN).log(msg); } - + @Override public void warn(Marker marker, String format, Object arg) { - delegate().warn(marker, format, arg); + internalEventBuilder(marker, Level.WARN).log(format, arg); } - + @Override public void warn(Marker marker, String format, Object arg1, Object arg2) { - delegate().warn(marker, format, arg1, arg2); + internalEventBuilder(marker, Level.WARN).log(format, arg1, arg2); } - + @Override public void warn(Marker marker, String format, Object... arguments) { - delegate().warn(marker, format, arguments); + internalEventBuilder(marker, Level.WARN).log(format, arguments); } - + @Override public void warn(Marker marker, String msg, Throwable t) { - delegate().warn(marker, msg, t); + internalEventBuilder(marker, Level.WARN).setCause(t).log(msg); } - + @Override public LoggingEventBuilder atWarn() { return delegate().atWarn(); } - - + + @Override public boolean isErrorEnabled() { return delegate().isErrorEnabled(); } - + @Override public void error(String msg) { - delegate().error(msg); + internalEventBuilder(Level.ERROR).log(msg); } - + @Override public void error(String format, Object arg) { - delegate().error(format, arg); + internalEventBuilder(Level.ERROR).log(format, arg); } - + @Override public void error(String format, Object arg1, Object arg2) { - delegate().error(format, arg1, arg2); + internalEventBuilder(Level.ERROR).log(format, arg1, arg2); } - + @Override public void error(String format, Object... arguments) { - delegate().error(format, arguments); + internalEventBuilder(Level.ERROR).log(format, arguments); } - + @Override public void error(String msg, Throwable t) { - delegate().error(msg, t); + internalEventBuilder(Level.ERROR).setCause(t).log(msg); } - + @Override public boolean isErrorEnabled(Marker marker) { return delegate().isErrorEnabled(marker); } - + @Override public void error(Marker marker, String msg) { - delegate().error(marker, msg); + internalEventBuilder(marker, Level.ERROR).log(msg); } - + @Override public void error(Marker marker, String format, Object arg) { - delegate().error(marker, format, arg); + internalEventBuilder(marker, Level.ERROR).log(format, arg); } - + @Override public void error(Marker marker, String format, Object arg1, Object arg2) { - delegate().error(marker, format, arg1, arg2); + internalEventBuilder(marker, Level.ERROR).log(format, arg1, arg2); } - + @Override public void error(Marker marker, String format, Object... arguments) { - delegate().error(marker, format, arguments); + internalEventBuilder(marker, Level.ERROR).log(format, arguments); } - + @Override public void error(Marker marker, String msg, Throwable t) { - delegate().error(marker, msg, t); + internalEventBuilder(marker, Level.ERROR).setCause(t).log(msg); } @Override public LoggingEventBuilder atError() { return delegate().atError(); } - + @Override public boolean equals(Object o) { if (this == o) @@ -471,7 +475,7 @@ public boolean isDelegateEventAware() { } return delegateEventAware; } - + public void log(LoggingEvent event) { if (isDelegateEventAware()) { try { @@ -490,4 +494,44 @@ public boolean isDelegateNull() { public boolean isDelegateNOP() { return _delegate instanceof NOPLogger; } + + @Override + public void log(Marker marker, String fqcn, int level, String message, Object[] argArray, Throwable t) { + Logger delegate = delegate(); + if (delegate instanceof LocationAwareLogger) { + ((LocationAwareLogger) delegate).log(marker, fqcn, level, message, argArray, t); + } else { + // Unless the delegate implements `LoggingEventAware` the caller boundary information will be lost, + // but this spares us the trouble of calling the class API. + LoggingEventBuilder builder = + delegate.atLevel(Level.intToLevel(level)).addMarker(marker).setCause(t); + if (builder instanceof CallerBoundaryAware) { + ((CallerBoundaryAware) builder).setCallerBoundary(fqcn); + } + builder.log(message, argArray); + } + } + + /** + * Creates a {@link LoggingEventBuilder} used within a method of this class. + */ + private LoggingEventBuilder internalEventBuilder(Level level) { + LoggingEventBuilder builder = delegate().makeLoggingEventBuilder(level); + if (builder instanceof CallerBoundaryAware) { + ((CallerBoundaryAware) builder).setCallerBoundary(SELF); + } + return builder; + } + + /** + * Creates a {@link LoggingEventBuilder} used within a method of this class. + */ + private LoggingEventBuilder internalEventBuilder(Marker marker, Level level) { + LoggingEventBuilder builder = delegate().makeLoggingEventBuilder(level).addMarker(marker); + if (builder instanceof CallerBoundaryAware) { + ((CallerBoundaryAware) builder).setCallerBoundary(SELF); + } + return builder; + } + } diff --git a/slf4j-api/src/test/java/org/slf4j/helpers/SubstitutableLoggerTest.java b/slf4j-api/src/test/java/org/slf4j/helpers/SubstituteLoggerTest.java similarity index 54% rename from slf4j-api/src/test/java/org/slf4j/helpers/SubstitutableLoggerTest.java rename to slf4j-api/src/test/java/org/slf4j/helpers/SubstituteLoggerTest.java index f82c4f5db..68ca237ea 100644 --- a/slf4j-api/src/test/java/org/slf4j/helpers/SubstitutableLoggerTest.java +++ b/slf4j-api/src/test/java/org/slf4j/helpers/SubstituteLoggerTest.java @@ -24,6 +24,7 @@ */ package org.slf4j.helpers; +import static org.junit.Assert.assertEquals; import static org.junit.Assert.assertTrue; import static org.junit.Assert.fail; @@ -33,17 +34,27 @@ import java.lang.reflect.Proxy; import java.util.Arrays; import java.util.HashSet; +import java.util.Locale; import java.util.Set; import org.junit.Test; +import org.junit.runner.RunWith; +import org.junit.runners.Parameterized; import org.slf4j.Logger; +import org.slf4j.Marker; import org.slf4j.event.EventRecordingLogger; +import org.slf4j.event.Level; +import org.slf4j.event.LoggingEvent; +import org.slf4j.spi.DefaultLoggingEventBuilder; +import org.slf4j.spi.LocationAwareLogger; +import org.slf4j.spi.LoggingEventAware; /** * @author Chetan Mehrotra * @author Ceki Gülcü */ -public class SubstitutableLoggerTest { +@RunWith(Parameterized.class) +public class SubstituteLoggerTest { // NOTE: previous implementations of this class performed a handcrafted conversion of // a method to a string. In this implementation we just invoke method.toString(). @@ -53,9 +64,22 @@ public class SubstitutableLoggerTest { private static final Set EXCLUDED_METHODS = new HashSet<>( Arrays.asList("getName")); - + + @Parameterized.Parameters(name = "{0}") + public static Object[] parameters() { + return new Object[] { LocationAwareLogger.class, LoggingEventAware.class}; + } + + @Parameterized.Parameter + public Class locationAwareInterface; + + private String currentMethodSignature; + /** - * Test that all SubstituteLogger methods invoke the delegate, except for explicitly excluded methods. + * Test that all SubstituteLogger methods invoke the delegate, except for explicitly excluded methods. + *

+ * If the invoked method generates a log event, the event must have the correct caller boundary. + *

*/ @Test public void delegateIsInvokedTest() throws Exception { @@ -64,7 +88,10 @@ public void delegateIsInvokedTest() throws Exception { Set expectedMethodSignatures = determineMethodSignatures(Logger.class); LoggerInvocationHandler loggerInvocationHandler = new LoggerInvocationHandler(); - Logger proxyLogger = (Logger) Proxy.newProxyInstance(getClass().getClassLoader(), new Class[] { Logger.class }, loggerInvocationHandler); + Logger proxyLogger = (Logger) Proxy.newProxyInstance( + getClass().getClassLoader(), + new Class[] {Logger.class, locationAwareInterface}, + loggerInvocationHandler); substituteLogger.setDelegate(proxyLogger); invokeAllMethodsOf(substituteLogger); @@ -79,6 +106,7 @@ public void delegateIsInvokedTest() throws Exception { private void invokeAllMethodsOf(Logger logger) throws InvocationTargetException, IllegalAccessException { for (Method m : Logger.class.getDeclaredMethods()) { if (!EXCLUDED_METHODS.contains(m.getName())) { + currentMethodSignature = m.toString(); m.invoke(logger, new Object[m.getParameterTypes().length]); } } @@ -101,13 +129,61 @@ private class LoggerInvocationHandler implements InvocationHandler { private final Set invokedMethodSignatures = new HashSet<>(); public Object invoke(Object proxy, Method method, Object[] args) throws Throwable { - invokedMethodSignatures.add(method.toString()); + // Register the method that caused this delegated call. + invokedMethodSignatures.add(currentMethodSignature); + // Handle filtering methods if (method.getName().startsWith("is")) { return true; } + // Handle fluent API methods + if ("makeLoggingEventBuilder".equals(method.getName()) || "atLevel".equals(method.getName())) { + return new DefaultLoggingEventBuilder((Logger) proxy, (Level) args[0]); + } + if (method.getName().startsWith("at")) { + Level level = getLevelFromMethodName(method.getName()); + return new DefaultLoggingEventBuilder((Logger) proxy, level); + } + // Check that only methods with a caller boundary field are called. + if ("log".equals(method.getName())) { + Class[] parameterTypes = method.getParameterTypes(); + // Call of the LoggingEventAware method + if (parameterTypes.length == 1 && LoggingEvent.class.equals(parameterTypes[0])) { + LoggingEvent event = (LoggingEvent) args[0]; + assertEquals( + "Expected caller boundary", SubstituteLogger.class.getName(), event.getCallerBoundary()); + return null; + } + if (parameterTypes.length == 6 + && Arrays.equals(parameterTypes, new Class[] { + Marker.class, String.class, int.class, String.class, Object[].class, Throwable.class + })) { + assertEquals("Expected caller boundary", SubstituteLogger.class.getName(), args[1]); + return null; + } + } + fail("A method without a caller boundary parameter was invoked: " + method); return null; } + private Level getLevelFromMethodName(String methodName) { + String levelString = + (methodName.startsWith("at") ? methodName.substring(2) : methodName).toUpperCase(Locale.ROOT); + switch (levelString) { + case "TRACE": + return Level.TRACE; + case "DEBUG": + return Level.DEBUG; + case "INFO": + return Level.INFO; + case "WARN": + return Level.WARN; + case "ERROR": + return Level.ERROR; + default: + throw new IllegalArgumentException("Unknown level: " + levelString); + } + } + public Set getInvokedMethodSignatures() { return invokedMethodSignatures; }