Repository navigation
check-rd-presets reports a present preset as missing when printf loses a SIGPIPE race under pipefail #4153
Description
Activity
Captured in production rather than reproduced synthetically, and the two lines land together in the log:
hack/check-rd-presets.sh: line 39: printf: write error: Broken pipe FAIL: packages/system/postgres-rd/cozyrds/postgres.yaml resourcesPreset enum missing: s1.nano make: *** [Makefile:120: rd-presets-check] Error 1That is run 34163203912, on a pull request that touches
packages/apps/vm-instanceand nothing underpostgres-rd.s1.nanois present inpackages/system/postgres-rd/cozyrds/postgres.yamlonmainand on the branch alike, so the preset the check calls missing is there in both trees the job could have been looking at.The broken-pipe warning immediately preceding the FAIL is the mechanism naming itself:
printfwas still writing whengrep -qexited on the match, andpipefailturned that into the failure theif !reads as absence.Worth noting what this costs beyond the red check. The job fails at
rd-presets-checkbefore the rest of the target completes, so a pull request that trips this loses the coverage of whatever ran after it, not just the preset check. And because the victim is whichever file the loop happened to be on, the failure message points at a package the author never touched, which sends whoever reads it to look in the wrong tree first.I filed #4158 on the same line before finding this one, so that one is a duplicate and I have closed it. Bringing over the measurement from it, because it does not agree with the reasoning here.
The claim that
$enumsis long enough to fill the pipe buffer does not hold. The largest enum any RD file yields is 3009 bytes (seaweedfs); every other one is smaller. A pipe buffer is 64 KiB, soprintfcompletes its single write beforegrepcan leave, and there is no SIGPIPE for it to take.Measured rather than argued, on bash 5.3:
- The real 47-preset list, searching for the first element (the worst case, since grep leaves immediately): 3000 runs, zero false "missing". Another 3000 with the CPU saturated the way a parallel
makesaturates a runner: still zero. - The reproducer in this issue, searching the last element: 3000 runs, zero. Same list searching the first element: 3000 runs, zero.
- The construct does fail as described once the input outgrows the buffer.
seq 1 200000piped intogrep -Fqx -- "1"reports the element as missing, and the pipeline returns 141.
So the mechanism is real and the fix is right, but it is not what made these jobs red, and the issue currently states a cause it has not established.
One more data point against the SIGPIPE reading: the failing
Unit & controller testsjob on #3594 went green on a rerun with no change to the tree. Whatever differs between the two runs, it is not the script and not the input.Worth noting alongside:
ghwas returningGateway Timeoutonactions/runs,actions/workflowsand GraphQL while these failures were being looked at, andhelm plugin installwas failing atValidating Checksumin the same window. Three failed network calls in one window is not a diagnosis either, but it is a better lead than a race that does not reproduce at this input size.The sweep of the other call sites stands on its own and is worth doing regardless of which cause is found, for the reason the issue gives: the construct turns any write error into a wrong answer about the data instead of surfacing a broken read.
- The real 47-preset list, searching for the first element (the worst case, since grep leaves immediately): 3000 runs, zero false "missing". Another 3000 with the CPU saturated the way a parallel
I filed #4178 as a separate report before finding this one. Closing it as a duplicate; two things from it are worth carrying over here.
The victim is not stable across attempts of the same run. Run 34516348714 reported
packages/system/opensearch-rd/cozyrds/opensearch.yaml resourcesPreset enum missing: u1.mediumat 11:40:31, andpackages/system/rabbitmq-rd/cozyrds/rabbitmq.yaml resourcesPreset enum missing: s1.xlargeat 13:10:11. Same run id, different file, different preset, both present in the file named. So matching the failure against what a PR changed will never clear it, and a re-run does not fix it — it reshuffles which name appears. A third sighting today on an unrelated PR namedredis-rdandt1.xlarge.The line-39 attribution is right, and the other pipe in that loop is ruled out. The same function has a second writer into a pipe at lines 27-32,
enums=$(printf '%s' "$schema" | jq -r '...' 2>/dev/null || true), which writes the whole schema blob and is therefore a far more plausible EPIPE site by size. It is not the one: bash attributes an error inside a multi-line command to that command's last line, so an EPIPE there would be reported as line 32. Note also that the2>/dev/nullon that line binds to jq, not to printf, so a printf warning from that site would still have reached the log under its own line number.One expectation worth setting for anyone who tries to reproduce it by hand. At the real input size it does not reproduce on a developer machine: the enum list is a few kilobytes, one
write()well inside the 64K pipe buffer, so printf finishes before grep can close the read end and there is no window. Several hundred iterations locally gave zero false failures. Forcing the window open needs an oversized writer, which demonstrates the mechanism and says nothing about the real size. Expect green when you try it; that is not evidence against the bug.Fixed on main by #4204. The failures in #4178 from 17 and 18 September were re-runs of runs created on 9 September, and a re-run keeps the merge commit it was created with, so they ran the old script.
One correction to my comment above. bash sets stdout to line buffering at startup (
sh_setlinebuf (stdout)in shell.c), so the builtin printf flushes at newline boundaries and the 47-line list goes out in a dozen or so writes rather than one (strace on bash 5.2 with glibc: the first lines one per write, the rest in chunks of several lines). grep -q leaves after the first match and every write after that gets EPIPE, at any list size. The here-string has no such window: bash writes the whole document into a pipe or a temp file before the command starts.Main still has no test for this script. #4191 and #4194 both carry one. Whichever gets rebased should keep it. Closing.
hack/check-rd-presets.shreports a preset that is present as missing, at random, on loaded runners. It is a SIGPIPE race, not a content problem, and it fails theUnit & controller testsjob of whatever pull request happens to be running when it fires.Line 39 is
if ! printf '%s\n' "$enums" | grep -Fqx -- "$want"; then, underset -euo pipefailfrom line 7.grep -qexits the instant it matches. Ifprintfis still writing at that moment it takes SIGPIPE and exits 141,pipefailhands 141 up as the pipeline's status, andif !reads the failure as "not found". So the branch that runs is the one that reports a preset the file actually contains as absent.Reproduced with the same construct rather than argued:
prints
SMALL: foundandLARGE: reported MISSING. The value is present in both cases; only the size of the write differs.That is why it is intermittent and why it passes locally. Forty-odd short lines usually fit the pipe buffer, so
printffinishes beforegrepexits and nothing goes wrong. It needs a runner loaded enough for the writer to lose that race. It also explains the shape of the failures: two different pull requests running in the same minute failed the same line naming different presets,postgres-rdmissings1.nanoin one andnats-rdmissings1.4xlargein the other. A stale-content failure names the same thing every time; a race names whatever it happened to be checking.The fix is to remove the pipe rather than to work around the exit code, since the pipe is what creates the writer that can be killed:
That change already exists unmerged: commit
99d16a21bonfeat/externalip-apimakes it, with a comment naming the same mechanism. Until that branch lands the race stays live on main and any pull request can still fail this line.Two things have to hold together for this to bite:
pipefail, so the writer's SIGPIPE becomes the pipeline's status, and a writer with enough left to write that it is still going whengrep -qexits.hack/has many| grep -qsites and only a few scripts that setpipefail, and line 39 here is the only place the two meet. The other sites run withoutpipefail, so grep's status is the pipeline's status and the writer's death never surfaces.seaweedfs-naming-audit.shis the clearest of those: it is POSIXshon purpose, with a comment saying dash rejectspipefailand thatcozytest.shsources the script into dash.