Skip to content

Commit

Permalink
Merge pull request #4342 from DataDog/jpbempel/eval-reporting
Browse files Browse the repository at this point in the history
Add evaluation error reporting for expressions
  • Loading branch information
jpbempel authored Dec 2, 2022
2 parents 262f93c + 99e1cc8 commit 3586edf
Show file tree
Hide file tree
Showing 7 changed files with 206 additions and 28 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -35,9 +35,11 @@ public class Snapshot {
private final String language;
private final transient CapturedThread thread;
private final transient Set<String> capturingProbeIds = new HashSet<>();
private final transient Set<String> errorReportingIds = new HashSet<>();
private final transient String thisClassName;
private String traceId; // trace_id
private String spanId; // span_id
private List<EvaluationError> evaluationErrors;
private final transient SummaryBuilder summaryBuilder;

public Snapshot(java.lang.Thread thread, ProbeDetails probeDetails, String thisClassName) {
Expand Down Expand Up @@ -173,12 +175,16 @@ public String getSpanId() {
return spanId;
}

public List<EvaluationError> getEvaluationErrors() {
return evaluationErrors;
}

public String getSummary() {
return summaryBuilder.build();
}

public void commit() {
if (!isCapturing()) {
if (!isCapturing() && evaluationErrors == null) {
DebuggerContext.skipSnapshot(probe.id, DebuggerContext.SkipCause.CONDITION);
for (ProbeDetails probeDetails : probe.additionalProbes) {
DebuggerContext.skipSnapshot(probeDetails.id, DebuggerContext.SkipCause.CONDITION);
Expand All @@ -202,13 +208,14 @@ public void commit() {
* - Snapshot.commit()
*/
recordStackTrace(3);
if (capturingProbeIds.contains(probe.id)) {
if (capturingProbeIds.contains(probe.id) || errorReportingIds.contains(probe.id)) {
DebuggerContext.addSnapshot(this);
} else {
DebuggerContext.skipSnapshot(probe.id, DebuggerContext.SkipCause.CONDITION);
}
for (ProbeDetails additionalProbe : probe.additionalProbes) {
if (capturingProbeIds.contains(additionalProbe.id)) {
if (capturingProbeIds.contains(additionalProbe.id)
|| errorReportingIds.contains(additionalProbe.id)) {
DebuggerContext.addSnapshot(copy(additionalProbe.id, UUID.randomUUID().toString()));
} else {
DebuggerContext.skipSnapshot(additionalProbe.id, DebuggerContext.SkipCause.CONDITION);
Expand Down Expand Up @@ -243,11 +250,22 @@ private boolean checkCapture(CapturedContext capture) {
if (!executeScript(script, capture, probe.id)) {
capturingProbeIds.remove(probe.id);
}
if (capture.areEvalErrors()) {
errorReportingIds.add(probe.id);
if (capture.evaluationErrors != null) {
if (evaluationErrors == null) {
evaluationErrors = new ArrayList<>();
}
evaluationErrors.addAll(capture.evaluationErrors);
}
}
List<ProbeDetails> additionalProbes = probe.additionalProbes;
if (!additionalProbes.isEmpty()) {
for (ProbeDetails additionalProbe : additionalProbes) {
if (executeScript(additionalProbe.getScript(), capture, additionalProbe.id)) {
capturingProbeIds.add(additionalProbe.id);
} else if (capture.areEvalErrors()) {
errorReportingIds.add(additionalProbe.id);
}
}
}
Expand Down Expand Up @@ -568,6 +586,7 @@ public static class CapturedContext implements ValueReferenceResolver {
private Map<String, CapturedValue> fields;
private Limits limits = Limits.DEFAULT;
private String thisClassName;
private List<EvaluationError> evaluationErrors;

public CapturedContext() {}

Expand Down Expand Up @@ -604,18 +623,28 @@ public Object resolve(String path) {
Object target = Values.UNDEFINED_OBJECT;
if (prefix.equals(ValueReferences.FIELD_PREFIX)) {
target = tryRetrieveField(head);
checkUndefined(path, target, head, "Cannot find field: ");
} else if (prefix.equals(ValueReferences.SYNTHETIC_PREFIX)) {
target = tryRetrieveSynthetic(head);
checkUndefined(path, target, head, "Cannot find synthetic var: ");
} else if (prefix.equals(ValueReferences.LOCALVAR_PREFIX)) {
target = tryRetrieveLocalVar(head);
checkUndefined(path, target, head, "Cannot find local var: ");
} else if (prefix.equals(ValueReferences.ARGUMENT_PREFIX)) {
target = tryRetrieveArgument(head);
checkUndefined(path, target, head, "Cannot find argument: ");
}
target = followReferences(target, parts);
target = followReferences(path, target, parts);

return target instanceof CapturedValue ? ((CapturedValue) target).getValue() : target;
}

private void checkUndefined(String path, Object target, String name, String msg) {
if (target == Values.UNDEFINED_OBJECT) {
addEvalError(path, msg + name);
}
}

private Object tryRetrieveField(String name) {
if (fields == null) {
return Values.UNDEFINED_OBJECT;
Expand Down Expand Up @@ -651,7 +680,7 @@ private Object tryRetrieveArgument(String name) {
* @param parts the reference path
* @return the resolved value or {@linkplain Values#UNDEFINED_OBJECT}
*/
private Object followReferences(Object src, String[] parts) {
private Object followReferences(String path, Object src, String[] parts) {
if (src == Values.UNDEFINED_OBJECT) {
return src;
}
Expand All @@ -677,8 +706,13 @@ private Object followReferences(Object src, String[] parts) {
}
}
} else {
target = ReflectiveFieldValueResolver.resolve(target, target.getClass(), parts[i]);
if (target != null) {
target = ReflectiveFieldValueResolver.resolve(target, target.getClass(), parts[i]);
} else {
target = Values.UNDEFINED_OBJECT;
}
}
checkUndefined(path, target, parts[i], "Cannot dereference to field: ");
}
return target;
}
Expand Down Expand Up @@ -747,6 +781,20 @@ public void addFields(CapturedValue[] values) {
}
}

public void addEvalError(String expr, String message) {
if (evaluationErrors == null) {
evaluationErrors = new ArrayList<>();
}
evaluationErrors.add(new EvaluationError(expr, message));
}

boolean areEvalErrors() {
if (evaluationErrors != null) {
return !evaluationErrors.isEmpty();
}
return false;
}

public void setLimits(
int maxReferenceDepth, int maxCollectionSize, int maxLength, int maxFieldCount) {
this.limits = new Limits(maxReferenceDepth, maxCollectionSize, maxLength, maxFieldCount);
Expand Down Expand Up @@ -1139,4 +1187,25 @@ public String toString() {
+ '}';
}
}

/**
* Store evaluation errors from expressions (probe conditions, log template, metric values, ...)
*/
public static class EvaluationError {
private final String expr;
private final String message;

public EvaluationError(String expr, String message) {
this.expr = expr;
this.message = message;
}

public String getExpr() {
return expr;
}

public String getMessage() {
return message;
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -18,7 +18,7 @@
public class SnapshotSummaryTest {
private static final String CLASS_NAME = "com.datadog.debugger.SomeClass";
private static final ProbeLocation PROBE_LOCATION =
new ProbeLocation(CLASS_NAME, "someMethod", null, null);;
new ProbeLocation(CLASS_NAME, "someMethod", null, null);

@BeforeAll
public static void staticSetup() {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -818,11 +818,11 @@ public void simpleConditionTest() throws IOException, URISyntaxException {
DSL.eq(DSL.ref(".fld"), DSL.value(11)),
// this reference chain needs to use reflection
DSL.eq(DSL.ref(".typed.fld.fld.msg"), DSL.value("hello"))),
DSL.or(
DSL.and(
DSL.eq(DSL.ref(ValueReferences.argument("arg")), DSL.value("5")),
DSL.gt(
DSL.ref(ValueReferences.DURATION_REF), DSL.value(500_000L))))),
"(.fld == 11 && .typed.fld.fld.msg == 'hello') && (#arg == '5' || @duration > 500000)"))
DSL.gt(DSL.ref(ValueReferences.DURATION_REF), DSL.value(0L))))),
"(.fld == 11 && .typed.fld.fld.msg == 'hello') && (#arg == '5' && @duration > 0)"))
.evaluateAt(ProbeDefinition.MethodLocation.EXIT)
.build();
DebuggerTransformerTest.TestSnapshotListener listener =
installProbes(CLASS_NAME, snapshotProbe);
Expand All @@ -832,10 +832,30 @@ public void simpleConditionTest() throws IOException, URISyntaxException {
Assert.assertTrue((i == 2 && result == 2) || result == 3);
}
Assert.assertEquals(1, listener.snapshots.size());
Snapshot.CapturedValue argument =
listener.snapshots.get(0).getCaptures().getEntry().getArguments().get("arg");
Assert.assertEquals("5", getValue(argument));
Assert.assertEquals("java.lang.String", argument.getType());
assertCaptureArgs(
listener.snapshots.get(0).getCaptures().getReturn(), "arg", "java.lang.String", "5");
}

@Test
public void nullCondition() throws IOException, URISyntaxException {
final String CLASS_NAME = "CapturedSnapshot08";
SnapshotProbe snapshotProbe =
createProbeBuilder(PROBE_ID, CLASS_NAME, "doit", "int (java.lang.String)")
.when(
new ProbeCondition(
DSL.when(DSL.eq(DSL.ref(".nullTyped.fld.fld.msg"), DSL.value("hello"))),
".nullTyped.fld.fld.msg == 'hello'"))
.build();
DebuggerTransformerTest.TestSnapshotListener listener =
installProbes(CLASS_NAME, snapshotProbe);
Class<?> testClass = compileAndLoadClass(CLASS_NAME);
int result = Reflect.on(testClass).call("main", "1").get();
Assert.assertEquals(1, listener.snapshots.size());
List<Snapshot.EvaluationError> evaluationErrors =
listener.snapshots.get(0).getEvaluationErrors();
Assert.assertEquals(1, evaluationErrors.size());
Assert.assertEquals(".nullTyped.fld.fld.msg", evaluationErrors.get(0).getExpr());
Assert.assertEquals("Cannot dereference to field: fld", evaluationErrors.get(0).getMessage());
}

@Test
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -152,7 +152,28 @@ public void lineTemplateInvalidVarLog() throws IOException, URISyntaxException {
Assert.assertEquals(3, result);
Snapshot snapshot = assertOneSnapshot(listener);
assertEquals("this is log line with local var=UNDEFINED", snapshot.getSummary());
// TODO assert on eval errors from snapshot
assertEquals(1, snapshot.getEvaluationErrors().size());
assertEquals("#var42", snapshot.getEvaluationErrors().get(0).getExpr());
assertEquals(
"Cannot find local var: var42", snapshot.getEvaluationErrors().get(0).getMessage());
}

@Test
public void lineTemplateNullFieldLog() throws IOException, URISyntaxException {
final String CLASS_NAME = "CapturedSnapshot04";
DebuggerTransformerTest.TestSnapshotListener listener =
installSingleProbe(
"this is log line with field={#nullObject.intValue}", CLASS_NAME, null, null, "25");
Class<?> testClass = compileAndLoadClass(CLASS_NAME);
int result = Reflect.on(testClass).call("main", "").get();
Assert.assertEquals(143, result);
Snapshot snapshot = assertOneSnapshot(listener);
assertEquals("this is log line with field=UNDEFINED", snapshot.getSummary());
assertEquals(1, snapshot.getEvaluationErrors().size());
assertEquals("#nullObject.intValue", snapshot.getEvaluationErrors().get(0).getExpr());
assertEquals(
"Cannot dereference to field: intValue",
snapshot.getEvaluationErrors().get(0).getMessage());
}

private DebuggerTransformerTest.TestSnapshotListener installSingleProbe(
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -40,11 +40,6 @@ public class DebuggerSinkTest {
private static final String PROBE_ID = "12fd-8490-c111-4374-ffde";
private static final Snapshot.ProbeLocation PROBE_LOCATION =
new Snapshot.ProbeLocation("java.lang.String", "indexOf", null, null);
private static final Snapshot SNAPSHOT =
new Snapshot(
Thread.currentThread(),
new Snapshot.ProbeDetails(PROBE_ID, PROBE_LOCATION),
String.class.getTypeName());
public static final int MAX_PAYLOAD = 5 * 1024 * 1024;

@Mock private Config config;
Expand All @@ -71,7 +66,12 @@ void setUp() {
@Test
public void addSnapshot() throws URISyntaxException, IOException {
DebuggerSink sink = new DebuggerSink(config, batchUploader);
sink.addSnapshot(SNAPSHOT);
Snapshot snapshot =
new Snapshot(
Thread.currentThread(),
new Snapshot.ProbeDetails(PROBE_ID, PROBE_LOCATION),
String.class.getTypeName());
sink.addSnapshot(snapshot);
String fixtureContent = getFixtureContent(SINK_FIXTURE_PREFIX + "/snapshotRegex.txt");
String regex = fixtureContent.replaceAll("\\n", "");
sink.flush(sink);
Expand All @@ -84,7 +84,12 @@ public void addSnapshot() throws URISyntaxException, IOException {
public void addMultipleSnapshots() throws URISyntaxException, IOException {
when(config.getDebuggerUploadBatchSize()).thenReturn(2);
DebuggerSink sink = new DebuggerSink(config, batchUploader);
Arrays.asList(SNAPSHOT, SNAPSHOT).forEach(sink::addSnapshot);
Snapshot snapshot =
new Snapshot(
Thread.currentThread(),
new Snapshot.ProbeDetails(PROBE_ID, PROBE_LOCATION),
String.class.getTypeName());
Arrays.asList(snapshot, snapshot).forEach(sink::addSnapshot);

String fixtureContent = getFixtureContent(SINK_FIXTURE_PREFIX + "/multipleSnapshotRegex.txt");
String regex = fixtureContent.replaceAll("\\n", "");
Expand Down Expand Up @@ -242,7 +247,12 @@ public void addNoDiagnostic() {
public void reconsiderFlushIntervalIncreaseFlushInterval() {
DebuggerSink sink = new DebuggerSink(config, batchUploader);
long currentFlushInterval = sink.getCurrentFlushInterval();
sink.addSnapshot(SNAPSHOT);
Snapshot snapshot =
new Snapshot(
Thread.currentThread(),
new Snapshot.ProbeDetails(PROBE_ID, PROBE_LOCATION),
String.class.getTypeName());
sink.addSnapshot(snapshot);
sink.doReconsiderFlushInterval();
long newFlushInterval = sink.getCurrentFlushInterval();
assertEquals(currentFlushInterval + DebuggerSink.STEP_SIZE, newFlushInterval);
Expand All @@ -253,8 +263,13 @@ public void reconsiderFlushIntervalDecreaseFlushInterval() {
DebuggerSink sink = new DebuggerSink(config, batchUploader);
long currentFlushInterval = sink.getCurrentFlushInterval();
sink.flush(sink);
Snapshot snapshot =
new Snapshot(
Thread.currentThread(),
new Snapshot.ProbeDetails(PROBE_ID, PROBE_LOCATION),
String.class.getTypeName());
for (int i = 0; i < 1000; i++) {
sink.addSnapshot(SNAPSHOT);
sink.addSnapshot(snapshot);
}
sink.doReconsiderFlushInterval();
long newFlushInterval = sink.getCurrentFlushInterval();
Expand All @@ -265,8 +280,13 @@ public void reconsiderFlushIntervalDecreaseFlushInterval() {
public void reconsiderFlushIntervalNoChange() {
DebuggerSink sink = new DebuggerSink(config, batchUploader);
long currentFlushInterval = sink.getCurrentFlushInterval();
Snapshot snapshot =
new Snapshot(
Thread.currentThread(),
new Snapshot.ProbeDetails(PROBE_ID, PROBE_LOCATION),
String.class.getTypeName());
for (int i = 0; i < 500; i++) {
sink.addSnapshot(SNAPSHOT);
sink.addSnapshot(snapshot);
}
sink.doReconsiderFlushInterval();
long newFlushInterval = sink.getCurrentFlushInterval();
Expand All @@ -282,8 +302,13 @@ public void addSnapshotWithCorrelationIds() throws URISyntaxException, IOExcepti
Snapshot.CapturedValue.of("dd.trace_id", "java.lang.String", "123"),
Snapshot.CapturedValue.of("dd.span_id", "java.lang.String", "456"),
});
SNAPSHOT.setEntry(entry);
sink.addSnapshot(SNAPSHOT);
Snapshot snapshot =
new Snapshot(
Thread.currentThread(),
new Snapshot.ProbeDetails(PROBE_ID, PROBE_LOCATION),
String.class.getTypeName());
snapshot.setEntry(entry);
sink.addSnapshot(snapshot);
String fixtureContent =
getFixtureContent(SINK_FIXTURE_PREFIX + "/snapshotWithCorrelationIdsRegex.txt");
String regex = fixtureContent.replaceAll("\\n", "");
Expand All @@ -293,6 +318,27 @@ public void addSnapshotWithCorrelationIds() throws URISyntaxException, IOExcepti
assertTrue(strPayload.matches(regex), strPayload);
}

@Test
public void addSnapshotWithEvalErrors() throws URISyntaxException, IOException {
DebuggerSink sink = new DebuggerSink(config, batchUploader);
Snapshot.CapturedContext entry = new Snapshot.CapturedContext();
entry.addEvalError("obj.field", "Cannot dereference obj");
Snapshot snapshot =
new Snapshot(
Thread.currentThread(),
new Snapshot.ProbeDetails(PROBE_ID, PROBE_LOCATION),
String.class.getTypeName());
snapshot.setEntry(entry);
sink.addSnapshot(snapshot);
String fixtureContent =
getFixtureContent(SINK_FIXTURE_PREFIX + "/snapshotWithEvalErrorRegex.txt");
String regex = fixtureContent.replaceAll("\\n", "");
sink.flush(sink);
verify(batchUploader).upload(payloadCaptor.capture(), matches(EXPECTED_SNAPSHOT_TAGS));
String strPayload = new String(payloadCaptor.getValue(), StandardCharsets.UTF_8);
assertTrue(strPayload.matches(regex), strPayload);
}

@Test
public void addDiagnostic() {
DebuggerSink sink = new DebuggerSink(config, batchUploader);
Expand Down
Loading

0 comments on commit 3586edf

Please sign in to comment.