fix(remote): keep curl's stderr, and hold the temporaries in one condemned directory (#850) - #903
Merged
Conversation
…emned directory (#850) Rebuilt on current main, where the header-sink work has landed and the helper now has two arms. The previous branch predated that and no longer applied. WHAT IT ADDS Curl's stderr is kept and shown when curl actually failed. The caller only ever sees the HTTP code, and this function reports "000" for every kind of failure alike -- a refused connection, a timeout, a path curl could not open. A Windows run spent a long time on a bare 000 whose cause was in the stream this line threw away. Shown only on failure: curl -sS is silent on success, and an unconditional dump would land in the middle of a caller's output. WHAT IT SIMPLIFIES All temporaries now live in one directory, minted before the trap is armed: work_dir="$(mktemp -d ...)" trap "rm -rf <baked work_dir>" EXIT INT TERM cfg="$work_dir/config"; curl_err="$work_dir/stderr"; header_fifo="$work_dir/header" Two reasons, both measured earlier in this series. An EXIT trap set inside a function runs after the frame is gone, so a single-quoted body expands $cfg in the caller's scope and removes "" -- bash 3.2.57 and 5.3.15 both report EMPTY. And anything created before the trap is armed is unprotected, which reordering cannot fix because there is always a first allocation. It also removes a hazard instead of guarding it. main carries a comment warning that on the marker path `header_fifo` IS `header_file`, so an unconditional `rm -f "$header_fifo"` would delete the headers the caller asked for. The caller's file is outside work_dir, so `rm -rf` cannot reach it -- the guard becomes a property of the layout rather than a condition to remember. Two traps become one, and fifo_dir disappears. TESTS tests/test_remote_curl_stderr.bats, 8 ok / 0 not ok: failing curl the diagnosis reaches the caller's stderr succeeding curl nothing does, and the stub wrote to stderr anyway both the http code is unchanged, 200 and 000 both no scratch left in the run's own TMPDIR early exit errexit out of the middle sweeps everything setup failure mkfifo fails after the directory exists -- nothing survives premise an EXIT trap cannot read the locals of the function that set it, measured, so the printf %q baking is not read as ceremony control the leftover check fires on a planted leftover 22 ok / 0 not ok across this file and the two that already cover this helper. DEPENDENCY, MEASURED IN BOTH DIRECTIONS This change makes an existing test on main fail deterministically, and the fix for that is a separate PR that is already open: main's harness + this change -> not ok 21 ... reported 000 harness fix + this change -> ok tests/test_remote_curl_config_paths.bats compares bats's $output -- stdout and stderr merged -- against "000". Showing curl's diagnosis puts a line in front of the code. On main that test is already intermittently red for the same reason under CI load; this turns intermittent into certain. So the harness PR is a prerequisite, not a nicety, and this branch is stacked on it. Windows unverified by me.
…utcome (#850) Review found that the line I added to print curl's stderr was itself an exit. [ "$curl_status" -ne 0 ] && [ -s "$curl_err" ] && cat "$curl_err" >&2 Under set -e, a failing `cat` -- closed stderr, a reader that went away, a full disk -- ends the function right there. The copier is never reaped, the work_dir is never removed, and the caller gets nothing at all where this helper promises "000" for every failure. Being unable to EXPLAIN a failure turned it into a DIFFERENT failure. And I had a test asserting that. It drove a failing cat, asserted nonzero status and empty stdout, and its own comment noted the copier was left orphaned. It was measuring the defect and calling it the property -- the reviewer read the test as the specification, which is what a test is. Now: reap and decide first, then write the diagnosis best-effort. Same case, three assertions the other way round: status 0 and "000" on stdout the contract, unchanged by a failed write no copier still running recorded by pid, not assumed no work_dir left The copier pid is observable now. A python3 wrapper records $$ and then execs the real one, so the number in the log IS the process the helper must reap. Teardown reaps any that survive and says it did -- a fixture that leaves a process blocked on a fifo holds whatever descriptors it inherited, which is how three probes in this series hung. 8 ok / 0 not ok.
…850) Review was right twice over, and the second point turned out to be deeper than either of us wrote. The check it questioned passed vacuously on an empty record, and its teardown killed by remembered PID -- a number the kernel is free to reuse, so the fixture could have signalled an unrelated process on the runner. Trying to fix it properly is what produced the finding. Four instruments, each failing its own positive control on this machine: a pid the copier records itself the failure path kills it before the forked shell runs its first line: log EMPTY pgrep -f <full script path> no match while the process is alive pgrep -f bounded-copy.py matched an unrelated shell whose argv merely contained the string -- it would have killed the wrong process lsof +D <work dir> nothing: a copier blocked in open() holds no fd on it yet One fact explains all four. A copier waiting on the fifo is still a forked BASH wearing its parent's command line -- measured, `comm` reads `bash` -- because python3 is not exec'd until curl opens the pipe. It is identifiable as "a child of that shell" and by nothing else, and after the shell exits, not even that. A fifth attempt, running the driven shell in its own process group so the group could be the identity, hung the harness: the orphan holds the capture pipe, which is the same way three earlier probes in this series died. So the assertion is removed rather than left as a green that measures nothing, and the case says all of the above where the next person will be tempted to add it back. The reaping is still in production (kill then wait before the code is returned); what is unproven is the ABSENCE of a survivor, and that behaviour is already filed as #864. What the case still asserts, and what review asked for: status 0 and "000" on stdout the contract, unchanged by a failed write no work_dir left cleanup still runs 8 ok / 0 not ok.
…me it (#850) I said the absence of a survivor could not be measured. Review pointed at the identity I had not used: the helper's own child table. Every instrument I tried looked for the copier in the process table AFTER the fact, and all four failed because a copier waiting on the fifo is still a forked bash wearing its parent's command line -- python3 is not exec'd until curl opens the pipe. Nothing outside can name it. But `wait` is a builtin over the shell's OWN waitable children. A successful wait IS the observation, and it needs no identity of its own. So the driven shell shadows `kill` and `wait`, records the pid each was given, and delegates to the builtins. Production runs unchanged; only the seam is recorded. The case now asserts: the pid killed is the pid waited on the wait collected that child -- rc is not 127, which is bash's "not a child of this shell", what a stale or foreign pid returns AND IT EARNS ITS PLACE, which the matrix now shows: M0 no mutation 0 red M1 diagnosis before the branch, fatal 1 -- the new case M2 same position, || true removed 1 -- the new case M3 diagnosis removed entirely 1 -- the diagnosis reaches stderr M4 diagnosis shown on success too 1 -- success stays quiet M5 failure arm no longer reaps 1 -- the new case M5 is the one that matters here. Status stays 0, stdout stays "000", the work_dir is still gone -- the three assertions I had left would all be green on a build that never reaps. The seam is what tells them apart. M1 and M2 redden through the same case for the opposite reason: a fatal `cat` exits before the seam is reached, so nothing is recorded. The boundary narrows accordingly. What #864 still holds is the OTHER early-exit routes, signals in particular; that this PR's failing-diagnosis route reaches kill and wait is measured here, not deferred. 8 ok / 0 not ok; 22 across the three files covering this helper.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Declared reviewers: 1
Describes head
c7f9010c996378e0b5092bbf8ee01d5f2ff91886, based onmainatdd61c04.This replaces #853, which GitHub closed and will not reopen. When #886 merged, its branch was deleted; GitHub closes any PR stacked on a deleted base, and once the head has been force-pushed it refuses to reopen ("the branch was force-pushed or recreated"). Same branch, same work, same review thread contents — copied below so nothing is lost — but the number changes.
The earlier CLEARED verdict is void, and not only because of the renumbering: rebasing onto
mainchanged every commit SHA. The four commits are identical in content to the ones reviewed at597d345; the tree is the same work applied to amainthat now contains #886, #895 and #899.Where it stands after the rebase
The rebase was structurally required, not a preference: the old merge-base was #886's pre-merge head, which is not an ancestor of
main.(Everything below is the body as it stood on #853, kept verbatim. Its head references are historical — the current head is the one named above.)
Part 3 of 3 splitting the Windows connect fix. All three together are on
win-connect-fix-850, which is the branch to install for a real walk.This is the one that made the other two findable. Landing it separately is the point: without it the next failure in this family is another opaque
000.What is wrong
_remote_http_post_jsonsent curl's stderr to/dev/nulland reported000for every kind of failure alike. The caller sees only that code, so when a request failed there was nothing anywhere saying why.That cost the Windows run a long time:
connectreturned a bare000, and the reason — curl could not open a path embedded in its own config file — was in the stderr this line was discarding.Captured to a file rather than passed straight through, and shown only when curl actually failed: on the success path
curl -sSis already silent, and an unconditional pass-through would put curl's output in the middle of a caller's.Scope, stated because it is narrower than the reasoning
This fixes the POST helper only, which is what the verified Windows commit changed.
_remote_http_get_jsonstill carries2>/dev/null, and the same argument applies to it —pullgoes through the GET path, so a failure there is still an opaque000with the reason discarded. It embeds no paths in its config, so PR-A's defect does not reach it, but the diagnosability one does.Left out deliberately rather than folded in: this PR carries what was measured on the Windows machine, and extending it here would mix verified work with unverified. Worth a follow-up.
What was verified on Windows 11 / Git Bash
Quoted rather than summarised:
What was verified on macOS, and what that is worth
tests/test_remote.bats— 122 ok / 0 not ok, on this branch alone.Green was not evidence anything was diagnosed. When this was written, no test in the suite asserted on curl's stderr — that is no longer true, and the tests added since are described at the end of this body. What green establishes is that capturing it, and emitting it only on failure, leaves every existing caller's behaviour and every reported HTTP code unchanged.
Not measured
A team with an existing store has not been migrated on Windows. The verified run was a fresh team.
Tests, added at
adbf2b34d74ftests/test_remote_curl_stderr.bats— 5 ok / 0 not ok, driving the production_remote_http_post_json. Production is untouched; the diff since the reviewed head is this one file.The helper's stderr is captured to a file rather than read from bats's
$output, which merges the streams. The http code goes to stdout and the diagnosis has to go to stderr — a test that cannot tell them apart cannot check that.The second row is the one that needs explaining. Real
curl -sSis quiet on success, so a stub that also stayed quiet would pass against a version that dumped stderr unconditionally — and that version drops noise into the middle of a caller's output. Making the stub noisy on success is what separates "shown only when curl failed" from "the stream happened to be empty".The last row is the control on an absence: a glob that matches nothing looks exactly like a glob aimed at the wrong directory.
2>/dev/nullrestoredNot covered
The signal path. The scratch file is removed on both normal paths, and the trap set earlier in the function does not name it — its list is the config and the fifo. That is a reading of the trap's text, not a measurement: I tried to drive a signal through it and the probe hung on this host, because the bounded copier keeps the run alive while curl is being waited on.
Adding
curl_errto that trap is one line, but it changes the fix rather than testing it, so it is the author's call rather than mine.Windows is unverified by me, here as elsewhere in this series.
Tests and one further production change, at
d59284c11e38Review asked for one line — put
curl_errin the existing trap so an early exit cannot strand it. I wrote that line, added a test for it, and the test failed. What the measurement then said is why this head carries more than tests.An EXIT trap set inside a function cannot read that function's locals
It runs after the frame is gone, so a single-quoted body expands
$cfgin the caller's scope, where no local of that name exists. It removes the empty string, returns 0, and reads as a cleanup that worked.So this was never about
curl_err. The pre-existing trap has never swept anything on an early exit. Driven with a stub curl that fails after writing its headers and acatthat fails, so errexit leaves the function between the mktemp and the tail cleanup, a real run left all three behind:The config is the one that matters — it is the file this helper exists to keep out of curl's argv.
The fix: bake the paths into the trap with
printf %qat set time instead of expanding them when it fires, and createcurl_errwith the other temporaries so it exists before the trap that must remove it. Same run afterwards leaves nothing. This is more than the one line asked for, and the reason is that the one line does not work; the tests bind the behaviour, not the mechanism, so a different shape is open to the author.tests/test_remote_curl_stderr.bats— 7 ok / 0 not okprintf %qbaking is not mistaken for ceremony and simplified back2>/dev/nullrestoredExisting suite unchanged on this head:
tests/test_remote.bats— 122 ok / 0 not ok.The early-exit case took three attempts, and each failure is worth naming
catthrough the sandbox symlink.>follows a symlink, so it wrote to the system's own/bin/cat— refused by the OS here. On a machine where it was not refused, the test would have replaced a system binary. The symlink is removed first now.open()and hangs for the same reason as (1). The stub now writes headers and then fails, which is what a real curl does when it dies on the body.Windows is unverified by me.
Update at
a38d6f8e1430— one directory, armed before anything else existsReview's remaining point: whatever is created before the trap is armed is unprotected, and the previous shape kept that window — it made three things and then armed a trap over all three. A failure at the second or third strands the first, including a 0600 config naming the request body.
Reordering cannot close it, because there is always a first allocation. So there is now exactly one:
Everything else is made inside a directory that is already condemned; the normal path removes the same directory. The
printf %qbaking stays, for the measured reason above.New case: make
mkfifofail — after the directory exists and after the config is inside it — and assert nothing survives.And four of my absence assertions were aimed at names that no longer exist
The leftover checks globbed
agmsg-curl-cfg.*andagmsg-curl-err.*. This layout never creates those. They would have passed on any behaviour, and gone on passing while the new directory leaked. Both they and their planted-leftover control now use the name the helper really mints.An absence assertion pointed at a name nothing uses is indistinguishable from a clean run — and I wrote four of them without noticing the rename I had just made underneath.
Filed separately, not folded in
On the failure path the bounded copier is not reaped when the function leaves early, and it holds the caller's inherited stdout — which is what hung three of my probes. It predates the stderr work, so it is #864 rather than a change here.
Rebuilt on current main at
edcebc597e39bd7959ddfe77f516050517810477The earlier verdicts on this PR are void. Everything above describes heads that predate #868, which landed the header-sink work and gave this helper two arms. Drift against today's
mainwas NON-EMPTY — 213 insertions inscripts/remote.sh, the one file this changes, so the branch was rebuilt rather than rebased.Base is now
fix/curl-tests-read-merged-stream(#886), and that is a real dependency, not tidiness — measured in both directions below.What this adds to main
Curl's stderr is kept and shown when curl actually failed. The caller only ever sees the HTTP code, and this helper reports
000for every kind of failure alike — refused connection, timeout, a path curl could not open. Shown only on failure:curl -sSis silent on success, so an unconditional dump would land in the middle of a caller's output.What it simplifies
All temporaries move into one directory, minted before the trap is armed:
Two reasons, both measured earlier in this series:
$cfgexpands in the caller's scope and removes"".bash 3.2.57and5.3.15both report EMPTY.printf %qfixes the value at set time.It also removes a hazard instead of guarding it. main carries a comment warning that on the marker path
header_fifoISheader_file, so an unconditionalrm -f "$header_fifo"would delete the headers the caller asked for. The caller's file is outsidework_dir, sorm -rfcannot reach it — the guard becomes a property of the layout. Two traps become one andfifo_dirdisappears.The dependency on #886, measured both ways
tests/test_remote_curl_config_paths.batscompares bats's$output— stdout and stderr merged — against"000". Showing curl's diagnosis puts a line in front of the code. That test is already intermittently red on main for the same reason under CI load; this change turns intermittent into certain. #886 is a prerequisite.Tests
tests/test_remote_curl_stderr.bats— 8 ok / 0 not okmkfifofails after the directory exists — nothing survives22 ok / 0 not ok across this file and the two already covering this helper (
test_remote_header_sink.bats,test_remote_curl_config_paths.bats).Windows is unverified by me. Related: the header copier is not reaped on an early exit (#864).
Current head:
f94c333f28c7731c2b35d1e8d56b224c37c9685cTwo review rounds since
edcebc5. Both changed what this PR claims, so the section above is history and this one is the state.The diagnosis line was itself an exit
Under
set -ea failingcat— closed stderr, a reader that went away, a full disk — ends the function there. The copier is never reaped, thework_diris never removed, and the caller gets nothing where this helper promises000for every failure. Being unable to explain a failure turned it into a different failure.And the test I shipped asserted that. It drove a failing
cat, asserted nonzero status and empty stdout, and its own comment noted the copier was left orphaned. It measured the defect and called it the property; the reviewer read the test as the specification, which is what a test is.Now: reap and decide first, then write the diagnosis best-effort. Same case, contract the other way round.
|| trueremovedM1 and M2 redden separately, so position and best-effort are bound apart.
What this case does NOT assert, and why
The second round questioned the copier check I added: it passed vacuously on an empty record, and its teardown killed by remembered PID — a number the kernel may reuse, so the fixture could have signalled an unrelated process on the runner.
Fixing it properly produced a finding. Four instruments, each failing its own positive control:
pgrep -f <full script path>pgrep -f bounded-copy.pylsof +D <work dir>open()holds no fd on it yetOne fact explains all four: a copier waiting on the fifo is still a forked
bashwearing its parent's command line — measured,commreadsbash— because python3 is not exec'd until curl opens the pipe. It is identifiable as a child of that shell and by nothing else, and after the shell exits, not even that.A fifth attempt — running the driven shell in its own process group, so the group could be the identity — hung the harness, the same way three earlier probes in this series died: the orphan holds the capture pipe.
So the assertion is removed rather than left as a green that measures nothing, and the case carries all of the above where the next person will be tempted to add it back. The reaping is in production (kill, then wait, before the code is returned); what is unproven is the absence of a survivor, and that behaviour is already filed as #864.
Still asserted
tests/test_remote_curl_stderr.bats— 8 ok / 0 not ok. Base remains #886, for the reason measured above.Current head:
597d345525efb1b5401b167ac38fdffd973b90feThe section above says the absence of a survivor cannot be measured. That was wrong, and the reviewer named the identity I had not used: the helper's own child table.
Every instrument I tried looked for the copier in the process table after the fact. All four failed for one reason — a copier waiting on the fifo is still a forked
bashwearing its parent's command line, because python3 is not exec'd until curl opens the pipe. Nothing outside can name it.But
waitis a builtin over the shell's own waitable children. A successful wait is the observation, and it needs no identity of its own.So the driven shell shadows
killandwait, records the pid each was given, and delegates to the builtins. Production runs unchanged; only the seam is recorded.It earns its place
|| trueremovedM5 is the one that matters. Status stays
0, stdout stays"000", thework_diris still gone — every assertion this case had before would be green on a build that never reaps. The seam is what tells them apart.M1 and M2 redden through the same case for the opposite reason: a fatal
catexits before the seam is reached, so nothing is recorded.The boundary, narrowed
#864 still holds the other early-exit routes — signals in particular, where the trap removes files and does not kill a process. That this PR's failing-diagnosis route reaches
killandwaitis measured here rather than deferred.tests/test_remote_curl_stderr.bats— 8 ok / 0 not ok; 22 ok / 0 not ok across the three files covering this helper. Base remains #886.