Skip to content

Commit 15dc542

Browse files
amarzialiamarziali
authored
Include advice class name in instrumentation exception handler log (#11457)
Include advice class name in instrumentation exception handler log Apply suggestions from code review Co-authored-by: mhlidd <matthew.li@datadoghq.com> suggestions - simplify bytecode Merge branch 'master' into andrea.marziali/logger++ Co-authored-by: andrea.marziali <andrea.marziali@datadoghq.com>
1 parent 20950de commit 15dc542

3 files changed

Lines changed: 156 additions & 131 deletions

File tree

‎dd-java-agent/agent-installer/src/main/java/datadog/trace/agent/tooling/CombiningTransformerBuilder.java‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -274,7 +274,7 @@ private void addAdviceIfEnabled(
274274
}
275275
AgentBuilder.Transformer.ForAdvice forAdvice =
276276
new AgentBuilder.Transformer.ForAdvice(customMapping)
277-
.withExceptionHandler(ExceptionHandlers.defaultExceptionHandler())
277+
.withExceptionHandler(ExceptionHandlers.exceptionHandlerFor(adviceClass))
278278
.include(Utils.getBootstrapProxy());
279279
ClassLoader adviceLoader = Utils.getExtendedClassLoader();
280280
if (adviceShader != null) {

‎dd-java-agent/agent-tooling/src/main/java/datadog/trace/agent/tooling/bytebuddy/ExceptionHandlers.java‎

Lines changed: 151 additions & 126 deletions
Original file line numberDiff line numberDiff line change
@@ -7,6 +7,7 @@
77
import net.bytebuddy.asm.Advice.ExceptionHandler;
88
import net.bytebuddy.implementation.Implementation;
99
import net.bytebuddy.implementation.bytecode.StackManipulation;
10+
import net.bytebuddy.implementation.bytecode.constant.TextConstant;
1011
import net.bytebuddy.jar.asm.Label;
1112
import net.bytebuddy.jar.asm.MethodVisitor;
1213
import net.bytebuddy.jar.asm.Opcodes;
@@ -20,131 +21,155 @@ public class ExceptionHandlers {
2021
// Bootstrap ExceptionHandler.class will always be resolvable, so we'll use it in the log name
2122
private static final String HANDLER_NAME = ExceptionLogger.class.getName().replace('.', '/');
2223

23-
private static final ExceptionHandler EXCEPTION_STACK_HANDLER =
24-
new ExceptionHandler.Simple(
25-
new StackManipulation() {
26-
// Pops one Throwable off the stack. Maxes the stack to at least 3.
27-
private final Size size = new StackManipulation.Size(-1, 3);
28-
private final boolean appSecEnabled =
29-
InstrumenterConfig.get().getAppSecActivation() != ProductActivation.FULLY_DISABLED;
30-
private final boolean detailedErrors =
31-
InstrumenterConfig.get().isDetailedInstrumentationErrors();
32-
33-
@Override
34-
public boolean isValid() {
35-
return true;
36-
}
37-
38-
@Override
39-
public Size apply(final MethodVisitor mv, final Implementation.Context context) {
40-
final String name = context.getInstrumentedType().getName();
41-
final boolean exitOnFailure = InstrumenterConfig.get().isInternalExitOnFailure();
42-
final String logMethod = exitOnFailure ? "error" : "debug";
43-
44-
// Writes the following bytecode if exitOnFailure is false:
45-
//
46-
// BlockingExceptionHandler.rethrowIfBlockingException(t);
47-
// try {
48-
// InstrumentationErrors.recordError();
49-
// org.slf4j.LoggerFactory.getLogger((Class)ExceptionLogger.class)
50-
// .debug("Failed to handle exception in instrumentation for ...", t);
51-
// } catch (Throwable t2) {
52-
// }
53-
//
54-
// And the following bytecode if exitOnFailure is true:
55-
//
56-
// BlockingExceptionHandler.rethrowIfBlockingException(t);
57-
// try {
58-
// InstrumentationErrors.recordError();
59-
// org.slf4j.LoggerFactory.getLogger((Class)ExceptionLogger.class)
60-
// .error("Failed to handle exception in instrumentation for ...", t);
61-
// System.exit(1);
62-
// } catch (Throwable t2) {
63-
// }
64-
//
65-
final Label logStart = new Label();
66-
final Label logEnd = new Label();
67-
final Label eatException = new Label();
68-
final Label handlerExit = new Label();
69-
70-
// Frames are only meaningful for class files in version 6 or later.
71-
final boolean frames =
72-
context.getClassFileVersion().isAtLeast(ClassFileVersion.JAVA_V6);
73-
74-
if (appSecEnabled) {
75-
// rethrow blocking exceptions
76-
// stack: (top) throwable
77-
mv.visitMethodInsn(
78-
Opcodes.INVOKESTATIC,
79-
"datadog/trace/bootstrap/blocking/BlockingExceptionHandler",
80-
"rethrowIfBlockingException",
81-
"(Ljava/lang/Throwable;)Ljava/lang/Throwable;",
82-
false);
83-
}
84-
85-
mv.visitTryCatchBlock(logStart, logEnd, eatException, "java/lang/Throwable");
86-
mv.visitLabel(logStart);
87-
// record instrumentation error
88-
if (detailedErrors) {
89-
mv.visitMethodInsn(
90-
Opcodes.INVOKESTATIC,
91-
"datadog/trace/bootstrap/InstrumentationErrors",
92-
"recordError",
93-
"(Ljava/lang/Throwable;)Ljava/lang/Throwable;",
94-
false);
95-
} else {
96-
mv.visitMethodInsn(
97-
Opcodes.INVOKESTATIC,
98-
"datadog/trace/bootstrap/InstrumentationErrors",
99-
"recordError",
100-
"()V",
101-
false);
102-
}
103-
// stack: (top) throwable
104-
mv.visitLdcInsn(Type.getType("L" + HANDLER_NAME + ";"));
105-
mv.visitMethodInsn(
106-
Opcodes.INVOKESTATIC,
107-
LOG_FACTORY_NAME,
108-
"getLogger",
109-
"(Ljava/lang/Class;)L" + LOGGER_NAME + ";",
110-
false);
111-
mv.visitInsn(Opcodes.SWAP); // stack: (top) throwable,logger
112-
mv.visitLdcInsn("Failed to handle exception in instrumentation for " + name);
113-
mv.visitInsn(Opcodes.SWAP); // stack: (top) throwable,string,logger
114-
mv.visitMethodInsn(
115-
Opcodes.INVOKEINTERFACE,
116-
LOGGER_NAME,
117-
logMethod,
118-
"(Ljava/lang/String;Ljava/lang/Throwable;)V",
119-
true);
120-
121-
if (exitOnFailure) {
122-
mv.visitInsn(Opcodes.ICONST_1);
123-
mv.visitMethodInsn(Opcodes.INVOKESTATIC, "java/lang/System", "exit", "(I)V", false);
124-
}
125-
mv.visitLabel(logEnd);
126-
mv.visitJumpInsn(Opcodes.GOTO, handlerExit);
127-
128-
// if the runtime can't reach our ExceptionHandler or logger,
129-
// silently eat the exception
130-
mv.visitLabel(eatException);
131-
if (frames) {
132-
mv.visitFrame(Opcodes.F_SAME1, 0, null, 1, new Object[] {"java/lang/Throwable"});
133-
}
134-
mv.visitInsn(Opcodes.POP);
135-
// mv.visitMethodInsn(Opcodes.INVOKEVIRTUAL, "java/lang/Throwable",
136-
// "printStackTrace", "()V", false);
137-
138-
mv.visitLabel(handlerExit);
139-
if (frames) {
140-
mv.visitFrame(Opcodes.F_SAME, 0, null, 0, null);
141-
}
142-
143-
return size;
144-
}
145-
});
146-
147-
public static ExceptionHandler defaultExceptionHandler() {
148-
return EXCEPTION_STACK_HANDLER;
24+
// Shared bytecode that turns the [throwable, adviceName] stack left by the TextConstant
25+
// prefix into a logged + optionally swallowed exception.
26+
private static final StackManipulation EXCEPTION_STACK_MANIPULATION =
27+
new StackManipulation() {
28+
// Pops the throwable and the advice-name String off the stack.
29+
// Peak growth above the pair on entry is +2 (during message-building LDCs).
30+
private final Size size = new StackManipulation.Size(-2, 2);
31+
private final boolean appSecEnabled =
32+
InstrumenterConfig.get().getAppSecActivation() != ProductActivation.FULLY_DISABLED;
33+
private final boolean detailedErrors =
34+
InstrumenterConfig.get().isDetailedInstrumentationErrors();
35+
36+
@Override
37+
public boolean isValid() {
38+
return true;
39+
}
40+
41+
@Override
42+
public Size apply(final MethodVisitor mv, final Implementation.Context context) {
43+
final String instrumentedTypeName = context.getInstrumentedType().getName();
44+
final boolean exitOnFailure = InstrumenterConfig.get().isInternalExitOnFailure();
45+
final String logMethod = exitOnFailure ? "error" : "debug";
46+
47+
// On entry the stack is: (bottom) throwable, adviceName (top)
48+
// — adviceName was pushed by the preceding TextConstant.
49+
//
50+
// Emits the following Java-equivalent code when exitOnFailure is false:
51+
//
52+
// BlockingExceptionHandler.rethrowIfBlockingException(t);
53+
// try {
54+
// InstrumentationErrors.recordError();
55+
// org.slf4j.LoggerFactory.getLogger((Class) ExceptionLogger.class)
56+
// .debug("Failed to handle exception in instrumentation for <type> (" + adviceName +
57+
// ")", t);
58+
// } catch (Throwable t2) {
59+
// }
60+
//
61+
// and the same with .error(...) followed by System.exit(1) when exitOnFailure is true.
62+
final Label logStart = new Label();
63+
final Label logEnd = new Label();
64+
final Label eatException = new Label();
65+
final Label handlerExit = new Label();
66+
67+
// Frames are only meaningful for class files in version 6 or later.
68+
final boolean frames = context.getClassFileVersion().isAtLeast(ClassFileVersion.JAVA_V6);
69+
70+
if (appSecEnabled) {
71+
// Need throwable on top for rethrowIfBlockingException.
72+
// stack: (top) adviceName, throwable -> top throwable
73+
mv.visitInsn(Opcodes.SWAP);
74+
mv.visitMethodInsn(
75+
Opcodes.INVOKESTATIC,
76+
"datadog/trace/bootstrap/blocking/BlockingExceptionHandler",
77+
"rethrowIfBlockingException",
78+
"(Ljava/lang/Throwable;)Ljava/lang/Throwable;",
79+
false);
80+
// restore: (top) throwable, adviceName -> top adviceName
81+
mv.visitInsn(Opcodes.SWAP);
82+
}
83+
84+
mv.visitTryCatchBlock(logStart, logEnd, eatException, "java/lang/Throwable");
85+
mv.visitLabel(logStart);
86+
// record instrumentation error
87+
if (detailedErrors) {
88+
// recordError(Throwable) needs throwable on top, then we restore.
89+
mv.visitInsn(Opcodes.SWAP);
90+
mv.visitMethodInsn(
91+
Opcodes.INVOKESTATIC,
92+
"datadog/trace/bootstrap/InstrumentationErrors",
93+
"recordError",
94+
"(Ljava/lang/Throwable;)Ljava/lang/Throwable;",
95+
false);
96+
mv.visitInsn(Opcodes.SWAP);
97+
} else {
98+
mv.visitMethodInsn(
99+
Opcodes.INVOKESTATIC,
100+
"datadog/trace/bootstrap/InstrumentationErrors",
101+
"recordError",
102+
"()V",
103+
false);
104+
}
105+
106+
// Build the log message:
107+
// "Failed to handle exception in instrumentation for <type> - " + adviceName
108+
// <type> is a generation-time constant baked into the prefix LDC.
109+
// stack: (top) adviceName, throwable
110+
mv.visitLdcInsn(
111+
"Failed to handle exception in instrumentation for " + instrumentedTypeName + " - ");
112+
// stack: prefix (top), adviceName, throwable
113+
mv.visitInsn(Opcodes.SWAP);
114+
// stack: adviceName (top), prefix, throwable
115+
mv.visitMethodInsn(
116+
Opcodes.INVOKEVIRTUAL,
117+
"java/lang/String",
118+
"concat",
119+
"(Ljava/lang/String;)Ljava/lang/String;",
120+
false);
121+
// stack: message (top), throwable
122+
mv.visitInsn(Opcodes.SWAP);
123+
// stack: throwable(top), message
124+
125+
mv.visitLdcInsn(Type.getType("L" + HANDLER_NAME + ";"));
126+
mv.visitMethodInsn(
127+
Opcodes.INVOKESTATIC,
128+
LOG_FACTORY_NAME,
129+
"getLogger",
130+
"(Ljava/lang/Class;)L" + LOGGER_NAME + ";",
131+
false);
132+
// stack: logger (top), throwable, message
133+
mv.visitInsn(Opcodes.DUP_X2);
134+
// stack: logger (top), throwable, message, logger
135+
mv.visitInsn(Opcodes.POP);
136+
// stack: throwable (top), message, logger
137+
mv.visitMethodInsn(
138+
Opcodes.INVOKEINTERFACE,
139+
LOGGER_NAME,
140+
logMethod,
141+
"(Ljava/lang/String;Ljava/lang/Throwable;)V",
142+
true);
143+
144+
if (exitOnFailure) {
145+
mv.visitInsn(Opcodes.ICONST_1);
146+
mv.visitMethodInsn(Opcodes.INVOKESTATIC, "java/lang/System", "exit", "(I)V", false);
147+
}
148+
mv.visitLabel(logEnd);
149+
mv.visitJumpInsn(Opcodes.GOTO, handlerExit);
150+
151+
// if the runtime can't reach our ExceptionHandler or logger,
152+
// silently eat the exception
153+
mv.visitLabel(eatException);
154+
if (frames) {
155+
mv.visitFrame(Opcodes.F_SAME1, 0, null, 1, new Object[] {"java/lang/Throwable"});
156+
}
157+
mv.visitInsn(Opcodes.POP);
158+
// mv.visitMethodInsn(Opcodes.INVOKEVIRTUAL, "java/lang/Throwable",
159+
// "printStackTrace", "()V", false);
160+
161+
mv.visitLabel(handlerExit);
162+
if (frames) {
163+
mv.visitFrame(Opcodes.F_SAME, 0, null, 0, null);
164+
}
165+
166+
return size;
167+
}
168+
};
169+
170+
public static ExceptionHandler exceptionHandlerFor(final String adviceClassName) {
171+
return new ExceptionHandler.Simple(
172+
new StackManipulation.Compound(
173+
new TextConstant(adviceClassName), EXCEPTION_STACK_MANIPULATION));
149174
}
150175
}

‎dd-java-agent/agent-tooling/src/test/groovy/datadog/trace/agent/test/BaseExceptionHandlerTest.groovy‎

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -51,21 +51,21 @@ abstract class BaseExceptionHandlerTest extends DDSpecification {
5151
.transform(
5252
new AgentBuilder.Transformer.ForAdvice()
5353
.with(new AgentBuilder.LocationStrategy.Simple(ClassFileLocator.ForClassLoader.of(BadAdvice.getClassLoader())))
54-
.withExceptionHandler(ExceptionHandlers.defaultExceptionHandler())
54+
.withExceptionHandler(ExceptionHandlers.exceptionHandlerFor(BadAdvice.getName()))
5555
.advice(
5656
isMethod().and(named("isInstrumented")),
5757
BadAdvice.getName()))
5858
.transform(
5959
new AgentBuilder.Transformer.ForAdvice()
6060
.with(new AgentBuilder.LocationStrategy.Simple(ClassFileLocator.ForClassLoader.of(BadAdvice.getClassLoader())))
61-
.withExceptionHandler(ExceptionHandlers.defaultExceptionHandler())
61+
.withExceptionHandler(ExceptionHandlers.exceptionHandlerFor(BadAdvice.NoOpAdvice.getName()))
6262
.advice(
6363
isMethod().and(namedOneOf("smallStack", "largeStack")),
6464
BadAdvice.NoOpAdvice.getName()))
6565
.transform(
6666
new AgentBuilder.Transformer.ForAdvice()
6767
.with(new AgentBuilder.LocationStrategy.Simple(ClassFileLocator.ForClassLoader.of(BadAdvice.getClassLoader())))
68-
.withExceptionHandler(ExceptionHandlers.defaultExceptionHandler())
68+
.withExceptionHandler(ExceptionHandlers.exceptionHandlerFor(BlockingExceptionAdvice.getName()))
6969
.advice(
7070
isMethod().and(named("blockingException")),
7171
BlockingExceptionAdvice.getName()))
@@ -117,7 +117,7 @@ abstract class BaseExceptionHandlerTest extends DDSpecification {
117117
// Make sure the log event came from our error handler.
118118
// If the log message changes in the future, it's fine to just
119119
// update the test's hardcoded message
120-
testAppender.list.get(testAppender.list.size() - 1).getMessage().startsWith("Failed to handle exception in instrumentation for")
120+
testAppender.list.get(testAppender.list.size() - 1).getMessage() == "Failed to handle exception in instrumentation for ${SomeClass.getName()} - ${BadAdvice.getName()}"
121121
exitStatus.get() == expectedFailureExitStatus()
122122
}
123123

0 commit comments

Comments
 (0)