Linux & Bash · Part II · Module 33 · Debugging Failed Jobs and Broken Flows
Was It the Design, the Tool, or the Script?
A failing run hands you a log, and the log is usually the least useful thing about it. This chapter builds three failures with completely different causes that produce byte-identical logs, measures the two obvious ways of telling them apart and finds both unsound, and then builds the triage that works — before any waveform is opened.
Advanced27 min readLinuxPart IIDebuggingTriageBuild
Part II · Module 33 · Chapter 33.1 · Was It the Design, the Tool, or the Script?
Module 32 built a regression that reports fifteen runs as not-a-pass and hands you a log for each. This module is about the next step, and it opens with the observation that makes the whole module necessary:
the log tells you what happened inside the simulation, which is only one of the places the failure can be.
1. One Log, Three Causes
Here is a failing run from the fixture. The test prio0 checks that agent 0 wins the first contention on a two-request arbiter:
TB test=prio0 seed=1 cycles=200 verbosity=LOW
TB ERROR t=35 gnt=10 expected 01
TB TEST FAILED test=prio0 checks=1 errors=1
tb/tb_arb.v:152: $finish called at 35 (1s)That is as clear a design-bug report as a log can produce. A named check, a time, an expected value, an actual value. Everything about it says open the waveform at t=35.
Now here are three situations, each of which produced exactly that log:
A — the design really is broken. The arbiter resets with last = 0, so under req = 2'b11 it grants agent 1 first. The test is right and the RTL is wrong.
B — the source was fixed and nobody rebuilt. rtl/arb.v now carries the fix. The compiled image does not, because it was built before the edit. The run tested code that no longer exists.
C — the source was fixed, the image was rebuilt, and the wrapper ran a different image. A path left over from an experiment, pointing at an older build.
$ md5 -q cap/A/run.log cap/B/run.log cap/C/run.log | sort -u | wc -l
1One distinct hash. Not similar — identical, to the byte.
2. The First Obvious Technique, Measured
If the question is "was this image built from today's sources", the obvious answer is to build today's sources and compare:
$ iverilog -o /tmp/fresh.vvp tb/tb_arb.v rtl/arb.v
$ md5 -q /tmp/fresh.vvp
$ md5 -q logs/sim.vvp # the same? then the image is currentThat is what I wrote first, and it reported every image as stale — including one built seconds earlier from unchanged sources. So I measured the compiler:
=== build the SAME sources three times, compare ===
build 1: 651e3cee1cba40c42538f8fa969f8a8d 27979 bytes
build 2: 633e04c3bd5894d8ac06e884bd9c90d0 27979 bytes
build 3: b83008632fe347299e1982e06b0e434c 27979 bytes
distinct: 3Three builds of identical sources give three different digests. Same length, different content:
differing bytes: 1084 of 27979And the differing region says why:
ebrew/Cellar/icarus-verilog/13.0/lib/ivl/va_math.vpi";
S_0x7a5080000 .scope module, "tb_arb" "tb_arb" 2 3;
.timescale 0 0;
v0x7a50743c0_0 .S_0x7a5080000 and v0x7a50743c0_0 are memory addresses. The vvp assembly names its scopes and variables after the compiler's own heap pointers, which move between runs. So the output is not a function of the input, and comparing a rebuilt artifact against a stored one cannot work.
This is not an Icarus peculiarity to be shrugged at. Reproducible builds are a goal that most toolchains have not reached: embedded timestamps, build paths, hostnames and address-derived symbol names are all common. The rule is to measure whether your compiler is reproducible before building anything on the assumption that it is — and the measurement is three lines.
3. The Second Obvious Technique, Also Measured
If digests will not work, surely timestamps will: the image is stale if a source is newer than it.
$ bin/build # 16:05:44
$ cp rtl/arb_fixed.v rtl/arb.v # also 16:05:44
$ [ rtl/arb.v -nt logs/sim.vvp ] && echo STALE || echo current
currentIt missed it. The source genuinely changed after the build, and test -nt said the image was current:
image mtime : 16:05:44
source mtime: 16:05:44
test -nt says: the source is NOT newer -> STALENESS MISSED
whole-second mtimes: image=1791542144 source=1791542144 equal=YESThe filesystem knows better than test does:
$ stat -f '%Fm' rtl/arb.v
1791542144.378106044
$ python3 -c "import os; print(repr(os.stat('rtl/arb.v').st_mtime))"
1791542144.378106Sub-second mtimes exist and test -nt does not use them. A build and an edit inside the same second are indistinguishable to it — and a build followed immediately by an edit is exactly what happens when somebody is iterating.
And the failure runs both ways:
$ touch rtl/arb.v # content unchanged
$ [ rtl/arb.v -nt logs/sim.vvp ] && echo STALE
STALEA touch with no content change reports stale, which is how a correctness check turns into a daily unnecessary rebuild and then gets switched off.
4. The Technique That Works
Record the digests of the sources at build time, beside the image. Source digests are reproducible by construction — they are a function of the file content and nothing else.
#!/bin/bash
# build [OUT] -- compile the filelist, and record WHAT WENT IN beside the image.
#
# The manifest records the digest of every SOURCE, not of the output, because
# iverilog's output is not reproducible: three builds of identical sources gave
# three different digests, 1084 bytes apart, since the vvp assembly embeds the
# compiler's memory addresses. And mtime cannot substitute -- `test -nt` uses
# whole seconds and missed an edit made in the same second as the build.
set -u
root=$(cd "$(dirname "$0")/.." && pwd)
. "$root/bin/digestlib.sh"
out=${1:-$root/logs/sim.vvp}
[ -r "$root/cfg/files.f" ] || { echo "build: no cfg/files.f" >&2; exit 2; }
cd "$root" || exit 2
files=$(/usr/bin/grep -v '^[[:space:]]*\(#.*\)\{0,1\}$' cfg/files.f)
[ -n "$files" ] || { echo "build: cfg/files.f lists no sources" >&2; exit 2; }
for f in $files; do
[ -r "$f" ] || { echo "build: cannot read source '$f'" >&2; exit 2; }
done
iverilog -o "$out" $files || exit 2
{ printf 'tool\t%s\n' "$(iverilog -V 2>&1 | head -1)"
printf 'filelist\t%s\n' "$(digest cfg/files.f)"
printf 'built\t%s\n' "$(date -u +%Y-%m-%dT%H:%M:%SZ)"
printf 'out\t%s\n' "$out"
for f in $files; do printf 'src\t%s\t%s\n' "$f" "$(digest "$f")"; done
} > "$out.manifest" || exit 2
printf 'build: %s (%s source file(s) recorded)\n' "$out" "$(printf '%s\n' $files | grep -c .)" >&2The manifest it writes:
$ column -t -s$'\t' logs/sim.vvp.manifest
tool Icarus Verilog version 13.0 (stable) (v13_0)
filelist 44008f3be934fbf11cb61e5107add1d7
built 2026-10-09T10:36:06Z
out /…/m33/logs/sim.vvp
src tb/tb_arb.v ba56b6a74822f03d1ec69b703de77efd
src rtl/arb.v 53b44193bfef952b1bce3d72b329db0cFive things recorded, and each one answers a question the log cannot.
Every source and its digest, which is what makes staleness decidable — and better than decidable, because it names which file changed rather than just reporting that something did.
The filelist's own digest. A filelist that gained a file is a different build even if every file it previously listed is unchanged, which is the hazard Chapter 26.4 measured from the ordering side.
The tool version, because Chapter 25.7 established that the same sources through two tool versions are two different experiments.
The build time, which is for humans and is deliberately not used for any decision.
And the output path, so a manifest found on its own still says what it describes.
5. The Triage
#!/bin/bash
# triage RUNDIR -- which LAYER does this failure belong to?
#
# A log cannot answer this. A broken design, an image built before the fix, and
# a wrapper that named the wrong image all produce BYTE-IDENTICAL logs. What
# separates them is evidence the log does not contain: which image ran, and
# whether that image was built from the sources that exist now.
#
# 0 nothing to triage -- the run passed
# 1 DESIGN or TEST -- the image matches today's sources; read the log
# 3 TOOL -- the simulator did not finish, or will not compile
# 4 TESTBENCH -- exited 0 and never stated an outcome
# 5 BUILD -- the image predates a source change; rebuild first
# 6 SCRIPT -- the run used an image it should not have
set -u
d=${1:-}
[ -n "$d" ] || { echo "triage: need a run directory" >&2; exit 2; }
root=$(cd "$(dirname "$0")/.." && pwd)
. "$root/bin/digestlib.sh"
canon=$root/logs/sim.vvp
for f in run.log image.path tool.rc; do
[ -r "$d/$f" ] || { echo "triage: '$d' has no $f -- a run that did not record itself cannot be triaged" >&2; exit 2; }
done
ranpath=$(cat "$d/image.path")
rc=$(cat "$d/tool.rc")
verdict=$(/usr/bin/grep -o 'TEST PASSED\|TEST FAILED' "$d/run.log" | head -1)
printf 'triage %s\n' "$d"
printf ' verdict in the log : %s\n' "${verdict:-none}"
printf ' tool exit status : %s\n' "$rc"
printf ' image that ran : %s\n' "${ranpath#$root/}"
if [ "$verdict" = "TEST PASSED" ]; then
echo " => nothing to triage: this run passed."
exit 0
fi
if [ -z "$verdict" ]; then
if [ "$rc" -ne 0 ]; then
echo " => TOOL layer: non-zero status and no verdict -- the simulator did not finish."
exit 3
fi
echo " => TESTBENCH layer: exited 0 and never stated an outcome."
exit 4
fi
if [ "$ranpath" != "$canon" ]; then
printf ' canonical output : %s\n' "${canon#$root/}"
echo " => SCRIPT layer: the run used an image that is not the canonical build output."
echo " Whatever the log says is a statement about some other build."
exit 6
fi
man=$ranpath.manifest
[ -r "$man" ] || {
echo " => SCRIPT layer: the image has no manifest, so nothing can say what went into it."
exit 6; }
changed=0
while IFS="$(printf '\t')" read -r kind a b; do
[ "$kind" = src ] || continue
if [ ! -r "$root/$a" ]; then
printf ' source GONE : %s\n' "$a"; changed=$((changed+1)); continue
fi
now=$(digest "$root/$a") || exit 2
if [ "$now" != "$b" ]; then
printf ' source CHANGED : %s\n' "$a"; changed=$((changed+1))
fi
done < "$man"
if [ "$changed" -gt 0 ]; then
printf ' => BUILD layer: %d source file(s) changed since this image was built.\n' "$changed"
echo " Rebuild and re-run before investigating anything in the log."
exit 5
fi
echo " all recorded sources are unchanged since the build"
echo " => DESIGN or TEST layer: the image that ran was built from today's sources."
echo " The failure is reproducible from source. Now read the log."
exit 1Seven exit values, and every one of them was exercised rather than reasoned about:
| exit | layer | produced by |
|---|---|---|
| 0 | nothing to triage | a run that passed |
| 1 | DESIGN or TEST | A and D — sources unchanged since the build |
| 2 | refusal | H — a run directory with only a log in it |
| 3 | TOOL | E — crash, non-zero with no verdict |
| 4 | TESTBENCH | F — silent, zero with no verdict |
| 5 | BUILD | B — rtl/arb.v changed after the build |
| 6 | SCRIPT | C — a non-canonical image; G and G2 — no manifest |
The three cases from Section 1, run through it:
########## A: the design really is broken ##########
triage cap/A
verdict in the log : TEST FAILED
tool exit status : 0
image that ran : logs/sim.vvp
all recorded sources are unchanged since the build
=> DESIGN or TEST layer: the image that ran was built from today's sources.
The failure is reproducible from source. Now read the log.
exit=1
########## B: the source was fixed, nobody rebuilt ##########
triage cap/B
verdict in the log : TEST FAILED
tool exit status : 0
image that ran : logs/sim.vvp
source CHANGED : rtl/arb.v
=> BUILD layer: 1 source file(s) changed since this image was built.
Rebuild and re-run before investigating anything in the log.
exit=5
########## C: rebuilt, but the wrapper named an old side build ##########
triage cap/C
verdict in the log : TEST FAILED
tool exit status : 0
image that ran : builds/sim_old.vvp
canonical output : logs/sim.vvp
=> SCRIPT layer: the run used an image that is not the canonical build output.
Whatever the log says is a statement about some other build.
exit=6Three identical logs, three different answers, and B and C were decided without reading the log's contents at all.
6. The Order Is the Design
The questions are cheap and the order is what makes them useful. Each one that fires stops the investigation, so the cheapest and most decisive go first.
Question 1 is a refusal, not an answer. A run that did not record its own argv and image cannot be triaged:
$ triage cap/H
triage: 'cap/H' has no image.path -- a run that did not record itself cannot be triaged
exit=2Refusing beats guessing. A triage that assumed the canonical image when none was recorded would answer every question about the wrong file, confidently. This is Chapter 32.6's rule — an unverifiable claim is worse than an absent one — applied one layer earlier.
Question 2 does not need the build at all. No verdict means the design never got a chance to be wrong:
triage cap/E triage cap/F
verdict in the log : none verdict in the log : none
tool exit status : 1 tool exit status : 0
=> TOOL layer => TESTBENCH layerThe split on the exit status is Chapter 32.3's distinction between CRASH and NO_VERDICT, and it is the one piece of the exit status that is reliable: non-zero means the simulator itself had a problem.
Questions 3 and 4 precede question 5 because "the wrong image" and "a stale image" need different fixes. Rebuilding does not help if the wrapper is going to run a different file anyway, and the message has to say which:
=> SCRIPT layer: the image has no manifest, so nothing can say what went into it.And question 5 names the file. source CHANGED : rtl/arb.v is immediately actionable in a way that "the image is stale" is not — on a real design the manifest has hundreds of entries and the interesting output is the two that moved.
7. What This Costs to Adopt
Three things have to be true before any of this works, and all three are cheap:
The build records its inputs. One manifest file per image, written by the same script that compiles — never by hand, and never optionally, because an optional manifest is absent exactly when it is needed.
The run records which image it used. Chapter 32.2 recorded the image's digest in env.txt; this chapter's runone records the resolved path, the digest, and the argv as one token per line:
{ printf '%s\n' vvp "$absimg" "+TESTNAME=$test" "+SEED=$seed" "+CYCLES=${CYCLES:-200}"; } > "$d/cmd.args"One token per line rather than one quoted string, because a path containing a space must survive the round trip — Chapter 33.5's subject, and the reason Chapter 27.9 chose the same format.
And the path is resolved to absolute before anything changes directory. runone does it in its third line, because the simulation runs from inside its own run directory and a relative image path would not survive the cd — the mechanism this track has now met seven times, most expensively in Chapter 30.1.
What it buys is the difference between a morning and a minute, on the two cases out of three where the log is actively misleading.
Practice
- Take a failing run from your own flow and write down what the log says the problem is.
- Construct the same failure three ways — a genuine bug, a stale image, and a wrong image path.
- Diff the three logs and confirm what you get.
- Build identical sources twice and compare the output digests.
- If they differ, find where, and identify what the compiler embedded.
- Decide whether your toolchain is reproducible before relying on it being so.
- Build, then edit a source in the same second, and ask
test -ntwhether the image is stale. - Read the sub-second mtime with
stat -f '%Fm'and compare. toucha source without changing it and ask again.- Write a build that records a manifest of source digests, the filelist digest and the tool version.
- Explain why the build time is recorded but never used for a decision.
- Change one source and have the manifest comparison name it.
- Write the triage with one exit value per layer and no fall-through.
- Exercise every exit value, including the refusal.
- Give it a run directory with only a log and confirm it refuses.
- Run it on a passing run and confirm it says so.
- Reorder the questions so the build check comes before the image-path check, and find the case it now answers wrongly.
- Make it rebuild automatically and then explain what disappears from next week's report.
- Record the argv one token per line and put a space in the image's path.
- Resolve the image path to absolute and then break it by removing that line.
Check Your Understanding
- Why is the log often the least useful thing about a failing run?
- Describe the three situations that produced one identical log.
- How many distinct log hashes did they produce?
- Which two are the expensive ones, and why specifically?
- What is the worst version of case C?
- What happened when the same sources were built three times?
- What is embedded in the output that makes it unreproducible?
- What general rule does that give you about a toolchain?
- What did
test -ntsay about a source edited after the build, and why? - What does
stat -f '%Fm'show thattestdoes not use? - What does
touchwithout a content change report? - Why are those two failure modes especially bad for a correctness check?
- Why digest the sources rather than the output?
- Name the five things the manifest records and what each answers.
- Why record the filelist's own digest separately?
- Why is the build time recorded but never used?
- List the seven triage exit values and what each means.
- Which two cases were decided without reading the log's contents?
- Why is question 1 a refusal rather than an answer?
- Why does question 2 not need the build at all?
- Which piece of a simulator's exit status is reliable?
- Why do questions 3 and 4 precede question 5?
- Why does question 5 name the file rather than just reporting staleness?
- Why must triage not rebuild automatically?
- Give the three other repairs it must not make.
- What three things must be true before any of this works?
- Why record the argv one token per line?
8. Remember
- The log describes one layer. Three different causes produced a byte-identical log, and two of the three make the log actively misleading.
- B and C produce a confident wrong investigation, and C's worst form is a correct fix being reverted.
iverilogis not reproducible: three builds of identical sources gave three digests, 1,084 bytes apart, because thevvpassembly embeds the compiler's memory addresses. Measure your toolchain before assuming otherwise.test -ntmissed a real staleness because the edit landed in the build's whole second — and reported a false one after a baretouch. Sub-second mtimes exist;testdoes not use them.- Digest the sources at build time. That is reproducible by construction, and it names which file changed.
- Record the filelist's digest and the tool version too, and record the build time without ever deciding anything with it.
- Triage before reading. Seven exit values, each exercised: pass, design/test, refusal, tool, testbench, build, script.
- Order the questions by cost and decisiveness, and let the first one that fires stop the investigation.
- A run that did not record itself cannot be triaged. Refuse rather than assume.
- Separate
BUILDfromSCRIPT— a missing pipeline step and a wrong constant are not one bug. - Triage must never repair anything, or the reason it was needed vanishes from the report.
- Resolve the image to an absolute path before any
cd, and record the argv one token per line.
9. What Is Next
Triage says which layer, and for the design layer it says the failure is reproducible from source. Chapter 33.2 is the next obligation: making that one run fail again by hand, outside the regression, which is the precondition for debugging it — and measuring what happens to a "reproduction" when one piece of the run's identity is reconstructed from memory instead of from the record.
Where this fits
Part of the Linux & Bash curriculum.
