From ad363bec60821f43f0397c67570ad4c5c92f681d Mon Sep 17 00:00:00 2001
From: Ashley Scopes <73482956+ascopes@users.noreply.github.com>
Date: Tue, 27 Sep 2022 08:35:08 +0100
Subject: [PATCH 1/2] Improve diagnostics in LoggingFileManagerProxy
---
.../jct/jsr199/LoggingFileManagerProxy.java | 115 +++++++++++++++---
1 file changed, 98 insertions(+), 17 deletions(-)
diff --git a/java-compiler-testing/src/main/java/io/github/ascopes/jct/jsr199/LoggingFileManagerProxy.java b/java-compiler-testing/src/main/java/io/github/ascopes/jct/jsr199/LoggingFileManagerProxy.java
index 310c9afcd..a659e0e2e 100644
--- a/java-compiler-testing/src/main/java/io/github/ascopes/jct/jsr199/LoggingFileManagerProxy.java
+++ b/java-compiler-testing/src/main/java/io/github/ascopes/jct/jsr199/LoggingFileManagerProxy.java
@@ -17,8 +17,8 @@
import io.github.ascopes.jct.utils.ToStringBuilder;
import java.lang.reflect.InvocationHandler;
-import java.lang.reflect.InvocationTargetException;
import java.lang.reflect.Method;
+import java.lang.reflect.Parameter;
import java.lang.reflect.Proxy;
import java.util.Arrays;
import java.util.Objects;
@@ -34,7 +34,9 @@
* JavaFileManager, along with a corresponding stacktrace.
*
* This is useful for diagnosing difficult-to-find errors being produced by {@code javac}
- * during testing.
+ * during testing, however, it may produce a hefty performance overhead when in use.
+ *
+ *
All logs are emitted with the {@code INFO} logging level.
*
* @author Ashley Scopes
* @since 0.0.1
@@ -46,10 +48,12 @@ public class LoggingFileManagerProxy implements InvocationHandler {
private final FileManager inner;
private final boolean stackTraces;
+ private final ThreadLocal stackDepth;
private LoggingFileManagerProxy(FileManager inner, boolean stackTraces) {
this.inner = inner;
this.stackTraces = stackTraces;
+ stackDepth = ThreadLocal.withInitial(() -> 0);
}
/**
@@ -67,35 +71,101 @@ public Object invoke(Object proxy, Method method, Object[] args) throws Throwabl
return toString();
}
- String extraInfo = "";
- if (stackTraces) {
- extraInfo = "\n" + Arrays.stream(Thread.currentThread().getStackTrace())
- .map(frame -> "\tat " + frame)
- .collect(Collectors.joining("\n"));
- }
-
+ var thread = Thread.currentThread();
+ var threadId = thread.getId();
+ var depth = incStackDepth();
+ var returnType = method.getReturnType().getSimpleName();
+ var methodName = method.getName();
+ var paramStr = Arrays
+ .stream(method.getParameters())
+ .map(Parameter::getType)
+ .map(Class::getSimpleName)
+ .collect(Collectors.joining(", "));
var argsStr = args == null ? "" : Arrays
.stream(args)
.map(Objects::toString)
.collect(Collectors.joining(", "));
- LOGGER.info(">>> {}({}){} is invoked", method.getName(), argsStr, extraInfo);
+ String extraInfo;
+
+ if (stackTraces) {
+ // skip top 2 frames to discard the call to
+ // .getStackTrace(), and this proxy method call.
+ extraInfo = "\n" + Arrays
+ .stream(thread.getStackTrace())
+ .skip(2)
+ .map(frame -> "\tat " + frame)
+ .collect(Collectors.joining("\n"));
+ } else {
+ extraInfo = "";
+ }
+
+ LOGGER.info(
+ ">>> [thread={}, depth={}] {} {}({}) called with ({}){}",
+ threadId,
+ depth,
+ returnType,
+ methodName,
+ paramStr,
+ argsStr,
+ extraInfo
+ );
try {
var result = method.invoke(inner, args);
+
if (method.getReturnType().equals(void.class)) {
- LOGGER.info("<<< {}({}) completes", method.getName(), argsStr);
+ LOGGER.info(
+ "<<< [thread={}, depth={}] {}({}) returned,
+ threadId,
+ depth,
+ returnType,
+ methodName,
+ paramStr
+ );
+
} else {
- LOGGER.info("<<< {}({}) returns {}", method.getName(), argsStr, result);
+ LOGGER.info(
+ "<<< [thread={}, depth={}] {} {}({}) returned {}",
+ threadId,
+ depth,
+ returnType,
+ methodName,
+ paramStr,
+ result
+ );
}
+
return result;
- } catch (InvocationTargetException ex) {
- var cause = ex.getCause() == null
- ? ex
- : ex.getCause();
- LOGGER.error("!!! {}({}) throws exception", method.getName(), argsStr, cause);
+ } catch (ReflectiveOperationException ex) {
+ // We always want the cause to get the real exception.
+ // If, however, for any reason it is not present, then
+ // it probably means something else went wrong, so report
+ // it directly.
+ Throwable cause;
+
+ if (ex.getCause() == null) {
+ cause = ex;
+ } else {
+ cause = ex.getCause();
+ cause.addSuppressed(ex);
+ }
+
+ LOGGER.error(
+ "!!! [thread={}, depth={}] {} {}({}) threw exception",
+ threadId,
+ depth,
+ returnType,
+ methodName,
+ paramStr,
+ cause
+ );
+
throw cause;
+
+ } finally {
+ decStackDepth();
}
}
@@ -122,4 +192,15 @@ public static FileManager wrap(FileManager manager, boolean stackTraces) {
new LoggingFileManagerProxy(manager, stackTraces)
);
}
+
+ private int incStackDepth() {
+ var depth = stackDepth.get() + 1;
+ stackDepth.set(depth);
+ return depth;
+ }
+
+ private void decStackDepth() {
+ var depth = stackDepth.get() - 1;
+ stackDepth.set(depth);
+ }
}
From ca0fa1aed1c519af6e9101134f93cc25f62f2696 Mon Sep 17 00:00:00 2001
From: Ashley Scopes <73482956+ascopes@users.noreply.github.com>
Date: Tue, 27 Sep 2022 08:36:49 +0100
Subject: [PATCH 2/2] Add missing token
---
.../io/github/ascopes/jct/jsr199/LoggingFileManagerProxy.java | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/java-compiler-testing/src/main/java/io/github/ascopes/jct/jsr199/LoggingFileManagerProxy.java b/java-compiler-testing/src/main/java/io/github/ascopes/jct/jsr199/LoggingFileManagerProxy.java
index a659e0e2e..3fe7b8e76 100644
--- a/java-compiler-testing/src/main/java/io/github/ascopes/jct/jsr199/LoggingFileManagerProxy.java
+++ b/java-compiler-testing/src/main/java/io/github/ascopes/jct/jsr199/LoggingFileManagerProxy.java
@@ -116,7 +116,7 @@ public Object invoke(Object proxy, Method method, Object[] args) throws Throwabl
if (method.getReturnType().equals(void.class)) {
LOGGER.info(
- "<<< [thread={}, depth={}] {}({}) returned,
+ "<<< [thread={}, depth={}] {}({}) returned",
threadId,
depth,
returnType,