Pipefail turned success into failure
My installer kept reporting that an agent had not loaded, when it had, because its check found the answer too fast for pipefail.
By Andrew Pyle
Some shell bugs only appear when a command succeeds faster than the one feeding it.
01A warning that lied
Loaded, and reported missing
The installer's last line was a warning: the agent's label, then "is not in launchctl list". The exit status was 1.
I install my launchd agents with small shell scripts, and the last thing each one does is check its own work. It asks launchd for the list of loaded agents and looks for the label it just installed. If the label is there, the script prints a verified line and exits cleanly. If not, it warns and fails.
On October 12th that check failed for an agent I had just installed. When I ran launchctl list myself, the agent was right there: registered, with a last exit status of 0. launchd said it was loaded and healthy. The script that loaded it said it did not exist.
02Ten out of ten
The cause was a signal
The obvious suspect for a check like this is timing: the script looked before launchd had finished registering the agent. Timing would predict a flaky failure, some runs passing and some failing. So I ran the old check ten times, and it missed ten out of ten. Then I ran the same check with pipefail turned off, and it found the agent ten out of ten.
The difference was a shell option. The scripts run with set -o pipefail, which makes a pipeline fail if any command in it fails, instead of reporting only the last one. The check itself was one line: launchctl list piped into grep -q for the label. On every miss, the pipeline's exit statuses, which bash keeps in PIPESTATUS, came back as 141 and 0. grep had succeeded. The command feeding it had not.
set -o pipefail
launchctl list | grep -q "$LABEL" # the old check
echo "${PIPESTATUS[@]}"
# 141 0What exit 141 means
Exit status 141 is 128 plus 13, and signal 13 is SIGPIPE. grep -q exits on its first match and closes its end of the pipe. launchctl list was still writing the rest of the list, and with no reader left, the write killed it with a broken-pipe signal. pipefail then reported that signal as the pipeline's failure. The check failed because grep found the answer before the list was done.
03Remove the pipe
Ask launchd the question directly
The check never needed a pipe. launchctl list accepts a label and answers for that one agent. The new check runs launchctl list with the label, throws the output away, and treats the exit status as the whole answer. I verified that contract both ways: it exits 0 when the label is loaded and 113 when it is not. Under pipefail, the new check found a loaded agent ten out of ten times and reported a missing label as missing ten out of ten times.
# the new check: ask launchd about one label, no pipe
launchctl list "$LABEL" >/dev/null 2>&1
# exits 0 when the label is loaded, 113 when it is notThe same old line was in 27 installer scripts, plus one line in the script that bootstraps a new Mac. The change was the same one line in each place, with 29 files changed and about 30 lines in all. I did not re-run the 27 installers, because re-running them would reload live agents. Each edited script passes a bash syntax check, and all of the testing happened on macOS, on one machine.
04Keep it out
A guard for one string
A one-line pattern that was copied into 28 places will get copied again. So there is now a test that scans every shell script under the scripts folder for the literal string launchctl list | grep -q. It skips comment lines and lines that only echo text, and when it finds an offender it fails with the file, the line number, and the suggested replacement. To prove it could fail, I stashed the script changes and watched it go red on the old versions.
The change took 30 minutes from opening to merge, the day after the false warning showed up. The benefit is modest and concrete. Runbooks, and I, stop chasing failures that are not there. One check is still pending. The original installer gets re-run after deploy, where it should print its verified line and exit 0, and I have not recorded that run yet.
Pipefail is still the right default for my scripts. What I misjudged was what a reader like grep -q does to the command upstream of it. Any reader that stops early can make the writer before it die, and pipefail will report that death as a failure. Before I put a pipe in a check now, I ask whether the question can be asked directly.
Related
writing
A limit that was never enforced
Eighty of my scheduled tasks ran on a time limit different from the one they declared, because the loader quietly threw it away, and the first plan I built on those numbers was wrong.
writing
A deploy should drain, not kill
A routine deploy quietly ate a day of work, and the monitor that was supposed to notice reported nothing wrong.
writing
A cold cache is not free
My feature-flags page felt instant once I cached it, and the first request to each fresh worker after a deploy still paid about fifteen seconds.
writing
A 200 is not the same as access
My leak probe failed with seventeen leaks on its first real run. Every one of them was the same page that was never a leak.
writing
The grep that matched itself
My cleanup script decided every checkout was in use, including the ones that were plainly idle.