You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@activemq.apache.org by cl...@apache.org on 2022/07/21 00:06:30 UTC
[activemq-artemis] 26/26: log processing improvement with exceptions
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 96509b8d4082315794e9544ce6bd51408a2e5aff
Author: Clebert Suconic <cl...@apache.org>
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;
}