Skip to content

Profiling results publish script with improved checks #5923

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
marc-casavant wants to merge 3 commits into
base: master
Choose a base branch
from
+89 −83
Open

Profiling results publish script with improved checks #5923

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
f104cb6
ci: publish refuses or prunes unclean profiling runs
marc-casavant Aug 21, 2026
2f4325a
publish: always prune unclean tests, go red only when all are pruned
marc-casavant Aug 21, 2026
2d8ac44
ci: BRANCH-LOCAL run only multi-server tests while developing the check
marc-casavant Aug 21, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
73 changes: 5 additions & 68 deletions .github/workflows/ci-pipeline.yml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -22,76 +22,13 @@ concurrency:
group: ${{ github.workflow }}-${{ github.head_ref || github.ref_name }}
cancel-in-progress: true

#
# BRANCH-LOCAL: every leg except the multi-server tests is removed while the
# profiling result check is developed on this branch. Restore the full job
# list from master before merging.
#
jobs:
ci:
name: CI
uses: ./.github/workflows/ci.yml
with:
selfhosted: ${{ github.repository_owner == 'FreeRADIUS' && '1' || '0' }}
docker_prefix: ${{ github.repository_owner == 'FreeRADIUS' && 'docker.internal.networkradius.com/' || '' }}
secrets: inherit

ci-deb:
name: CI DEB
uses: ./.github/workflows/ci-deb.yml
secrets: inherit

ci-rpm:
name: CI RPM
uses: ./.github/workflows/ci-rpm.yml
secrets: inherit

ci-sanitizers:
name: CI-Sanitizers
uses: ./.github/workflows/ci-sanitizers.yml
with:
selfhosted: ${{ github.repository_owner == 'FreeRADIUS' && '1' || '0' }}
docker_prefix: ${{ github.repository_owner == 'FreeRADIUS' && 'docker.internal.networkradius.com/' || '' }}
secrets: inherit

#
# Run on every commit but absent from merge's needs:, so a failure here is
# reported and diagnosed without holding up the merge.
#
ci-freebsd:
name: CI FreeBSD
uses: ./.github/workflows/ci-freebsd.yml
secrets: inherit

ci-macos:
name: CI macOS
uses: ./.github/workflows/ci-macos.yml
secrets: inherit

ci-multi-server:
name: Multi-Server CI Tests
uses: ./.github/workflows/ci-multi-server-tests.yml
secrets: inherit

#
# Image builds take about as long as CI takes to fail, so ungated they were
# finishing in full on every broken commit. needs: ci skips them instead.
# They are per-commit smoke builds - docker-refresh.yml does the publishing
# on its own schedule - so starting them later costs nothing.
#
docker-crossbuild:
name: Docker crossbuild images
needs: [ci]
uses: ./.github/workflows/docker-crossbuild.yml
secrets: inherit

docker-service:
name: Docker service images
needs: [ci]
uses: ./.github/workflows/docker-service.yml
secrets: inherit

#
# No if:, so the default applies: runs only when every leg it needs
# succeeded, and is skipped otherwise. Only the gating legs are listed.
#
merge:
needs: [ci, ci-deb, ci-rpm, ci-sanitizers]
uses: ./.github/workflows/merge-upstream.yml
secrets:
GH_APP_PRIVATE_KEY: ${{ secrets.GH_APP_PRIVATE_KEY }}
77 changes: 67 additions & 10 deletions scripts/ci/publish-profiling-results.sh
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -22,9 +22,11 @@ Core dumps are excluded; collect-core-dumps.sh keeps those instead. Run from
the directory holding prof-results/. A missing prof-results/ tree, or one
holding nothing publishable, is a quiet success.

Fails without publishing when any test's valgrind-exit-status is non-zero,
because a run valgrind killed has truncated callgrind output whose numbers are
not comparable with previous runs.
Prunes any test whose valgrind-exit-status is non-zero or missing, because a
run valgrind killed has truncated callgrind output whose numbers are not
comparable with previous runs. The clean remainder is published, so the store
receives only comparable data. A run where every test is unclean has nothing
comparable to publish and exits non-zero so the CI leg goes red.

<url> Where to POST. Its origin becomes the OIDC audience.
-h Show this help.
Expand Down Expand Up @@ -53,13 +55,19 @@ audience="${url%%://*}://${host_path%%/*}"

[ -d prof-results ] || { echo "no prof-results/ tree; skipping"; exit 0; }

# Refuse to publish a run valgrind did not finish cleanly. start_valgrind_-
# Never publish a test valgrind did not finish cleanly. start_valgrind_-
# profiling.sh drops a valgrind-exit-status file in each test's results dir; a
# non-zero status means valgrind was killed, which leaves callgrind output
# truncated at whatever point it died. Numbers from a truncated run are not
# comparable with a clean one, and publishing them silently poisons the
# per-suite history the regression gate compares against. Exits non-zero so
# the leg goes red rather than passing with nothing uploaded.
# per-suite history the regression gate compares against, so unclean tests
# are pruned (with a warning naming each one) and the rest publish normally.
#
# A results dir holding the wrapper's log but no valgrind-exit-status is just
# as unclean: the wrapper writes valgrind_profiling.log first and the status
# file only after valgrind exits, so a missing status file means the wrapper
# was killed mid-run (e.g. the container was torn down around a hung
# shutdown) and never saw valgrind finish.
unclean=""
for status_file in $(find prof-results -type f -name valgrind-exit-status | sort); do
read -r status <"$status_file" || status="unreadable"
Expand All @@ -68,13 +76,55 @@ for status_file in $(find prof-results -type f -name valgrind-exit-status | sort
esac
unclean="${unclean} ${status_file%/valgrind-exit-status}:${status}"
done
for wrapper_log in $(find prof-results -type f -name valgrind_profiling.log | sort); do
dir=${wrapper_log%/valgrind_profiling.log}
[ -f "$dir/valgrind-exit-status" ] || unclean="${unclean} ${dir}:missing"
done
# Exit statuses above 128 are 128 + signal number; name the common ones so
# the CI log reads as a cause, not a bare number.
explain_status()
{
case $1 in
missing)
echo "no exit status recorded: the profiling wrapper was killed mid-run" ;;
134) echo "status 134: SIGABRT, usually a freeradius assert (see the freeradius.log line below)" ;;
137) echo "status 137: SIGKILL (out-of-memory killer, or forced container teardown)" ;;
139) echo "status 139: SIGSEGV (crash)" ;;
143) echo "status 143: SIGTERM (asked to shut down mid-run)" ;;
*) if [ "$1" -gt 128 ] 2>/dev/null; then
echo "status $1: killed by signal $(($1 - 128))"
else
echo "valgrind exited with status $1"
fi ;;
esac
}

if [ -n "$unclean" ]; then
echo "ERROR: refusing to publish, valgrind exited uncleanly in:" >&2
echo "WARNING: pruning tests where valgrind did not finish cleanly:" >&2
for entry in $unclean; do
echo " ${entry%:*} (status ${entry##*:})" >&2
dir=${entry%:*}
echo " ${dir}" >&2
echo " $(explain_status "${entry##*:}")" >&2
# Valgrind passes the profiled server's exit status through, so the
# cause usually lives in freeradius.log (asserts, caught signals),
# not valgrind.log. Quote the first such line so the cause is
# visible without downloading the artifact. NOTE: valgrind.log's
# "brk segment overflow" warning appears in clean runs too (glibc
# falls back to mmap); do not treat it as the failure reason.
diag=$(grep -E -m1 "ASSERT FAILED|CAUGHT SIGNAL|_EXIT\(|PANIC" "$dir/freeradius.log" 2>/dev/null || true)
if [ -n "$diag" ]; then
echo " freeradius.log: ${diag}" >&2
else
diag=$(grep -E -m1 "Assertion|FATAL|out of memory|'impossible' happened|Fatal error" "$dir/valgrind.log" 2>/dev/null || true)
[ -n "$diag" ] && echo " valgrind.log: ${diag}" >&2
Comment on lines +116 to +119

@claude claude Bot Aug 21, 2026

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 In publish-profiling-results.sh this script runs under #!/bin/sh (dash on the CI runners), whose echo builtin interprets backslash escapes by default — so echo "...: ${diag}" at lines 121/124 can mangle or truncate the diagnostic line (a trailing \c drops the rest of the line and its newline) since $diag is untrusted, grep-captured log content that can contain backslashes (e.g. LDAP DN escapes, DOMAIN\\user). The sibling script touched by this same PR (start_valgrind_profiling.sh) already avoids this exact issue by using printf '%s\n' "$var" for variable content — the same pattern should be used here, e.g. printf ' freeradius.log: %s\n' "${diag}" >&2.

Extended reasoning...

The bug: publish-profiling-results.sh declares #!/bin/sh, which on the FreeRADIUS CI runners resolves to dash. Unlike bash, dash's echo builtin interprets backslash escape sequences unconditionally (XSI-style behavior, no -e needed) — POSIX explicitly leaves this implementation-defined, and dash chooses to always expand escapes. The new diagnostic lines added by this PR are:

echo "           freeradius.log: ${diag}" >&2
...
echo "           valgrind.log: ${diag}" >&2

$diag is not a fixed string — it is captured via grep -E -m1 ... "$dir/freeradius.log" (or valgrind.log), i.e. arbitrary, attacker/environment-controlled log content (assert messages, panic messages, signal-related text). FreeRADIUS fault messages routinely embed backslashes: LDAP DN/filter escaping uses sequences like \\28/\\29, and Windows/NTLM/Kerberos identities appear as DOMAIN\\user. If such a backslash sequence lands in the matched line, dash's echo will reinterpret it as an escape rather than printing it literally.

Concrete proof (verified by two independent verifiers running dash):

$ dash -c 'diag="some text\\ctrailing"; echo "line: ${diag}"'
line: some text

The \\c sequence causes dash's echo to suppress all further output including the trailing newline — the diagnostic is truncated mid-line and the next echo's output gets concatenated onto the same terminal/log line. Other sequences like \\n or \\t insert literal control characters into the CI log instead of printing the log line as-is.

Why nothing today prevents this: the value flows straight from grep output into echo with no sanitization, and there is no guarantee the shell interpreting the script is a POSIX/bash-only echo — the shebang is #!/bin/sh, and CI runners for this repo use dash for /bin/sh.

Established precedent in this very PR: start_valgrind_profiling.sh, modified by this same PR, already prints variable/log-derived content ($CTRL_OUT) via printf '%s\n' "$CTRL_OUT" specifically to sidestep this exact class of shell-dependent echo behavior. The new diagnostic code in publish-profiling-results.sh doesn't follow that established, safer pattern.

Impact: this is diagnostic output written to stderr in the CI log only — it does not influence the unclean-detection logic, the prune/refuse-to-publish decision, or the exit code, all of which are driven by the valgrind-exit-status file contents, not this echoed string. Worst case is a garbled or truncated hint line in the CI log, occasionally running into the next line's output, which makes the diagnostic harder to read right when someone is debugging a CI failure — mildly self-defeating for a change whose whole purpose is improving diagnostics, but not something that breaks the pipeline.

Fix: swap both echo calls for printf, matching the sibling script's pattern:

printf '           freeradius.log: %s\n' "${diag}" >&2
...
printf '           valgrind.log: %s\n' "${diag}" >&2

fi
done
# Drop each unclean test's directory so only comparable data travels. An
# all-unclean run leaves nothing publishable and errors out at the
# empty-file-list check below.
for entry in $unclean; do
rm -rf "${entry%:*}"
done
echo "ERROR: truncated profiling data is not comparable with previous runs" >&2
exit 1
fi

tmpdir=$(mktemp -d)
Expand Down Expand Up @@ -113,6 +163,13 @@ if [ -s "$core_list" ]; then
fi

if ! [ -s "$file_list" ]; then
# An all-unclean run is a failure, not a skip: every test was pruned, so
# the run produced no comparable data at all and the leg must go red
# rather than quietly publishing nothing.
if [ -n "$unclean" ]; then
echo "ERROR: every test was pruned as unclean; no comparable data to publish" >&2
exit 1
fi
echo "prof-results/ holds no publishable files; skipping"
exit 0
fi
Expand Down
22 changes: 17 additions & 5 deletions src/tests/multi-server/scripts/profiling/start_valgrind_profiling.sh
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -125,18 +125,30 @@
echo "INFO: waiting for valgrind to exit"
VALGRIND_STATUS=0
wait ${VALGRIND_PID} 2>/dev/null || VALGRIND_STATUS=$?
echo "${VALGRIND_STATUS}" > /etc/prof-results/valgrind-exit-status

if [ "${VALGRIND_STATUS}" -ne 0 ]; then
# Over 128 means a signal. 139 is SIGSEGV, which is how valgrind exiting on
# its 8 MB brk segment ceiling presents; valgrind.log names the real reason
# on the line above its backtrace.
# Over 128 means a signal. Valgrind passes the profiled server's exit
# status through (verified: freeradius's own _EXIT(134) matched the 134
# recorded here on the e26e348 ldap run), so a signal status usually
# means FREERADIUS died of that signal - an assert or crash logged in

Check warning on line 134 in src/tests/multi-server/scripts/profiling/start_valgrind_profiling.sh

View check run for this annotation

Claude / Claude Code Review

Stale comment in start_valgrind_profiling.sh describes old refuse-to-publish behavior 

The comment above this block (start_valgrind_profiling.sh:119-124) still says the publish step 'refuses to upload an unclean run' — this same PR rewrote publish-profiling-results.sh so it now only prunes the unclean test's own directory and publishes the clean remainder, refusing the whole run only when every test is unclean. The PR updated the parallel comments in publish-profiling-results.sh itself but missed this sibling description of the same cross-script contract.
Comment on lines 128 to +134

@claude claude Bot Aug 21, 2026

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 The comment above this block (start_valgrind_profiling.sh:119-124) still says the publish step 'refuses to upload an unclean run' — this same PR rewrote publish-profiling-results.sh so it now only prunes the unclean test's own directory and publishes the clean remainder, refusing the whole run only when every test is unclean. The PR updated the parallel comments in publish-profiling-results.sh itself but missed this sibling description of the same cross-script contract.

Extended reasoning...

The bug: The comment at start_valgrind_profiling.sh:119-124 explains why VALGRIND_STATUS is written to valgrind-exit-status, stating: "the status has to survive to the publish step, which reads this file and refuses to upload an unclean run." That description was accurate before this PR — the old publish-profiling-results.sh did an all-or-nothing exit 1 whenever any test's status file was non-zero.

What changed under it: This exact PR rewrites publish-profiling-results.sh to no longer refuse the whole run. It now loops over unclean entries, prints a WARNING: pruning tests... message, and rm -rfs only each unclean test's own directory (for entry in $unclean; do rm -rf "${entry%:*}"; done), then proceeds to tar and publish whatever clean directories remain. The script only exit 1s if every test was pruned (the new check if [ -n "$unclean" ] inside the ! [ -s "$file_list" ] branch). So for the common case — one flaky/crashed test among several — the run is no longer refused; it's partially published.

Why existing code doesn't catch this: Nothing enforces comment/behavior consistency automatically; this is purely a documentation-drift issue caught by manual review. The PR author clearly tracked this same contract change in the sibling file: the header doc-comment in publish-profiling-results.sh changed from "Fails without publishing when any test's valgrind-exit-status is non-zero" to "Prunes any test whose valgrind-exit-status is non-zero or missing... The clean remainder is published", and the inline comment above the unclean loop changed from "Refuse to publish a run valgrind did not finish cleanly" to "Never publish a test valgrind did not finish cleanly... unclean tests are pruned... and the rest publish normally." Both of those were deliberately kept in sync. The comment in the sibling script describing the same cross-script contract was simply missed.

Impact: None on runtime behavior — this is a comment inside start_valgrind_profiling.sh, which only records $VALGRIND_STATUS to the status file; the stale text doesn't change what gets recorded or how the publish step behaves. The impact is purely on a future reader: someone debugging why a partially-unclean profiling run still got some data published might read this comment, believe the whole run should have been refused, and waste time looking for a bug in the prune logic that doesn't exist.

Step-by-step proof:

  1. Suppose a multi-server CI job runs 3 profiling tests; test B's freeradius process crashes under valgrind (SIGSEGV), tests A and C finish cleanly.
  2. start_valgrind_profiling.sh runs in each container; for B it writes a non-zero VALGRIND_STATUS (e.g. 139) to /etc/prof-results/valgrind-exit-status, exactly as the comment at line 119-124 describes.
  3. publish-profiling-results.sh runs once over the combined prof-results/ tree. It finds B's status file is non-zero, adds it to $unclean, prints the warning + diagnostic for B, and rm -rfs only B's directory.
  4. A's and C's directories are untouched. $file_list is non-empty (A and C's files), so the script proceeds to tar, mint an OIDC token, and POST the tarball — the run is published, just without B's data.
  5. Reading the comment at lines 119-124 of start_valgrind_profiling.sh, a reader would conclude step 4 shouldn't have happened ("refuses to upload an unclean run") — but it did, correctly, per the new intended behavior.

Fix: Reword the trailing clause, e.g.: "...so the status has to survive to the publish step, which prunes this test's directory if the run was unclean rather than publishing truncated data. The status is recorded for clean runs too, so an absent file means 'the wrapper did not get this far' rather than 'the run was fine'." matching the phrasing already used in the updated publish-profiling-results.sh comments.

# freeradius.log - rather than valgrind itself being killed.
# valgrind.log's "brk segment overflow" warning is NOT the reason: clean
# runs carry it too (glibc falls back to mmap when brk cannot grow).
if [ "${VALGRIND_STATUS}" -gt 128 ]; then
echo "ERROR: valgrind was killed by signal $((VALGRIND_STATUS - 128)); profiling data is truncated" >&2
SIG=$((VALGRIND_STATUS - 128))
case ${SIG} in
6) SIGNAME="SIGABRT (abort/assertion)" ;;
9) SIGNAME="SIGKILL (OOM killer or forced teardown)" ;;
11) SIGNAME="SIGSEGV (crash)" ;;
15) SIGNAME="SIGTERM" ;;
*) SIGNAME="signal ${SIG}" ;;
esac
echo "ERROR: exit status ${VALGRIND_STATUS}: ${SIGNAME}; freeradius likely died of that signal (see freeradius.log for asserts/backtraces)" >&2
else
echo "ERROR: valgrind exited ${VALGRIND_STATUS}; profiling data may be truncated" >&2
fi
echo "ERROR: see valgrind.log for the reason; these results will not be published" >&2
echo "ERROR: these results will not be published" >&2
fi

# Signal that valgrind has finished writing all profiling data
Expand Down
Loading