Skip to content

Commit c05874d

Browse files
jpbempeljpbempel
authored
Add more information for timeout messages (#9999)
* Add more information for timeout messages * Add NonRetryable annotation use @NonRetryable annotation on Exception Replay smoke tests to keep logs intact for troubleshooting
1 parent 0614d73 commit c05874d

13 files changed

+195
-53
lines changed

‎buildSrc/src/main/kotlin/datadog.configure-tests.gradle.kts‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -101,6 +101,9 @@ tasks.withType<Test>().configureEach {
101101
develocity.testRetry {
102102
if (providers.environmentVariable("CI").isPresent()) {
103103
maxRetries = 3
104+
filter {
105+
excludeAnnotationClasses.add("*NonRetryable") // allow to mark classes non retryable
106+
}
104107
}
105108
}
106109
}

‎dd-smoke-tests/debugger-integration-tests/src/test/java/datadog/smoketest/AgentDebuggerIntegrationTest.java‎

Lines changed: 9 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -35,7 +35,9 @@ void testLatestJdk() throws Exception {
3535
snapshot -> {
3636
snapshotReceived.set(true);
3737
});
38-
processRequests(snapshotReceived::get);
38+
processRequests(
39+
snapshotReceived::get,
40+
() -> String.format("timeout snapshotReceived=%s", snapshotReceived.get()));
3941
assertFalse(logHasErrors(logFilePath, it -> false));
4042
}
4143

@@ -53,7 +55,9 @@ void testShutdown() throws Exception {
5355
snapshot -> {
5456
snapshotReceived.set(true);
5557
});
56-
processRequests(snapshotReceived::get);
58+
processRequests(
59+
snapshotReceived::get,
60+
() -> String.format("timeout snapshotReceived=%s", snapshotReceived.get()));
5761
assertFalse(logHasErrors(logFilePath, it -> false));
5862
// Wait for the app exit with some extra time.
5963
// The expectation is that agent doesn't prevent app from exiting.
@@ -78,7 +82,9 @@ void testDestroy() throws Exception {
7882
snapshot -> {
7983
snapshotReceived.set(true);
8084
});
81-
processRequests(snapshotReceived::get);
85+
processRequests(
86+
snapshotReceived::get,
87+
() -> String.format("timeout snapshotReceived=%s", snapshotReceived.get()));
8288
targetProcess.destroy();
8389
// Wait for the app exit with some extra time.
8490
// The expectation is that agent doesn't prevent app from exiting.

‎dd-smoke-tests/debugger-integration-tests/src/test/java/datadog/smoketest/BaseIntegrationTest.java‎

Lines changed: 8 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -46,6 +46,7 @@
4646
import java.util.function.Consumer;
4747
import java.util.function.Function;
4848
import java.util.function.Predicate;
49+
import java.util.function.Supplier;
4950
import okhttp3.Headers;
5051
import okhttp3.HttpUrl;
5152
import okhttp3.mockwebserver.MockResponse;
@@ -118,6 +119,7 @@ static void setupAll() throws Exception {
118119

119120
@BeforeEach
120121
void setup(TestInfo testInfo) throws Exception {
122+
LOG.info("===== Starting {} ====", testInfo.getDisplayName());
121123
datadogAgentServer = new MockWebServer();
122124
probeMockDispatcher = new MockDispatcher();
123125
probeMockDispatcher.setDispatcher(this::datadogAgentDispatch);
@@ -132,13 +134,14 @@ void setup(TestInfo testInfo) throws Exception {
132134
}
133135

134136
@AfterEach
135-
void teardown() throws Exception {
137+
void teardown(TestInfo testInfo) throws Exception {
136138
if (targetProcess != null) {
137139
targetProcess.destroyForcibly();
138140
}
139141
datadogAgentServer.shutdown();
140142
statsDServer.close();
141143
ProbeRateLimiter.resetAll();
144+
LOG.info("===== Ending {} ====", testInfo.getDisplayName());
142145
}
143146

144147
protected ProcessBuilder createProcessBuilder(Path logFilePath, String... params) {
@@ -347,14 +350,15 @@ protected AtomicBoolean registerCheckReceivedInstalledEmitting() {
347350
return result;
348351
}
349352

350-
protected void processRequests(BooleanSupplier conditionOfDone) throws InterruptedException {
353+
protected void processRequests(BooleanSupplier conditionOfDone, Supplier<String> timeoutMessage)
354+
throws InterruptedException {
351355
long start = System.currentTimeMillis();
352356
try {
353357
RecordedRequest request;
354358
do {
355359
request = datadogAgentServer.takeRequest(REQUEST_WAIT_TIMEOUT, TimeUnit.SECONDS);
356360
if (request == null) {
357-
throw new RuntimeException("timeout!");
361+
throw new RuntimeException(timeoutMessage.get());
358362
}
359363
LOG.info("processRequests path={}", request.getPath());
360364
for (RequestType requestType : RequestType.values()) {
@@ -364,7 +368,7 @@ protected void processRequests(BooleanSupplier conditionOfDone) throws Interrupt
364368
}
365369
}
366370
} while (request != null && (System.currentTimeMillis() - start < 30_000));
367-
throw new RuntimeException("timeout!");
371+
throw new RuntimeException(timeoutMessage.get());
368372
} finally {
369373
probeStatusListeners.clear();
370374
}

‎dd-smoke-tests/debugger-integration-tests/src/test/java/datadog/smoketest/CodeOriginIntegrationTest.java‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -51,6 +51,7 @@ void testCodeOriginTraceAnnotation() throws Exception {
5151
}
5252
}
5353
});
54-
processRequests(codeOrigin::get);
54+
processRequests(
55+
codeOrigin::get, () -> String.format("timeout codeOrigin=%s", codeOrigin.get()));
5556
}
5657
}

‎dd-smoke-tests/debugger-integration-tests/src/test/java/datadog/smoketest/ExceptionDebuggerIntegrationTest.java‎

Lines changed: 19 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -10,24 +10,30 @@
1010
import datadog.trace.bootstrap.debugger.CapturedContext;
1111
import datadog.trace.test.agent.decoder.DecodedSpan;
1212
import datadog.trace.test.agent.decoder.DecodedTrace;
13-
import datadog.trace.test.util.Flaky;
13+
import datadog.trace.test.util.NonRetryable;
1414
import java.nio.file.Path;
1515
import java.util.ArrayList;
1616
import java.util.HashMap;
1717
import java.util.List;
1818
import java.util.Map;
19+
import java.util.function.Supplier;
1920
import org.junit.jupiter.api.DisplayName;
2021
import org.junit.jupiter.api.Test;
2122
import org.junit.jupiter.api.condition.DisabledIf;
2223

23-
@Flaky
24+
@NonRetryable
2425
public class ExceptionDebuggerIntegrationTest extends ServerAppDebuggerIntegrationTest {
2526

2627
private List<String> snapshotIdTags = new ArrayList<>();
2728
private boolean traceReceived;
2829
private boolean snapshotReceived;
2930
private Map<String, Snapshot> snapshots = new HashMap<>();
3031
private List<String> additionalJvmArgs = new ArrayList<>();
32+
private Supplier<String> timeoutMessage =
33+
() ->
34+
String.format(
35+
"Timeout! traceReceived=%s snapshotReceived=%s #snapshots=%d",
36+
traceReceived, snapshotReceived, snapshots.size());
3137

3238
@Override
3339
protected ProcessBuilder createProcessBuilder(Path logFilePath, String... params) {
@@ -74,7 +80,8 @@ void testSimpleSingleFrameException() throws Exception {
7480
return true;
7581
}
7682
return false;
77-
});
83+
},
84+
timeoutMessage);
7885
}
7986

8087
@Test
@@ -98,7 +105,7 @@ void testNoSubsequentCaptureAfterFirst() throws Exception {
98105
}
99106
}
100107
});
101-
processRequests(() -> traceReceived && !snapshotReceived);
108+
processRequests(() -> traceReceived && !snapshotReceived, timeoutMessage);
102109
}
103110

104111
// DeepOops exception stacktrace:
@@ -163,7 +170,8 @@ void test3CapturedFrames() throws Exception {
163170
return true;
164171
}
165172
return false;
166-
});
173+
},
174+
timeoutMessage);
167175
}
168176

169177
@Test
@@ -240,7 +248,8 @@ void test5CapturedFrames() throws Exception {
240248
return true;
241249
}
242250
return false;
243-
});
251+
},
252+
timeoutMessage);
244253
}
245254

246255
@Test
@@ -276,7 +285,8 @@ void test3CapturedRecursiveFrames() throws Exception {
276285
return true;
277286
}
278287
return false;
279-
});
288+
},
289+
timeoutMessage);
280290
}
281291

282292
private static void assertRecursiveSnapshot(Snapshot snapshot) {
@@ -321,7 +331,8 @@ void testLambdaHiddenFrames() throws Exception {
321331
return true;
322332
}
323333
return false;
324-
});
334+
},
335+
timeoutMessage);
325336
}
326337

327338
private void resetSnapshotsAndTraces() {

‎dd-smoke-tests/debugger-integration-tests/src/test/java/datadog/smoketest/LogProbesIntegrationTest.java‎

Lines changed: 63 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -52,7 +52,9 @@ void testInaccessibleObject() throws Exception {
5252
snapshot -> {
5353
snapshotReceived.set(true);
5454
});
55-
processRequests(snapshotReceived::get);
55+
processRequests(
56+
snapshotReceived::get,
57+
() -> String.format("timeout snapshotReceived=%s", snapshotReceived.get()));
5658
assertFalse(logHasErrors(logFilePath, it -> false));
5759
}
5860

@@ -92,7 +94,12 @@ void testFullMethod() throws Exception {
9294
snapshotReceived.set(true);
9395
});
9496
AtomicBoolean statusResult = registerCheckReceivedInstalledEmitting();
95-
processRequests(() -> snapshotReceived.get() && statusResult.get());
97+
processRequests(
98+
() -> snapshotReceived.get() && statusResult.get(),
99+
() ->
100+
String.format(
101+
"timeout snapshotReceived=%s statusResult=%s",
102+
snapshotReceived.get(), statusResult.get()));
96103
}
97104

98105
@Test
@@ -119,7 +126,12 @@ void testFullMethodWithCondition() throws Exception {
119126
snapshotReceived.set(true);
120127
});
121128
AtomicBoolean statusResult = registerCheckReceivedInstalledEmitting();
122-
processRequests(() -> snapshotReceived.get() && statusResult.get());
129+
processRequests(
130+
() -> snapshotReceived.get() && statusResult.get(),
131+
() ->
132+
String.format(
133+
"timeout snapshotReceived=%s statusResult=%s",
134+
snapshotReceived.get(), statusResult.get()));
123135
}
124136

125137
@Test
@@ -148,7 +160,12 @@ void testFullMethodWithConditionAtExit() throws Exception {
148160
snapshotReceived.set(true);
149161
});
150162
AtomicBoolean statusResult = registerCheckReceivedInstalledEmitting();
151-
processRequests(() -> snapshotReceived.get() && statusResult.get());
163+
processRequests(
164+
() -> snapshotReceived.get() && statusResult.get(),
165+
() ->
166+
String.format(
167+
"timeout snapshotReceived=%s statusResult=%s",
168+
snapshotReceived.get(), statusResult.get()));
152169
}
153170

154171
@Test
@@ -176,7 +193,12 @@ void testFullMethodWithConditionFailed() throws Exception {
176193
snapshotReceived.set(true);
177194
});
178195
AtomicBoolean statusResult = registerCheckReceivedInstalledEmitting();
179-
processRequests(() -> snapshotReceived.get() && statusResult.get());
196+
processRequests(
197+
() -> snapshotReceived.get() && statusResult.get(),
198+
() ->
199+
String.format(
200+
"timeout snapshotReceived=%s statusResult=%s",
201+
snapshotReceived.get(), statusResult.get()));
180202
}
181203

182204
@Test
@@ -208,7 +230,12 @@ void testFullMethodWithLogTemplate() throws Exception {
208230
snapshotReceived.set(true);
209231
});
210232
AtomicBoolean statusResult = registerCheckReceivedInstalledEmitting();
211-
processRequests(() -> snapshotReceived.get() && correctLogMessage.get() && statusResult.get());
233+
processRequests(
234+
() -> snapshotReceived.get() && correctLogMessage.get() && statusResult.get(),
235+
() ->
236+
String.format(
237+
"timeout snapshotReceived=%s correctLogMessage=%s statusResult=%s",
238+
snapshotReceived.get(), correctLogMessage.get(), statusResult.get()));
212239
}
213240

214241
@Test
@@ -255,7 +282,12 @@ void testFullMethodWithCaptureExpressions() throws Exception {
255282
snapshotReceived.set(true);
256283
});
257284
AtomicBoolean statusResult = registerCheckReceivedInstalledEmitting();
258-
processRequests(() -> snapshotReceived.get() && statusResult.get());
285+
processRequests(
286+
() -> snapshotReceived.get() && statusResult.get(),
287+
() ->
288+
String.format(
289+
"timeout snapshotReceived=%s statusResult=%s",
290+
snapshotReceived.get(), statusResult.get()));
259291
}
260292

261293
@Test
@@ -296,7 +328,12 @@ void testMultiProbes() throws Exception {
296328
&& statuses.values().stream()
297329
.allMatch(status -> status == ProbeStatus.Status.EMITTING));
298330
});
299-
processRequests(() -> allSnapshotReceived.get() && allStatusEmitting.get());
331+
processRequests(
332+
() -> allSnapshotReceived.get() && allStatusEmitting.get(),
333+
() ->
334+
String.format(
335+
"timeout allSnapshotReceived=%s allStatusEmitting=%s",
336+
allSnapshotReceived.get(), allStatusEmitting.get()));
300337
assertEquals(NB_PROBES, probeIds.size());
301338
for (int i = 0; i < NB_PROBES; i++) {
302339
assertTrue(probeIds.contains(String.valueOf(i)));
@@ -328,7 +365,12 @@ void testLineProbe() throws Exception {
328365
snapshotReceived.set(true);
329366
});
330367
AtomicBoolean statusResult = registerCheckReceivedInstalledEmitting();
331-
processRequests(() -> snapshotReceived.get() && statusResult.get());
368+
processRequests(
369+
() -> snapshotReceived.get() && statusResult.get(),
370+
() ->
371+
String.format(
372+
"timeout snapshotReceived=%s statusResult=%s",
373+
snapshotReceived.get(), statusResult.get()));
332374
}
333375

334376
@Test
@@ -386,7 +428,8 @@ private void doSamplingSnapshot(ProbeCondition probeCondition, MethodLocation ev
386428
() -> {
387429
LOG.info("snapshots={}", snapshotCount.get());
388430
return snapshotCount.get() >= 2 && snapshotCount.get() <= 20;
389-
});
431+
},
432+
() -> String.format("timeout snapshotCount=%d", snapshotCount.get()));
390433
}
391434

392435
@Test
@@ -420,7 +463,8 @@ void testSamplingLogDefault() throws Exception {
420463
() -> {
421464
LOG.info("snapshots={}", snapshotCount.get());
422465
return snapshotCount.get() >= 850 && snapshotCount.get() <= 1000;
423-
});
466+
},
467+
() -> String.format("timeout snapshotCount=%d", snapshotCount.get()));
424468
}
425469

426470
@Test
@@ -454,7 +498,8 @@ void testSamplingLogCustom() throws Exception {
454498
() -> {
455499
LOG.info("snapshots={}", snapshotCount.get());
456500
return snapshotCount.get() > 0 && snapshotCount.get() < 200;
457-
});
501+
},
502+
() -> String.format("timeout snapshotCount=%d", snapshotCount.get()));
458503
}
459504

460505
@Test
@@ -485,7 +530,9 @@ void testUncaughtException() throws Exception {
485530
throwable.getStacktrace().get(0).getFunction());
486531
snapshotReceived.set(true);
487532
});
488-
processRequests(snapshotReceived::get);
533+
processRequests(
534+
snapshotReceived::get,
535+
() -> String.format("timeout snapshotReceived=%s", snapshotReceived.get()));
489536
}
490537

491538
@Test
@@ -516,7 +563,9 @@ void testCaughtException() throws Exception {
516563
throwable.getStacktrace().get(0).getFunction());
517564
snapshotReceived.set(true);
518565
});
519-
processRequests(snapshotReceived::get);
566+
processRequests(
567+
snapshotReceived::get,
568+
() -> String.format("timeout snapshotReceived=%s", snapshotReceived.get()));
520569
}
521570

522571
private ProbeId getProbeId(int i) {

0 commit comments

Comments
 (0)