Skip to content

Commit 26ef439

Browse files
jpbempeljpbempel
authored
Fix flaky test with timeout (#11926)
Fix flaky test with timeout Log template evaluation is now limited by a timeout. For tests this timeout maybe too short in some situation. Refactor StringTemplateBuilder timeout to store the default value in probes so we can build probe with a custom timeout for tests. Add custom eval timeout for LogPRobeInstrumentationTest Co-authored-by: jean-philippe.bempel <jean-philippe.bempel@datadoghq.com>
1 parent f2121a0 commit 26ef439

6 files changed

Lines changed: 94 additions & 33 deletions

File tree

‎dd-java-agent/agent-debugger/src/main/java/com/datadog/debugger/agent/StringTemplateBuilder.java‎

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -29,10 +29,12 @@ public class StringTemplateBuilder {
2929
private final List<LogProbe.Segment> segments;
3030

3131
private final Limits limits;
32+
private final Duration timeout;
3233

33-
public StringTemplateBuilder(List<LogProbe.Segment> segments, Limits limits) {
34+
public StringTemplateBuilder(List<LogProbe.Segment> segments, Limits limits, Duration timeout) {
3435
this.segments = segments;
3536
this.limits = limits;
37+
this.timeout = timeout;
3638
}
3739

3840
public String evaluate(CapturedContext context, LogProbe.LogStatus status) {
@@ -41,7 +43,6 @@ public String evaluate(CapturedContext context, LogProbe.LogStatus status) {
4143
}
4244
StringBuilder sb = new StringBuilder();
4345
// Only one timeout for all expressions
44-
Duration timeout = Duration.ofMillis(Config.get().getDynamicInstrumentationEvalTimeout());
4546
TimeoutChecker timeoutChecker = TimeoutChecker.create(Config.get(), timeout);
4647
for (LogProbe.Segment segment : segments) {
4748
ValueScript parsedExr = segment.getParsedExpr();

‎dd-java-agent/agent-debugger/src/main/java/com/datadog/debugger/probe/ExceptionProbe.java‎

Lines changed: 4 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -12,12 +12,14 @@
1212
import com.datadog.debugger.instrumentation.InstrumentationResult;
1313
import com.datadog.debugger.instrumentation.MethodInfo;
1414
import com.datadog.debugger.sink.Snapshot;
15+
import datadog.trace.api.Config;
1516
import datadog.trace.bootstrap.debugger.CapturedContext;
1617
import datadog.trace.bootstrap.debugger.MethodLocation;
1718
import datadog.trace.bootstrap.debugger.ProbeId;
1819
import datadog.trace.bootstrap.debugger.ProbeImplementation;
1920
import datadog.trace.bootstrap.debugger.ProbeLocation;
2021
import datadog.trace.bootstrap.debugger.el.ValueReferences;
22+
import java.time.Duration;
2123
import java.util.List;
2224
import org.slf4j.Logger;
2325
import org.slf4j.LoggerFactory;
@@ -47,7 +49,8 @@ public ExceptionProbe(
4749
new ProbeCondition(DSL.when(DSL.TRUE), "true"),
4850
capture,
4951
sampling,
50-
null);
52+
null,
53+
Duration.ofMillis(Config.get().getDynamicInstrumentationEvalTimeout()));
5154
this.exceptionProbeManager = exceptionProbeManager;
5255
this.chainedExceptionIdx = chainedExceptionIdx;
5356
initSamplers();

‎dd-java-agent/agent-debugger/src/main/java/com/datadog/debugger/probe/LogProbe.java‎

Lines changed: 23 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -325,6 +325,7 @@ public String toString() {
325325
Collections.synchronizedMap(new WeakIdentityHashMap<>());
326326
protected transient Sampler sampler;
327327
protected transient Sampler errorSampler;
328+
protected final transient Duration evalTimeout;
328329

329330
// no-arg constructor is required by Moshi to avoid creating instance with unsafe and by-passing
330331
// constructors, including field initializers.
@@ -341,7 +342,8 @@ public LogProbe() {
341342
null,
342343
null,
343344
null,
344-
null);
345+
null,
346+
Duration.ofMillis(Config.get().getDynamicInstrumentationEvalTimeout()));
345347
}
346348

347349
public LogProbe(
@@ -356,7 +358,8 @@ public LogProbe(
356358
ProbeCondition probeCondition,
357359
Capture capture,
358360
Sampling sampling,
359-
List<CaptureExpression> captureExpressions) {
361+
List<CaptureExpression> captureExpressions,
362+
Duration evalTimeout) {
360363
this(
361364
language,
362365
probeId,
@@ -369,7 +372,8 @@ public LogProbe(
369372
probeCondition,
370373
capture,
371374
sampling,
372-
captureExpressions);
375+
captureExpressions,
376+
evalTimeout);
373377
}
374378

375379
private LogProbe(
@@ -384,7 +388,8 @@ private LogProbe(
384388
ProbeCondition probeCondition,
385389
Capture capture,
386390
Sampling sampling,
387-
List<CaptureExpression> captureExpressions) {
391+
List<CaptureExpression> captureExpressions,
392+
Duration evalTimeout) {
388393
super(language, probeId, tags, where, evaluateAt);
389394
this.template = template;
390395
this.segments = segments;
@@ -393,6 +398,7 @@ private LogProbe(
393398
this.capture = capture;
394399
this.sampling = sampling;
395400
this.captureExpressions = captureExpressions;
401+
this.evalTimeout = evalTimeout;
396402
}
397403

398404
public LogProbe(LogProbe.Builder builder) {
@@ -408,7 +414,8 @@ public LogProbe(LogProbe.Builder builder) {
408414
builder.probeCondition,
409415
builder.capture,
410416
builder.sampling,
411-
builder.captureExpressions);
417+
builder.captureExpressions,
418+
builder.evalTimeout);
412419
this.snapshotProcessor = builder.snapshotProcessor;
413420
initSamplers();
414421
}
@@ -426,7 +433,8 @@ public LogProbe copy() {
426433
probeCondition,
427434
capture,
428435
sampling,
429-
captureExpressions);
436+
captureExpressions,
437+
evalTimeout);
430438
}
431439

432440
public String getTemplate() {
@@ -547,7 +555,8 @@ private void processMsgTemplate(CapturedContext context, LogStatus logStatus) {
547555
if (!logStatus.isSampled() || !logStatus.getCondition()) {
548556
return;
549557
}
550-
StringTemplateBuilder logMessageBuilder = new StringTemplateBuilder(segments, LIMITS);
558+
StringTemplateBuilder logMessageBuilder =
559+
new StringTemplateBuilder(segments, LIMITS, evalTimeout);
551560
String msg = logMessageBuilder.evaluate(context, logStatus);
552561
if (msg != null && msg.length() > LOG_MSG_LIMIT) {
553562
StringBuilder sb = new StringBuilder(LOG_MSG_LIMIT + 3);
@@ -1123,6 +1132,8 @@ public static class Builder extends ProbeDefinition.Builder<Builder> {
11231132
private Sampling sampling;
11241133
private List<CaptureExpression> captureExpressions;
11251134
private Consumer<Snapshot> snapshotProcessor;
1135+
private Duration evalTimeout =
1136+
Duration.ofMillis(Config.get().getDynamicInstrumentationEvalTimeout());
11261137

11271138
public Builder snapshotProcessor(Consumer<Snapshot> processor) {
11281139
this.snapshotProcessor = processor;
@@ -1169,6 +1180,11 @@ public Builder captureExpressions(List<CaptureExpression> captureExpressions) {
11691180
return this;
11701181
}
11711182

1183+
public Builder evalTimeout(Duration evalTimeout) {
1184+
this.evalTimeout = evalTimeout;
1185+
return this;
1186+
}
1187+
11721188
public LogProbe build() {
11731189
return new LogProbe(this);
11741190
}

‎dd-java-agent/agent-debugger/src/main/java/com/datadog/debugger/probe/SpanDecorationProbe.java‎

Lines changed: 25 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -162,11 +162,20 @@ public int hashCode() {
162162
private final TargetSpan targetSpan;
163163
private final List<Decoration> decorations;
164164
private transient Sampler errorSampler;
165+
private final transient Duration evalTimeout;
165166

166167
// no-arg constructor is required by Moshi to avoid creating instance with unsafe and by-passing
167168
// constructors, including field initializers.
168169
public SpanDecorationProbe() {
169-
this(LANGUAGE, null, null, null, MethodLocation.DEFAULT, TargetSpan.ACTIVE, null);
170+
this(
171+
LANGUAGE,
172+
null,
173+
null,
174+
null,
175+
MethodLocation.DEFAULT,
176+
TargetSpan.ACTIVE,
177+
null,
178+
Duration.ofMillis(Config.get().getDynamicInstrumentationEvalTimeout()));
170179
}
171180

172181
public SpanDecorationProbe(
@@ -176,10 +185,12 @@ public SpanDecorationProbe(
176185
Where where,
177186
MethodLocation methodLocation,
178187
TargetSpan targetSpan,
179-
List<Decoration> decorations) {
188+
List<Decoration> decorations,
189+
Duration evalTimeout) {
180190
super(language, probeId, tagStrs, where, methodLocation);
181191
this.targetSpan = targetSpan;
182192
this.decorations = decorations;
193+
this.evalTimeout = evalTimeout;
183194
}
184195

185196
public SpanDecorationProbe(SpanDecorationProbe.Builder builder) {
@@ -190,7 +201,8 @@ public SpanDecorationProbe(SpanDecorationProbe.Builder builder) {
190201
builder.where,
191202
builder.evaluateAt,
192203
builder.targetSpan,
193-
builder.decorations);
204+
builder.decorations,
205+
builder.evalTimeout);
194206
initSamplers();
195207
}
196208

@@ -210,8 +222,7 @@ public void evaluate(
210222
MethodLocation methodLocation,
211223
boolean singleProbe) {
212224
// Only one timeout for all conditions
213-
Duration timeout = Duration.ofMillis(Config.get().getDynamicInstrumentationEvalTimeout());
214-
TimeoutChecker timeoutChecker = TimeoutChecker.create(Config.get(), timeout);
225+
TimeoutChecker timeoutChecker = TimeoutChecker.create(Config.get(), evalTimeout);
215226
for (Decoration decoration : decorations) {
216227
if (decoration.when != null) {
217228
try {
@@ -234,7 +245,8 @@ public void evaluate(
234245
SpanDecorationStatus spanStatus = (SpanDecorationStatus) status;
235246
for (Tag tag : decoration.tags) {
236247
String tagName = sanitize(tag.name);
237-
StringTemplateBuilder builder = new StringTemplateBuilder(tag.value.getSegments(), LIMITS);
248+
StringTemplateBuilder builder =
249+
new StringTemplateBuilder(tag.value.getSegments(), LIMITS, evalTimeout);
238250
LogProbe.LogStatus logStatus = new LogProbe.LogStatus(this);
239251
String tagValue = builder.evaluate(context, logStatus);
240252
if (logStatus.hasLogTemplateErrors()) {
@@ -418,6 +430,8 @@ public static SpanDecorationProbe.Builder builder() {
418430
public static class Builder extends ProbeDefinition.Builder<SpanDecorationProbe.Builder> {
419431
private TargetSpan targetSpan;
420432
private List<Decoration> decorations;
433+
private Duration evalTimeout =
434+
Duration.ofMillis(Config.get().getDynamicInstrumentationEvalTimeout());
421435

422436
public Builder targetSpan(TargetSpan targetSpan) {
423437
this.targetSpan = targetSpan;
@@ -434,6 +448,11 @@ public Builder decorations(Decoration decoration) {
434448
return this;
435449
}
436450

451+
public Builder evalTimeout(Duration evalTimeout) {
452+
this.evalTimeout = evalTimeout;
453+
return this;
454+
}
455+
437456
public SpanDecorationProbe build() {
438457
return new SpanDecorationProbe(this);
439458
}

‎dd-java-agent/agent-debugger/src/test/java/com/datadog/debugger/agent/LogProbesInstrumentationTest.java‎

Lines changed: 7 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -28,6 +28,7 @@
2828
import java.lang.instrument.ClassFileTransformer;
2929
import java.lang.instrument.Instrumentation;
3030
import java.net.URISyntaxException;
31+
import java.time.Duration;
3132
import java.util.Collection;
3233
import java.util.List;
3334
import net.bytebuddy.agent.ByteBuddyAgent;
@@ -550,12 +551,16 @@ private static LogProbe.Builder createProbeBuilder(
550551

551552
private static LogProbe createMethodProbe(
552553
ProbeId id, String template, String typeName, String methodName, String signature) {
553-
return createProbeBuilder(id, template, typeName, methodName, signature).build();
554+
return createProbeBuilder(id, template, typeName, methodName, signature)
555+
.evalTimeout(Duration.ofMillis(1000))
556+
.build();
554557
}
555558

556559
private static LogProbe createLineProbe(
557560
ProbeId id, String template, String sourceFile, int line) {
558-
return createProbeBuilder(id, template, sourceFile, line).build();
561+
return createProbeBuilder(id, template, sourceFile, line)
562+
.evalTimeout(Duration.ofMillis(1000))
563+
.build();
559564
}
560565

561566
private TestSnapshotListener installProbes(Configuration configuration) {

0 commit comments

Comments
 (0)