This is an automated email from the ASF dual-hosted git repository. clebertsuconic pushed a commit to branch new-logging in repository https://gitbox.apache.org/repos/asf/activemq-artemis.git
commit dd3dea40981c45bde94079e08743ba8dc6de76dd Author: Clebert Suconic <[email protected]> AuthorDate: Wed Jul 20 17:22:25 2022 -0400 log processing improvement with exceptions --- artemis-log-processor/pom.xml | 6 ++ .../artemis/logprocessor/LogProcessor.java | 57 ++++++++++++++--- .../activemq/artemis/logprocessor/MyException.java | 3 + .../artemis/logprocessor/SimpleBundle.java | 18 ++++++ .../artemis/logprocessor/SimpleBundleTest.java | 71 ++++++++++++++++++++++ .../artemis/logs/AssertionLoggerHandler.java | 22 +++++++ 6 files changed, 167 insertions(+), 10 deletions(-) diff --git a/artemis-log-processor/pom.xml b/artemis-log-processor/pom.xml index 6abe8ab169..50b87d265a 100644 --- a/artemis-log-processor/pom.xml +++ b/artemis-log-processor/pom.xml @@ -38,6 +38,12 @@ <artifactId>artemis-log-facade</artifactId> <version>${project.version}</version> </dependency> + <dependency> + <groupId>org.apache.activemq</groupId> + <artifactId>artemis-unit-test-support</artifactId> + <version>${project.version}</version> + <scope>test</scope> + </dependency> <dependency> <groupId>org.slf4j</groupId> <artifactId>slf4j-api</artifactId> diff --git a/artemis-log-processor/src/main/java/org/apache/activemq/artemis/logprocessor/LogProcessor.java b/artemis-log-processor/src/main/java/org/apache/activemq/artemis/logprocessor/LogProcessor.java index d88d690eaa..2d7c7f706a 100644 --- a/artemis-log-processor/src/main/java/org/apache/activemq/artemis/logprocessor/LogProcessor.java +++ b/artemis-log-processor/src/main/java/org/apache/activemq/artemis/logprocessor/LogProcessor.java @@ -32,14 +32,17 @@ import javax.lang.model.type.TypeMirror; import javax.tools.Diagnostic; import javax.tools.JavaFileObject; import java.io.PrintWriter; +import java.util.ArrayList; import java.util.HashMap; import java.util.Iterator; +import java.util.List; import java.util.Set; import org.apache.activemq.artemis.logprocessor.annotation.LogBundle; import org.apache.activemq.artemis.logprocessor.annotation.GetLogger; import org.apache.activemq.artemis.logprocessor.annotation.LogMessage; import org.apache.activemq.artemis.logprocessor.annotation.Message; +import org.slf4j.helpers.MessageFormatter; @SupportedAnnotationTypes({"org.apache.activemq.artemis.logprocessor.annotation.LogBundle"}) @SupportedSourceVersion(SourceVersion.RELEASE_11) @@ -351,27 +354,57 @@ public class LogProcessor extends AbstractProcessor { writerOutput.println(" @Override"); writerOutput.write(" public void " + executableMember.getSimpleName() + "("); - Iterator<? extends VariableElement> parameters = executableMember.getParameters().iterator(); + List<? extends VariableElement> parametersList = executableMember.getParameters(); boolean hasParameters = false; - // the one that will be used on the call - StringBuffer callList = new StringBuffer(); + VariableElement exceptionParameter = null; + ArrayList<VariableElement> nonExceptionParameters = new ArrayList<>(); + + Iterator<? extends VariableElement> parameters = parametersList.iterator(); while (parameters.hasNext()) { hasParameters = true; VariableElement parameter = parameters.next(); writerOutput.write(parameter.asType() + " " + parameter.getSimpleName()); - callList.append(parameter.getSimpleName()); if (parameters.hasNext()) { writerOutput.write(", "); - callList.append(","); + } + + boolean isException = isException(parameter.asType(), parameter); + + if (isException) { + if (exceptionParameter != null) { + throw new IllegalArgumentException("You can only have one exception defined per log message, check:: " + executableMember); + } + exceptionParameter = parameter; + } + + if (DEBUG) { + debug("Parameter " + parameter + (isException? "is" : "is not") + " an exception"); + } + + if (!isException) { + nonExceptionParameters.add(parameter); } } - // the real implementation writerOutput.println(")"); writerOutput.println(" {"); + // the one that will be used on the call + StringBuffer callList = new StringBuffer(); + parameters = nonExceptionParameters.iterator(); + + while (parameters.hasNext()) { + hasParameters = true; + VariableElement parameter = parameters.next(); + callList.append(parameter.getSimpleName()); + if (parameters.hasNext()) { + callList.append(","); + } + } + + String methodName; switch (messageAnnotation.level()) { @@ -389,12 +422,16 @@ public class LogProcessor extends AbstractProcessor { throw new IllegalStateException("illegal method level " + messageAnnotation.level()); } - //TODO: handle causes being passed in the args to be logged, but not necessarily (often not) being last arg at present as SLF4J/frameworks expect. String formattingString = encodeSpecialChars(bundleAnnotation.projectCode() + messageAnnotation.id() + ": " + messageAnnotation.value()); - if (!hasParameters) { - writerOutput.println(" logger." + methodName + "(\"" + formattingString + "\");"); + if (exceptionParameter != null) { + writerOutput.println(" FormattingTuple output = org.slf4j.helpers.MessageFormatter.arrayFormat(\"" + formattingString + "\",new Object[] {" + callList + "});"); + writerOutput.println(" logger." + methodName + "(output.getMessage(), " + exceptionParameter.getSimpleName() +");"); } else { - writerOutput.println(" logger." + methodName + "(\"" + formattingString + "\", " + callList + ");"); + if (!hasParameters) { + writerOutput.println(" logger." + methodName + "(\"" + formattingString + "\");"); + } else { + writerOutput.println(" logger." + methodName + "(\"" + formattingString + "\", " + callList + ");"); + } } writerOutput.println(" }"); writerOutput.println(); diff --git a/artemis-log-processor/src/test/java/org/apache/activemq/artemis/logprocessor/MyException.java b/artemis-log-processor/src/test/java/org/apache/activemq/artemis/logprocessor/MyException.java index d9551c3d85..1c99e60d01 100644 --- a/artemis-log-processor/src/test/java/org/apache/activemq/artemis/logprocessor/MyException.java +++ b/artemis-log-processor/src/test/java/org/apache/activemq/artemis/logprocessor/MyException.java @@ -27,5 +27,8 @@ public class MyException extends Exception { super(error, cause); } + public String toString() { + return getMessage(); + } } diff --git a/artemis-log-processor/src/test/java/org/apache/activemq/artemis/logprocessor/SimpleBundle.java b/artemis-log-processor/src/test/java/org/apache/activemq/artemis/logprocessor/SimpleBundle.java index 5826103cad..5780e13abd 100644 --- a/artemis-log-processor/src/test/java/org/apache/activemq/artemis/logprocessor/SimpleBundle.java +++ b/artemis-log-processor/src/test/java/org/apache/activemq/artemis/logprocessor/SimpleBundle.java @@ -17,6 +17,8 @@ package org.apache.activemq.artemis.logprocessor; +import java.io.IOException; + import org.apache.activemq.artemis.logprocessor.annotation.GetLogger; import org.apache.activemq.artemis.logprocessor.annotation.LogBundle; import org.apache.activemq.artemis.logprocessor.annotation.LogMessage; @@ -58,6 +60,22 @@ public interface SimpleBundle { @Message(id = 10, value = "{} {} {} {}") String objectsAbcd(MyObject a, MyObject b, MyObject c, MyObject d); + @LogMessage(id = 11, value = "This message has the following parameter:: {}", level = LogMessage.Level.WARN) + void parameterException(String parameter, IOException e); + + @LogMessage(id = 12, value = "This message has the following parameter:: {}", level = LogMessage.Level.WARN) + void myExceptionLogger(String parameter, MyException e); + + @LogMessage(id = 13, value = "This message has the following parameter:: p{}", level = LogMessage.Level.WARN) + void outOfOrder(MyException e, String parameter); + + @LogMessage(id = 14, value = "OutOfOrder with 4 parameters p{} p{} p{}", level = LogMessage.Level.WARN) + void outOfOrder(MyException p1, String p2, String p3, String p4); + + @LogMessage(id = 15, value = "Long with 5 parameters p{} p{} p{} p{} p{}", level = LogMessage.Level.WARN) + void longParameters(String p1, String p2, String p3, String p4, String p5); + + @GetLogger Logger getLogger(); } diff --git a/artemis-log-processor/src/test/java/org/apache/activemq/artemis/logprocessor/SimpleBundleTest.java b/artemis-log-processor/src/test/java/org/apache/activemq/artemis/logprocessor/SimpleBundleTest.java index 424538da4c..8cc3cc5ddb 100644 --- a/artemis-log-processor/src/test/java/org/apache/activemq/artemis/logprocessor/SimpleBundleTest.java +++ b/artemis-log-processor/src/test/java/org/apache/activemq/artemis/logprocessor/SimpleBundleTest.java @@ -17,10 +17,12 @@ package org.apache.activemq.artemis.logprocessor; +import java.io.IOException; import java.util.UUID; import org.junit.Assert; import org.junit.Test; +import org.apache.activemq.artemis.logs.AssertionLoggerHandler; public class SimpleBundleTest { @@ -83,6 +85,75 @@ public class SimpleBundleTest { } + @Test + public void exceptions() { + SimpleBundle.MESSAGES.parameterException("hello", new IOException("this is an exception")); + SimpleBundle.MESSAGES.myExceptionLogger("hello2", new MyException("this is an exception")); + } + + @Test + public void outOfOrderException() { + AssertionLoggerHandler.startCapture(false, true); + try { + SimpleBundle.MESSAGES.outOfOrder(createMyException("NotHere"), "2"); + Assert.assertTrue("parameter2 was not on the output", AssertionLoggerHandler.findText("p2")); + Assert.assertFalse(AssertionLoggerHandler.findText("pNotHere")); + Assert.assertTrue("Stack trace was not printed", AssertionLoggerHandler.findText("createMyException")); + Assert.assertFalse("logging not working", AssertionLoggerHandler.findText("{}")); + } finally { + AssertionLoggerHandler.stopCapture(); + } + } + + @Test + public void outOfOrderExceptionLongParameter() { + try { + AssertionLoggerHandler.startCapture(false, false); + SimpleBundle.MESSAGES.outOfOrder(new MyException("ex1"), "2", "3", "4"); + Assert.assertFalse("parameter not found", AssertionLoggerHandler.findText("pex1")); + Assert.assertTrue("parameter not found", AssertionLoggerHandler.findText("p2")); + Assert.assertTrue("parameter not found", AssertionLoggerHandler.findText("p3")); + Assert.assertTrue("parameter not found", AssertionLoggerHandler.findText("p4")); + Assert.assertFalse("formatting not working", AssertionLoggerHandler.findText("{}")); + + AssertionLoggerHandler.clear(); + AssertionLoggerHandler.startCapture(false, true); + + SimpleBundle.MESSAGES.outOfOrder(createMyException("ex1"), "2", "3", "4"); + Assert.assertFalse("parameter not found", AssertionLoggerHandler.findText("pex1")); + Assert.assertTrue("parameter not found", AssertionLoggerHandler.findText("p3")); + Assert.assertTrue("parameter not found", AssertionLoggerHandler.findText("p4")); + Assert.assertTrue("stack not found", AssertionLoggerHandler.findText("createMyException")); + Assert.assertFalse("formatting not working", AssertionLoggerHandler.findText("{}")); + + } finally { + AssertionLoggerHandler.stopCapture(); + } + } + + @Test + public void longList() { + AssertionLoggerHandler.startCapture(false, true); + try { + SimpleBundle.MESSAGES.longParameters("1", "2", "3", "4", "5"); + Assert.assertTrue("parameter not found", AssertionLoggerHandler.findText("p1")); + Assert.assertTrue("parameter not found", AssertionLoggerHandler.findText("p2")); + Assert.assertTrue("parameter not found", AssertionLoggerHandler.findText("p3")); + Assert.assertTrue("parameter not found", AssertionLoggerHandler.findText("p4")); + Assert.assertTrue("parameter not found", AssertionLoggerHandler.findText("p5")); + Assert.assertFalse("{}", AssertionLoggerHandler.findText("{}")); + } finally { + AssertionLoggerHandler.stopCapture(); + } + } + + + // I'm doing it on a method just to assert if this method will appear on the stack trace + private MyException createMyException(String message) { + return new MyException(message); + } + + @Test public void testGetLogger() { Assert.assertNotNull(SimpleBundle.MESSAGES.getLogger()); diff --git a/artemis-unit-test-support/src/main/java/org/apache/activemq/artemis/logs/AssertionLoggerHandler.java b/artemis-unit-test-support/src/main/java/org/apache/activemq/artemis/logs/AssertionLoggerHandler.java index 269745e4d5..224f016e6a 100644 --- a/artemis-unit-test-support/src/main/java/org/apache/activemq/artemis/logs/AssertionLoggerHandler.java +++ b/artemis-unit-test-support/src/main/java/org/apache/activemq/artemis/logs/AssertionLoggerHandler.java @@ -16,7 +16,9 @@ */ package org.apache.activemq.artemis.logs; +import java.io.PrintWriter; import java.io.Serializable; +import java.io.StringWriter; import java.util.LinkedList; import java.util.List; import java.util.Map; @@ -45,6 +47,8 @@ public class AssertionLoggerHandler extends AbstractAppender { private static final Map<String, LogEvent> messages = new ConcurrentHashMap<>(); private static List<String> traceMessages; private static volatile boolean capture = false; + private static volatile boolean captureStackTrace = false; + public static class Builder<B extends Builder<B>> extends AbstractAppender.Builder<B> implements org.apache.logging.log4j.core.util.Builder<AssertionLoggerHandler> { @Override @@ -67,7 +71,15 @@ public class AssertionLoggerHandler extends AbstractAppender { if (capture) { //TODO: see getFormattedMessage() around handling StringBuilderFormattable interface as well, check it out String formattedMessage = event.getMessage().getFormattedMessage(); + + if (captureStackTrace && event.getThrown() != null) { + StringWriter stackOutput = new StringWriter(); + event.getThrown().printStackTrace(new PrintWriter(stackOutput)); + formattedMessage += stackOutput.toString(); + } + messages.put(formattedMessage, event); + if (traceMessages != null) { traceMessages.add(formattedMessage); } @@ -207,15 +219,25 @@ public class AssertionLoggerHandler extends AbstractAppender { * @param individualMessages enables counting individual messages. */ public static final void startCapture(boolean individualMessages) { + startCapture(individualMessages, captureStackTrace); + } + + /** + * + * @param individualMessages enables counting individual messages. + */ + public static final void startCapture(boolean individualMessages, boolean captureStackTrace) { clear(); if (individualMessages) { traceMessages = new LinkedList<>(); } capture = true; + AssertionLoggerHandler.captureStackTrace = captureStackTrace; } public static final void stopCapture() { capture = false; + captureStackTrace = false; clear(); traceMessages = null; }
