Skip to content

Commit 9bfacbc

Browse files
frangarcjfrangarcj
committed
Name the end of the pipeline that actually broke
Windows failed twice this month at the same line, and both logs said the same thing: bin/makepkg.conf: Write error: Broken pipe That is bsdtar, naming whatever file it happened to be reading when its output closed. The file was fine. What broke was the other end -- most likely xz, killed for memory during a silent three-minute -9 over the core payload -- and a process the kernel kills leaves no message at all, so nothing in the log was about it. Under pipefail the failing status does surface; the text does not, because it belongs to whichever element noticed first, and that is never the one that died. So both compression pipelines now capture PIPESTATUS and report every element that failed, by name, and a status above 128 as the signal it is. The status the caller sees is unchanged: report_pipeline returns the last failing one, which is what pipefail would have given it. Simulated by putting an xz on PATH that dies mid-write, against tests/package/test-core-package.sh: before : Write error (and a job-control dump) after packaging vdpm-…pkg.tar.xz: bsdtar exited 1 packaging vdpm-…pkg.tar.xz: xz killed by signal 9 both exiting 137. tests/ci/test-pipeline-report.sh drives the function the script defines, not a copy: silence when nothing failed, the killed compressor with its signal, the upstream SIGPIPE reported too, an ordinary exit as an exit, an element past the names given, and the status preserved.
1 parent 8df1099 commit 9bfacbc

2 files changed

Lines changed: 140 additions & 0 deletions

File tree

‎scripts/create-core-package.sh‎

Lines changed: 44 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -106,6 +106,40 @@ for path in ${client_paths[@]+"${client_paths[@]}"}; do
106106
mv "$core_root/$path" "$client_root/$path"
107107
done
108108

109+
# Which end of a compression pipeline actually broke.
110+
#
111+
# Under pipefail a failing status surfaces, but the text does not: whichever
112+
# element notices first is the one that speaks, and that is never the one that
113+
# died. When xz goes, bsdtar reports "Write error: Broken pipe" against
114+
# whatever file it happened to be reading when its output closed -- and xz
115+
# says nothing at all if the kernel killed it for memory, which is what -9
116+
# over the core payload invites. So name every element that failed, and how.
117+
report_pipeline() {
118+
local description=$1 name status index=0 failed=0
119+
shift
120+
local -a names=()
121+
while [[ $1 != -- ]]; do
122+
names+=("$1")
123+
shift
124+
done
125+
shift
126+
for status in "$@"; do
127+
name=${names[index]:-element $((index + 1))}
128+
index=$((index + 1))
129+
((status == 0)) && continue
130+
# The last failing element's status, which is what pipefail would
131+
# have surfaced: this says more than that, it does not say less.
132+
failed=$status
133+
if ((status > 128)); then
134+
printf '%s: %s killed by signal %d\n' \
135+
"$description" "$name" "$((status - 128))" >&2
136+
else
137+
printf '%s: %s exited %d\n' "$description" "$name" "$status" >&2
138+
fi
139+
done
140+
return "$failed"
141+
}
142+
109143
set_tree_mtime() {
110144
local root=$1 timestamp
111145
if touch -h -d "@$source_date_epoch" "$root/.PKGINFO" 2>/dev/null; then
@@ -171,22 +205,32 @@ EOF
171205
set_tree_mtime "$root"
172206
(
173207
cd "$root"
208+
set +e
174209
list_package_files .MTREE | LC_ALL=C sort -z |
175210
COPYFILE_DISABLE=1 LANG=C bsdtar -cnf - --format=mtree \
176211
--no-acls --no-fflags --no-mac-metadata --no-xattrs \
177212
--options='!all,use-set,type,uid,gid,mode,time,size,sha256,link' \
178213
--uid 0 --gid 0 --null -T - |
179214
gzip -c -f -n > .MTREE
215+
statuses=(${PIPESTATUS[@]+"${PIPESTATUS[@]}"})
216+
set -e
217+
report_pipeline "writing .MTREE" \
218+
list_package_files sort bsdtar gzip -- ${statuses[@]+"${statuses[@]}"}
180219
)
181220
set_tree_mtime "$root"
182221

183222
(
184223
cd "$root"
224+
set +e
185225
list_package_files | LC_ALL=C sort -z |
186226
COPYFILE_DISABLE=1 LANG=C bsdtar -cnf - \
187227
--no-acls --no-fflags --no-mac-metadata --no-xattrs \
188228
--uid 0 --gid 0 --uname root --gname root --null -T - |
189229
xz -c -z -9 > "$path"
230+
statuses=(${PIPESTATUS[@]+"${PIPESTATUS[@]}"})
231+
set -e
232+
report_pipeline "packaging ${path##*/}" \
233+
list_package_files sort bsdtar xz -- ${statuses[@]+"${statuses[@]}"}
190234
)
191235

192236
"$script_directory/validate-core-package.sh" "$path"

‎tests/ci/test-pipeline-report.sh‎

Lines changed: 96 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,96 @@
1+
#!/usr/bin/env bash
2+
# When a compression pipeline breaks, say which end broke.
3+
#
4+
# Under pipefail the failing status surfaces, but the message belongs to
5+
# whichever element noticed first, and that is never the one that died: when
6+
# xz goes, bsdtar reports "Write error: Broken pipe" against whatever file it
7+
# was reading, and a compressor the kernel killed for memory leaves no
8+
# message at all. Every log of this failure so far has named bsdtar and a
9+
# file that was fine.
10+
11+
set -euo pipefail
12+
13+
repository_root=$(cd "$(dirname "${BASH_SOURCE[0]}")/../.." && pwd -P)
14+
script="$repository_root/scripts/create-core-package.sh"
15+
16+
failures=0
17+
18+
# The function as the script defines it, not a copy of it here.
19+
report()
20+
{
21+
bash -c '
22+
set -uo pipefail
23+
'"$(sed -n '/^report_pipeline()/,/^}/p' "$script")"'
24+
report_pipeline "$@"
25+
' report "$@" 2>&1
26+
}
27+
28+
check()
29+
{
30+
local description=$1 expected=$2
31+
shift 2
32+
local actual status=0
33+
actual=$(report "$@") || status=$?
34+
case $expected in
35+
ok)
36+
if ((status != 0)) || [[ -n $actual ]]; then
37+
printf 'FAIL: %s\n status %s, said: %s\n' \
38+
"$description" "$status" "$actual" >&2
39+
failures=$((failures + 1))
40+
fi
41+
;;
42+
*)
43+
if ((status == 0)); then
44+
printf 'FAIL: %s was reported as success\n' "$description" >&2
45+
failures=$((failures + 1))
46+
elif [[ $actual != *"$expected"* ]]; then
47+
printf 'FAIL: %s\n expected to contain: %s\n said: %s\n' \
48+
"$description" "$expected" "$actual" >&2
49+
failures=$((failures + 1))
50+
fi
51+
;;
52+
esac
53+
}
54+
55+
check "a pipeline where nothing failed says nothing" ok \
56+
packaging a b c xz -- 0 0 0 0
57+
58+
# The case this exists for. 137 is SIGKILL, which is what the kernel's
59+
# out-of-memory killer leaves behind, and it leaves nothing else.
60+
check "a compressor killed for memory is named, with its signal" \
61+
"xz killed by signal 9" \
62+
packaging list_package_files sort bsdtar xz -- 141 0 141 137
63+
64+
# And the message that used to be the only one must not be the headline: the
65+
# upstream SIGPIPE is a consequence, so it may be reported, but the killed
66+
# element has to be there too.
67+
actual=$(report packaging list_package_files sort bsdtar xz -- 141 0 141 137 || true)
68+
if ! grep -q 'bsdtar killed by signal 13' <<<"$actual"; then
69+
printf 'FAIL: the elements that took the SIGPIPE are not reported\n' >&2
70+
failures=$((failures + 1))
71+
fi
72+
73+
check "an ordinary non-zero exit is reported as an exit" \
74+
"gzip exited 1" \
75+
"writing .MTREE" list_package_files sort bsdtar gzip -- 0 0 0 1
76+
77+
check "an element beyond the names given is still reported" \
78+
"element 5 exited 2" \
79+
packaging a b c d -- 0 0 0 0 2
80+
81+
# The status pipefail would have surfaced is still the status: a caller that
82+
# was reading 137 out of this keeps reading 137.
83+
status=0
84+
report packaging list_package_files sort bsdtar xz -- 141 0 1 137 >/dev/null 2>&1 ||
85+
status=$?
86+
if ((status != 137)); then
87+
printf 'FAIL: the last failing status is not preserved\n expected 137, got %s\n' \
88+
"$status" >&2
89+
failures=$((failures + 1))
90+
fi
91+
92+
if ((failures)); then
93+
printf '%d pipeline report check(s) failed\n' "$failures" >&2
94+
exit 1
95+
fi
96+
printf 'pipeline failure reporting: all checks passed\n'

0 commit comments

Comments
 (0)