Files
ducoterra ac2f310d10 Say what an image build is doing, and keep saying it
A build is the slow part of a first run and the thing --install triggers: apt, a Node
tarball, an npm install. Every byte of podman's transcript used to go to a log file, so
minutes of silence looked exactly like a wedge -- and a wedge is what people interrupt,
leaving a half-built image.

One line per build step, plus a notice every AISB_BUILD_QUIET_SECS (15) that a step has
shown the terminal nothing, whether it is producing output the view drops or no output at
all. AISB_BUILD_OUTPUT=progress|full|quiet picks how much the terminal sees; the complete
transcript stays in $AISB_STATE_DIR/build-*.log in all three, because the progress view is
a filter and a failed build has to be diagnosable from the raw apt output. The first line
names the extra packages going in, which is what answers "why is this run building when
the last one did not".

podman build writes its transcript to *stdout* -- the same stdout the
$(ensure_image ...) call reads back as the image ref -- so the transcript is routed onto
stderr and the ref stays one clean line. A failed build now names the package apt could
not find instead of pointing at a file to go read, and reports the time it took.
Resolving a digest by pulling the base says so too: that is a download of the base image.

tests/unit/11_build.sh stubs podman for both heartbeat paths and checks the ref, the
failure text and that a canary credential appears nowhere.

LLM-Generated: true
2026-10-30 22:53:57 -04:00

167 lines
8.6 KiB
Bash
Executable File

#!/usr/bin/env bash
# tests/unit/11_build.sh -- feedback while an image is being built.
#
# The bug this file exists for: a build is the slow part of a first run and the thing
# --install triggers, and every byte of podman's transcript used to go to a log file.
# Minutes of silence reads as a hang. So these tests ask the running script what a user
# would see, with a stub for podman rather than a container.
#
# The stub stands in for the two behaviours of the real thing that this file is about:
# 'image exists' answers no, so a build is needed, and 'build' writes its transcript to
# *stdout* (measured on podman 5: that is where podman build writes) -- which is the one
# thing the script must never let reach its own stdout, because ensure_image()'s stdout
# is read back as the image ref.
source "$TESTS/lib.sh"
PROJ="$WORK/proj"; mkdir -p "$PROJ"; cd "$PROJ" || exit 1
BIN="$WORK/bin"; mkdir -p "$BIN"
cat > "$BIN/podman" <<'EOS'
#!/usr/bin/env bash
case "${1:-} ${2:-}" in
"image exists") exit 1 ;;
"build -t")
# what the build was invoked with, so a credential smuggled into a --build-arg
# shows up in the transcript and the canary test below fails
printf 'STUB-BUILD-ARGS: %s\n' "$*"
# the packages the build was actually handed, read back out of --build-arg, so this
# transcript names what the policy under test asked for instead of a fixed guess
pkgs=""
for a in "$@"; do
case "$a" in AISB_EXTRA_PACKAGES=*) pkgs="${a#*=}" ;; esac
done
printf 'Trying to pull docker.io/library/ubuntu:24.04...\n'
printf 'Getting image source signatures\n'
printf 'STEP 1/3: FROM docker.io/library/ubuntu:24.04\n'
printf 'STEP 2/3: RUN apt-get update && apt-get install -y%s\n' "${pkgs:+ $pkgs}"
for ((i = 0; i < "${AISB_STUB_NOISE:-20}"; i++)); do
printf 'Get:%d http://archive.ubuntu.com/ubuntu noble/main amd64 curl amd64 8.5.0-1 [11 MB]\n' "$i"
sleep "${AISB_STUB_NOISE_DELAY:-0}"
done
sleep "${AISB_STUB_SLEEP:-0}"
if [[ "${AISB_STUB_RC:-0}" != 0 ]]; then
printf 'Reading package lists...\n'
for p in $pkgs; do printf 'E: Unable to locate package %s\n' "$p"; done
printf 'Error: building at STEP "RUN apt-get install": while running runtime: exit status 100\n'
exit "${AISB_STUB_RC}"
fi
printf '%s\n' '--> 1234567890ab'
printf 'STEP 3/3: CMD ["bash", "-li"]\n'
printf 'COMMIT localhost/ai-sandbox:stub\n'
printf 'Successfully tagged localhost/ai-sandbox:stub\n'
printf 'abc123def\n'
;;
*) exit 0 ;;
esac
EOS
chmod +x "$BIN/podman"
export PATH="$BIN:$PATH"
# node_sha256() fetches from nodejs.org; a unit test never touches a registry.
export AISB_NODE_SHA256=0000000000000000000000000000000000000000000000000000000000000000
# The transcript path the last run announced, which is the only way a test is supposed
# to find it -- and naming it is itself part of the feedback under test.
last_transcript() { printf '%s' "$OUT" | sed -n 's/^ai-sandbox: build: [^ ]* (transcript: \(.*\))$/\1/p' | head -1; }
log_says() { # log_says <needle> <label>
local f; f="$(last_transcript)"
if [[ -n "$f" && -r "$f" ]] && grep -qF -- "$1" "$f"; then _ok "$2"
else _bad "$2" "not in ${f:-no transcript was named}"; fi
}
log_lacks() { # log_lacks <needle> <label>
local f; f="$(last_transcript)"
if [[ -n "$f" && -r "$f" ]] && grep -qF -- "$1" "$f"; then _bad "$2" "present in $f"
else _ok "$2"; fi
}
t_name "a build says what it is doing instead of sitting silent"
sb_env AISB_INSTALL="rustc,cmake" build
assert_rc 0 "ai-sandbox build runs against the stub podman"
assert_contains "building the sandbox image with 2 extra package(s): rustc cmake" \
"it names the extra packages, which is why this run builds and the last did not"
assert_contains "one build per policy change" "and says the build is not repeated"
assert_contains "build: [1/3] FROM" "one line per build step, in order"
assert_contains "build: [2/3] RUN apt-get" "including the slow one"
assert_contains "build: [3/3]" "to the last step"
assert_contains "Trying to pull" "the base download before the first step is visible too"
assert_contains "COMMIT localhost/ai-sandbox:stub" "and the commit that names the image"
assert_contains "built localhost/ai-sandbox:" "and that it finished"
t_name "the transcript is kept in full, and named"
assert_contains "transcript: $WORK/state/build-sandbox-" "the run says where the full log is"
log_says "STUB-BUILD-ARGS:" "the log starts at the beginning of the build"
log_says "Get:1 http://archive.ubuntu.com" "the apt output that was filtered out is in the log"
log_says "Successfully tagged" "and so is the end of it"
t_name "apt's own noise is not what the terminal gets"
assert_absent "Get:1 http://archive.ubuntu.com" "a hundred lines of package lists stay in the log"
assert_absent "abc123def" "and so does the image id podman prints at the end"
t_name "the build transcript never becomes part of the image ref"
# The reason for the routing: ensure_image() is called as $(...), so podman build's
# stdout would come back spliced into the ref and into every 'podman run' after it.
rc=0; "$AISB" build > "$WORK/out" 2> "$WORK/err" || rc=$?
assert_eq 0 "$rc" "the build itself succeeded"
if [[ -s "$WORK/out" ]]; then
_bad "not one line of it lands on stdout" "$(head -2 "$WORK/out")"
else
_ok "not one line of it lands on stdout"
fi
if grep -qxE 'ai-sandbox: built [A-Za-z0-9./:@_+-]+ in [0-9]+s' "$WORK/err"; then
_ok "the ref it reports is still one clean line"
else
_bad "the ref it reports is still one clean line" "$(grep built "$WORK/err" | head -2)"
fi
t_name "a build with nothing new to show still says it is working (filtered output)"
# apt streaming 6 lines at 400ms apart is two and a half seconds of output the progress
# view deliberately drops: the heartbeat has to come from the clock, not from a read timeout.
sb_env AISB_BUILD_QUIET_SECS=1 AISB_STUB_NOISE=6 AISB_STUB_NOISE_DELAY=0.4 build
assert_rc 0 "a build that only takes a couple of seconds still succeeds"
assert_contains "still on [2/3]" "it names the step it is waiting on"
assert_contains "total)" "and how long the build has taken"
assert_absent "Get:3 http://archive.ubuntu.com" "without giving up the filtering to do it"
t_name "a build producing no output at all says it is working"
sb_env AISB_BUILD_QUIET_SECS=1 AISB_STUB_NOISE=0 AISB_STUB_SLEEP=3 build
assert_rc 0 "a build with a silent step succeeds"
assert_contains "still on [2/3]" "the heartbeat covers a step that says nothing either"
t_name "AISB_BUILD_OUTPUT=full puts the whole transcript on screen"
sb_env AISB_BUILD_OUTPUT=full build
assert_rc 0 "full output is not an error"
assert_contains "Get:1 http://archive.ubuntu.com" "the raw apt lines are shown as they come"
assert_contains "Successfully tagged" "all the way to the end"
assert_absent "still on [2/3]" "and nothing is summarised, so no heartbeat is needed"
t_name "AISB_BUILD_OUTPUT=quiet keeps the terminal clean and the log complete"
sb_env AISB_BUILD_OUTPUT=quiet build
assert_rc 0 "quiet is not an error"
assert_absent "STEP 2/3" "no step lines"
assert_absent "Get:1 http://archive.ubuntu.com" "no apt output"
assert_contains "transcript: $WORK/state/build-sandbox-" "it still says where the build went"
assert_contains "built localhost/ai-sandbox:" "and that it finished, with the time it took"
log_says "Get:1 http://archive.ubuntu.com" "quiet does not mean the transcript is lost"
t_name "a failed build names the package apt could not find"
sb_env AISB_STUB_RC=100 AISB_INSTALL="not-a-real-package" build
assert_rc 1 "a failed build fails the run"
assert_contains "no such apt package: not-a-real-package" \
"it names the package, instead of pointing at a file to go read"
assert_contains "E: Unable to locate package" "the failing lines are quoted back even in progress mode"
assert_contains "Error: building at STEP" "and the step that died is one of them"
assert_absent "built localhost/ai-sandbox" "it does not claim a build that did not happen"
t_name "a build mode that does not exist is reported, not obeyed blindly"
sb_env AISB_BUILD_OUTPUT=loud AISB_BUILD_QUIET_SECS=nope build
assert_rc 0 "a bad value is not fatal"
assert_contains "AISB_BUILD_OUTPUT='loud' is not progress, full or quiet" "it says the mode is not usable"
assert_contains "AISB_BUILD_QUIET_SECS='nope' is not a number" "and the same for the threshold"
assert_contains "build: [1/3]" "and it carries on with the default view"
t_name "nothing a build prints or writes carries a credential value"
CANARY="canary-token-value-4f2a9c"
sb_env AI_API_TOKEN="$CANARY" AISB_INSTALL="curl,jq" build
assert_rc 0 "the build ran"
assert_absent "$CANARY" "the token value is not printed"
log_lacks "$CANARY" "the build transcript holds no credential either"