Skip to content

Commit 57e6397

Browse files
jbachorikjbachorik
authored
Filter CI test logs for sanitized builds (#393)
1 parent 7ccec70 commit 57e6397

File tree

6 files changed

+226
-16
lines changed

6 files changed

+226
-16
lines changed

‎.github/scripts/filter_gradle_log.py‎

Lines changed: 121 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,121 @@
1+
#!/usr/bin/env python3
2+
"""
3+
Streaming filter for Gradle test output.
4+
5+
Compresses verbose test logs:
6+
- PASSED tests: single summary line; all buffered output (including [TEST::INFO]) discarded
7+
- FAILED tests: full context emitted: STARTED line + buffered stdout/stderr + FAILED line
8+
followed by exception/stack trace that comes after the FAILED marker
9+
- SKIPPED tests: single summary line
10+
- CRASHED tests: if the stream ends mid-test (JVM kill, OOM, sanitizer abort), the full
11+
buffer is emitted with a warning header
12+
13+
Designed for inline use with `tee` so the unfiltered raw log is preserved:
14+
15+
./gradlew ... 2>&1 \\
16+
| tee -a "${RAW_LOG}" \\
17+
| python3 -u .github/scripts/filter_gradle_log.py
18+
19+
Exit code and PIPESTATUS:
20+
The filter always exits 0 regardless of test outcomes; use ${PIPESTATUS[0]} in bash
21+
to capture the Gradle exit code:
22+
23+
./gradlew ... 2>&1 | tee -a raw.log | python3 -u filter_gradle_log.py
24+
GRADLE_EXIT=${PIPESTATUS[0]}
25+
26+
Limitations:
27+
- [TEST::INFO] lines emitted from class-level lifecycle methods (@BeforeAll, static
28+
initializers) appear before any STARTED marker and are suppressed in OUTSIDE state.
29+
They remain visible in the raw log preserved by tee.
30+
"""
31+
32+
import re
33+
import sys
34+
35+
# Matches Gradle per-test event lines emitted by the Test task:
36+
#
37+
# com.example.FooTest > testBar STARTED
38+
# com.example.FooTest > testBar[1] PASSED (0.456s)
39+
# com.example.FooTest > testBar(int) FAILED
40+
# com.example.FooTest > testBar SKIPPED
41+
#
42+
# The class name starts with a word character (not '>'), which prevents matching
43+
# "> Task :project:taskName FAILED" build-level lines.
44+
_TEST_EVENT = re.compile(
45+
r'^([\w.$][\w.$ ]* > \S.*?) (STARTED|PASSED|FAILED|SKIPPED)(\s+\([^)]+\))?\s*$'
46+
)
47+
48+
49+
def emit(line: str) -> None:
50+
print(line, flush=True)
51+
52+
53+
def main() -> None:
54+
# --- States ---
55+
OUTSIDE = 0 # between tests: pass lines through directly
56+
BUFFERING = 1 # inside a running test: accumulate output
57+
FAILING = 2 # after FAILED marker: pass lines through until next test
58+
59+
state = OUTSIDE
60+
buf: list = []
61+
62+
for raw in sys.stdin:
63+
line = raw.rstrip('\n')
64+
m = _TEST_EVENT.match(line)
65+
66+
if m:
67+
event = m.group(2)
68+
69+
if event == 'STARTED':
70+
if state == BUFFERING:
71+
# Previous test had no outcome line (shouldn't normally happen).
72+
# Emit the buffer so we don't silently discard output.
73+
for buffered_line in buf:
74+
emit(buffered_line)
75+
elif state == FAILING:
76+
emit('') # blank line to visually separate failure blocks
77+
78+
# Include the STARTED line in the buffer so it appears in failure output.
79+
buf = [line]
80+
state = BUFFERING
81+
82+
elif event == 'PASSED':
83+
buf = []
84+
emit(line)
85+
state = OUTSIDE
86+
87+
elif event == 'FAILED':
88+
# Emit everything collected since STARTED (includes [TEST::INFO] lines).
89+
for buffered_line in buf:
90+
emit(buffered_line)
91+
buf = []
92+
emit(line)
93+
state = FAILING
94+
95+
elif event == 'SKIPPED':
96+
buf = []
97+
emit(line)
98+
state = OUTSIDE
99+
100+
elif state == BUFFERING:
101+
buf.append(line)
102+
103+
else:
104+
# OUTSIDE or FAILING: pass through directly.
105+
# In FAILING state this captures exception lines, stack traces, etc.
106+
# In OUTSIDE state, suppress [TEST::INFO] lines: they originate from
107+
# class-level init (@BeforeAll, static blocks) and are noise when no
108+
# test has failed; the raw log still contains them for reference.
109+
if state == FAILING or not line.startswith('[TEST::INFO]'):
110+
emit(line)
111+
112+
# EOF handling: if still inside a test the JVM likely crashed (SIGABRT from sanitizer,
113+
# OOM kill, etc.). Emit everything so the failure is visible in the filtered log.
114+
if state == BUFFERING and buf:
115+
emit('# WARNING: stream ended inside a test (crash / OOM / sanitizer abort?)')
116+
for buffered_line in buf:
117+
emit(buffered_line)
118+
119+
120+
if __name__ == '__main__':
121+
main()

‎.github/scripts/prepare_reports.sh‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,11 @@
33
set -e
44
mkdir -p test-reports
55
mkdir -p unwinding-reports
6+
cp build/test-raw.log test-reports/ || true
67
cp /tmp/hs_err* test-reports/ || true
8+
cp /tmp/asan_*.log test-reports/ || true
9+
cp /tmp/ubsan_*.log test-reports/ || true
10+
cp /tmp/tsan_*.log test-reports/ || true
711
cp ddprof-test/javacore*.txt test-reports/ || true
812
cp ddprof-test/build/hs_err* test-reports/ || true
913
cp -r ddprof-lib/build/tmp test-reports/native_build || true

‎.github/workflows/test_workflow.yml‎

Lines changed: 23 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -101,9 +101,12 @@ jobs:
101101
export TEST_CONFIGURATION=glibc/${{ matrix.java_version }}-${{ matrix.config }}-amd64
102102
export LIBC=glibc
103103
export SANITIZER=${{ matrix.config }}
104-
105-
./gradlew -PCI -PkeepJFRs :ddprof-test:test${{ matrix.config }} --no-daemon --parallel --build-cache --no-watch-fs
106-
EXIT_CODE=$?
104+
105+
mkdir -p build/logs
106+
./gradlew -PCI -PkeepJFRs :ddprof-test:test${{ matrix.config }} --no-daemon --parallel --build-cache --no-watch-fs 2>&1 \
107+
| tee -a build/test-raw.log \
108+
| python3 -u .github/scripts/filter_gradle_log.py
109+
EXIT_CODE=${PIPESTATUS[0]}
107110

108111
if [ $EXIT_CODE -ne 0 ]; then
109112
echo "glibc-${{ matrix.java_version }}-${{ matrix.config }}-amd64" >> failures_glibc-${{ matrix.java_version }}-${{ matrix.config }}-amd64.txt
@@ -163,7 +166,7 @@ jobs:
163166
steps:
164167
- name: Setup OS
165168
run: |
166-
apk update && apk add curl moreutils wget hexdump linux-headers bash make g++ clang git cppcheck jq cmake gtest-dev gmock tar binutils >/dev/null
169+
apk update && apk add curl moreutils wget hexdump linux-headers bash make g++ clang git cppcheck jq cmake gtest-dev gmock tar binutils python3 >/dev/null
167170
# Install debug symbols for musl libc
168171
apk add musl-dbg
169172
- uses: actions/checkout@v6
@@ -190,6 +193,7 @@ jobs:
190193
- name: Extract Versions
191194
uses: ./.github/actions/extract_versions
192195
- name: Test
196+
shell: bash
193197
run: |
194198
set +e
195199
@@ -217,8 +221,11 @@ jobs:
217221
export JAVA_VERSION
218222
echo "JAVA_VERSION=${JAVA_VERSION}"
219223
220-
./gradlew -PCI -PkeepJFRs :ddprof-test:test${{ matrix.config }} --no-daemon --parallel --build-cache --no-watch-fs
221-
EXIT_CODE=$?
224+
mkdir -p build/logs
225+
./gradlew -PCI -PkeepJFRs :ddprof-test:test${{ matrix.config }} --no-daemon --parallel --build-cache --no-watch-fs 2>&1 \
226+
| tee -a build/test-raw.log \
227+
| python3 -u .github/scripts/filter_gradle_log.py
228+
EXIT_CODE=${PIPESTATUS[0]}
222229
223230
if [ $EXIT_CODE -ne 0 ]; then
224231
echo "musl-${{ matrix.java_version }}-${{ matrix.config }}-amd64" >> failures_musl-${{ matrix.java_version }}-${{ matrix.config }}-amd64.txt
@@ -339,8 +346,11 @@ jobs:
339346
export LIBC=glibc
340347
export SANITIZER=${{ matrix.config }}
341348
342-
./gradlew -PCI -PkeepJFRs :ddprof-test:test${{ matrix.config }} --no-daemon --parallel --build-cache --no-watch-fs
343-
EXIT_CODE=$?
349+
mkdir -p build/logs
350+
./gradlew -PCI -PkeepJFRs :ddprof-test:test${{ matrix.config }} --no-daemon --parallel --build-cache --no-watch-fs 2>&1 \
351+
| tee -a build/test-raw.log \
352+
| python3 -u .github/scripts/filter_gradle_log.py
353+
EXIT_CODE=${PIPESTATUS[0]}
344354
345355
if [ $EXIT_CODE -ne 0 ]; then
346356
echo "glibc-${{ matrix.java_version }}-${{ matrix.config }}-aarch64" >> failures_glibc-${{ matrix.java_version }}-${{ matrix.config }}-aarch64.txt
@@ -424,13 +434,16 @@ jobs:
424434
run: |
425435
set +e
426436
# the effective JAVA_VERSION is computed in the test_alpine_aarch64.sh script
437+
mkdir -p build/logs
427438
docker run --cpus 4 --rm -v /tmp:/tmp -v "${GITHUB_WORKSPACE}:${GITHUB_WORKSPACE}" -w "${GITHUB_WORKSPACE}" alpine:3.21 /bin/sh -c "
428439
\"$GITHUB_WORKSPACE/.github/scripts/test_alpine_aarch64.sh\" \
429440
\"${{ github.sha }}\" \"musl/${{ matrix.java_version }}-${{ matrix.config }}-aarch64\" \
430441
\"${{ matrix.config }}\" \"${{ env.JAVA_HOME }}\" \"${{ env.JAVA_TEST_HOME }}\"
431-
"
442+
" 2>&1 \
443+
| tee -a build/test-raw.log \
444+
| python3 -u .github/scripts/filter_gradle_log.py
432445
433-
EXIT_CODE=$?
446+
EXIT_CODE=${PIPESTATUS[0]}
434447
435448
if [ $EXIT_CODE -ne 0 ]; then
436449
echo "musl-${{ matrix.java_version }}-${{ matrix.config }}-aarch64" >> failures_musl-${{ matrix.java_version }}-${{ matrix.config }}-aarch64.txt

‎build-logic/conventions/src/main/kotlin/com/datadoghq/native/config/ConfigurationPresets.kt‎

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -205,8 +205,8 @@ object ConfigurationPresets {
205205
if (libasan != null) {
206206
config.testEnvironment.apply {
207207
put("LD_PRELOAD", libasan)
208-
put("ASAN_OPTIONS", "allocator_may_return_null=1:unwind_abort_on_malloc=1:use_sigaltstack=0:detect_stack_use_after_return=0:handle_segv=1:halt_on_error=0:abort_on_error=0:print_stacktrace=1:symbolize=1:suppressions=$rootDir/gradle/sanitizers/asan.supp")
209-
put("UBSAN_OPTIONS", "halt_on_error=0:abort_on_error=0:print_stacktrace=1:suppressions=$rootDir/gradle/sanitizers/ubsan.supp")
208+
put("ASAN_OPTIONS", "allocator_may_return_null=1:unwind_abort_on_malloc=1:use_sigaltstack=0:detect_stack_use_after_return=0:handle_segv=1:halt_on_error=0:abort_on_error=0:print_stacktrace=1:symbolize=1:log_path=/tmp/asan_%p.log:suppressions=$rootDir/gradle/sanitizers/asan.supp")
209+
put("UBSAN_OPTIONS", "halt_on_error=0:abort_on_error=0:print_stacktrace=1:log_path=/tmp/ubsan_%p.log:suppressions=$rootDir/gradle/sanitizers/ubsan.supp")
210210
put("LSAN_OPTIONS", "detect_leaks=0")
211211
}
212212
}
@@ -260,7 +260,7 @@ object ConfigurationPresets {
260260
if (libtsan != null) {
261261
config.testEnvironment.apply {
262262
put("LD_PRELOAD", libtsan)
263-
put("TSAN_OPTIONS", "suppressions=$rootDir/gradle/sanitizers/tsan.supp")
263+
put("TSAN_OPTIONS", "suppressions=$rootDir/gradle/sanitizers/tsan.supp:log_path=/tmp/tsan_%p.log")
264264
}
265265
}
266266
}

‎build-logic/conventions/src/main/kotlin/com/datadoghq/profiler/ProfilerTestPlugin.kt‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -208,7 +208,7 @@ class ProfilerTestPlugin : Plugin<Project> {
208208
// Test output
209209
testTask.testLogging {
210210
val logging = this
211-
logging.events("passed", "skipped", "failed")
211+
logging.events("started", "passed", "skipped", "failed")
212212
logging.showStandardStreams = true
213213
}
214214

‎ddprof-test/src/test/java/com/datadoghq/profiler/test/ProfilerTestRunner.java‎

Lines changed: 74 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,14 +1,21 @@
11
package com.datadoghq.profiler.test;
22

3+
import org.junit.platform.engine.TestExecutionResult;
4+
import org.junit.platform.engine.TestSource;
35
import org.junit.platform.engine.discovery.ClassNameFilter;
46
import org.junit.platform.engine.discovery.DiscoverySelectors;
7+
import org.junit.platform.engine.support.descriptor.MethodSource;
58
import org.junit.platform.launcher.Launcher;
69
import org.junit.platform.launcher.LauncherDiscoveryRequest;
10+
import org.junit.platform.launcher.TestExecutionListener;
11+
import org.junit.platform.launcher.TestIdentifier;
712
import org.junit.platform.launcher.core.LauncherDiscoveryRequestBuilder;
813
import org.junit.platform.launcher.core.LauncherFactory;
914
import org.junit.platform.launcher.listeners.SummaryGeneratingListener;
1015

1116
import java.io.PrintWriter;
17+
import java.util.Optional;
18+
import java.util.concurrent.ConcurrentHashMap;
1219

1320
/**
1421
* Custom test runner using JUnit Platform Launcher API.
@@ -101,10 +108,10 @@ private static void runTests() {
101108

102109
LauncherDiscoveryRequest request = requestBuilder.build();
103110

104-
// Create launcher and register listener
111+
// Create launcher and register listeners
105112
Launcher launcher = LauncherFactory.create();
106113
SummaryGeneratingListener listener = new SummaryGeneratingListener();
107-
launcher.registerTestExecutionListeners(listener);
114+
launcher.registerTestExecutionListeners(new GradleStyleTestListener(), listener);
108115

109116
// Execute tests
110117
launcher.execute(request);
@@ -149,4 +156,69 @@ private static boolean isMethodFilter(String filter) {
149156
// Method names conventionally start with lowercase
150157
return Character.isLowerCase(lastSegment.charAt(0));
151158
}
159+
160+
/**
161+
* Emits per-test STARTED / PASSED / FAILED / SKIPPED markers to stdout in the same
162+
* format as Gradle's Test task, so that filter_gradle_log.py can compress the output
163+
* identically on both glibc and musl paths.
164+
*
165+
* Output format (matches Gradle's testLogging output):
166+
* com.example.FooTest > testBar STARTED
167+
* com.example.FooTest > testBar PASSED (42ms)
168+
* com.example.FooTest > testBar FAILED
169+
* java.lang.AssertionError: ...
170+
*/
171+
private static final class GradleStyleTestListener implements TestExecutionListener {
172+
private final ConcurrentHashMap<String, Long> startTimes = new ConcurrentHashMap<>();
173+
174+
@Override
175+
public void executionStarted(TestIdentifier testIdentifier) {
176+
if (!testIdentifier.isTest()) return;
177+
startTimes.put(testIdentifier.getUniqueId(), System.currentTimeMillis());
178+
String name = formatName(testIdentifier);
179+
if (name != null) {
180+
System.out.println(name + " STARTED");
181+
System.out.flush();
182+
}
183+
}
184+
185+
@Override
186+
public void executionFinished(TestIdentifier testIdentifier, TestExecutionResult result) {
187+
if (!testIdentifier.isTest()) return;
188+
String name = formatName(testIdentifier);
189+
if (name == null) return;
190+
191+
Long start = startTimes.remove(testIdentifier.getUniqueId());
192+
long ms = start != null ? System.currentTimeMillis() - start : 0;
193+
194+
switch (result.getStatus()) {
195+
case SUCCESSFUL:
196+
System.out.printf("%s PASSED (%dms)%n", name, ms);
197+
break;
198+
case FAILED:
199+
case ABORTED:
200+
System.out.printf("%s FAILED%n", name);
201+
result.getThrowable().ifPresent(t -> t.printStackTrace(System.out));
202+
break;
203+
}
204+
System.out.flush();
205+
}
206+
207+
@Override
208+
public void executionSkipped(TestIdentifier testIdentifier, String reason) {
209+
if (!testIdentifier.isTest()) return;
210+
String name = formatName(testIdentifier);
211+
if (name != null) {
212+
System.out.println(name + " SKIPPED");
213+
System.out.flush();
214+
}
215+
}
216+
217+
private static String formatName(TestIdentifier testIdentifier) {
218+
Optional<TestSource> source = testIdentifier.getSource();
219+
if (!source.isPresent() || !(source.get() instanceof MethodSource)) return null;
220+
MethodSource ms = (MethodSource) source.get();
221+
return ms.getClassName() + " > " + ms.getMethodName();
222+
}
223+
}
152224
}

0 commit comments

Comments
 (0)