dbglab's random test fails with seed 23 on the peripheral's stream:
$ tb/run.sh random 23
dbglab: test=random seed=23
FAIL test=random seed=23 cycle=2385: STREAM: word #41 = xxxxxxxx, expected 00000000Unlike a scoreboard line, this one names no DMA run and no address. Word #41 could have come from the CPU or from a DMA copy, and its value could have gone bad anywhere between reset and cycle 2385. Suppose each look at the design's state costs you something real: an hour of simulation, a dump you cannot store, a chip you have to stop. When did the state first go bad?
The usual move is to dump everything from time zero and scroll back from the failure. On a small design that works. On a long run it is the problem: the dump is too big to write or to load, so people dump a window just before the failure, and the cause is earlier than the window (the dump strategy lesson shows exactly that). The other habit is to guess a time from the symptom ("the stream started at cycle 2000, look there") and dump around the guess. A wrong guess costs a full run and tells you only that the cause is not there.
Time is an ordered axis, and a run that goes wrong usually stays wrong. That is all bisection needs. The guessing vs searching lesson halved the number of operations a test makes, which changes the stimulus. Here the run stays exactly as it was and you halve when you look.
Choose a question about the state at one cycle, answerable with yes or no: does any RAM word hold an unknown value?, does the RAM disagree with the model?, is any FIFO pointer unknown? It should come from the symptom: here an unknown word reached the stream, so ask where unknown words live.
Make sure the answer flips once. Clean up to some cycle, bad from then on, until the failure. Ask what could make it bad early (reset, uninitialised memory) or clean again (an overwrite).
Check both ends. Look at a cycle you believe is clean and at the failing cycle. If the ends do not disagree, stop: the question or the window is wrong.
Look in the middle. Bad: the first bad cycle is at or before it. Clean: it is after it. Keep the half that holds the change.
Never disturb the run before the look. Read state from the side (hierarchical names, a backdoor, a scan chain), not by sending traffic through the design.
Stop when the window is small enough to read. Then dump or log just that window and walk back the last hops.
A window of N cycles takes about
looks: 2,375 cycles take 12, a million take 20. Each look costs a run up to its cycle, so the total is roughly a dozen runs, never one full dump.
The bars are on a log scale, so every look shortens them by the same step, whether its answer was clean or bad. Three looks said bad; nine said clean. Both kinds carry exactly one bit.
A look is a small module compiled next to dbglab. At cycle +AT it counts the RAM words that hold an unknown value, prints one line, and stops the simulation, the way a scan dump stops a chip: one look per run. It reads the RAM's array directly, so the run up to the look is the run that failed.
// not-run: needs dbglab's sources and bench; compile it next to them (command in the Evidence box)
// look_at: one look at the design's state at cycle +AT=<T>, then stop, the way a scan dump
// stops a chip. The question: does any RAM word hold an unknown value at cycle T?
// Prints one LOOK line: BAD with the count and the first such word, or CLEAN. Reads only.
`timescale 1ns/1ps
module look_at;
int unsigned at, n, first;
initial if (!$value$plusargs("AT=%d", at)) at = 0;
always @(posedge dbglab_tb.clk) begin
#0.5; // just after the edge
if (at != 0 && dbglab_tb.cycle == at) begin
n = 0;
for (int i = 0; i < 1024; i++)
if ($isunknown(dbglab_tb.dut.u_ram.mem[i])) begin
if (n == 0) first = i;
n++;
end
if (n != 0) $display("LOOK cycle=%0d BAD: %0d RAM words unknown, first word %0d", at, n, first);
else $display("LOOK cycle=%0d CLEAN", at);
$finish;
end
end
endmodule$ vvp -n build/look.vvp +TEST=random +SEED=23 +AT=1
dbglab: test=random seed=23
LOOK cycle=1 BAD: 1024 RAM words unknown, first word 0
...
$ vvp -n build/look.vvp +TEST=random +SEED=23 +AT=10
dbglab: test=random seed=23
LOOK cycle=10 CLEAN
...Cycle 1 is already bad: every RAM word is unknown until the bench preloads the RAM, a few cycles after reset. So the question flips twice, bad, then clean at cycle 10, then bad again somewhere later. Cycle 1 cannot be the clean end. Cycle 10 can.
# not-run: drives the look_at probe through vvp; run it from the dbglab folder (command in the Evidence box)
"""bisect_time.py: the first cycle at which a one-look check sees bad state.
usage: python3 bisect_time.py <test> <seed> <good cycle> <bad cycle> (run from the dbglab folder,
after compiling the look_at probe into build/look.vvp)
Each probe is one run that stops at its look, so it costs as many cycles as the look is late."""
import subprocess, sys
test, seed, lo, hi = sys.argv[1], sys.argv[2], int(sys.argv[3]), int(sys.argv[4])
def look(t):
out = subprocess.run(["vvp", "-n", "build/look.vvp", f"+TEST={test}", f"+SEED={seed}", f"+AT={t}"],
capture_output=True, text=True).stdout
line = next((l for l in out.splitlines() if l.startswith("LOOK")), f"LOOK cycle={t} (no look: the run ended first)")
return "BAD" in line or "no look" in line, line
runs, cost = 0, 0
for t in (lo, hi): # check both ends before trusting the search
bad, line = look(t); runs += 1; cost += t
print(f"end {line}")
if bad != (t == hi):
sys.exit(f"the ends do not bracket a change: cycle {t} is {'bad' if bad else 'clean'}")
while hi - lo > 1:
mid = (lo + hi) // 2
bad, line = look(mid); runs += 1; cost += mid
if bad: hi = mid
else: lo = mid
print(f"probe {line:62s} -> cycles {lo + 1}..{hi}")
print(f"first bad cycle: {hi} ({runs} runs, {cost} cycles simulated in all)")$ python3 ../probes/bisect_time.py random 23 10 2385
end LOOK cycle=10 CLEAN
end LOOK cycle=2385 BAD: 15 RAM words unknown, first word 48
probe LOOK cycle=1197 CLEAN -> cycles 1198..2385
probe LOOK cycle=1791 CLEAN -> cycles 1792..2385
probe LOOK cycle=2088 CLEAN -> cycles 2089..2385
probe LOOK cycle=2236 BAD: 2 RAM words unknown, first word 48 -> cycles 2089..2236
probe LOOK cycle=2162 CLEAN -> cycles 2163..2236
probe LOOK cycle=2199 CLEAN -> cycles 2200..2236
probe LOOK cycle=2217 CLEAN -> cycles 2218..2236
probe LOOK cycle=2226 CLEAN -> cycles 2227..2236
probe LOOK cycle=2231 BAD: 1 RAM words unknown, first word 48 -> cycles 2227..2231
probe LOOK cycle=2228 CLEAN -> cycles 2229..2231
probe LOOK cycle=2229 CLEAN -> cycles 2230..2231
probe LOOK cycle=2230 BAD: 1 RAM words unknown, first word 48 -> cycles 2230..2230
first bad cycle: 2230 (14 runs, 27429 cycles simulated in all)Read it line by line. At the failing cycle 15 words are unknown, the first at word 48. The first three looks are clean, which moves the window to the last 300 cycles. Look 4 at cycle 2236 sees two bad words; looks 5 to 8 close in from below; look 9 sees one. At look 12 the answer is a single cycle: at cycle 2230 word 48 becomes unknown, 155 cycles before the stream check fails. Fourteen runs simulated 27,429 cycles in all, about eleven times the failing run, and nothing was dumped.
Now the window is small enough to log in full. A probe that prints every bus request between two cycles, and the setup of any DMA run that starts near them:
$ ../probes/run-probe.sh ../probes/window_log.sv random 23 +FROM=2220 +TO=2232
dbglab: test=random seed=23
cycle 2220: cpu WR 00002018 0000000f
cycle 2223: cpu WR 0000201c 00000001
cycle 2224: DMA run #16 starts: ctrl=11 len=15 src=00001c8c dst=000010c0 fill=xxxxxxxx
cycle 2226: cpu RD 0000200c
cycle 2229: dma WR 000010c0 xxxxxxxx
FAIL test=random seed=23 cycle=2385: STREAM: word #41 = xxxxxxxx, expected 00000000The CPU writes LEN = 15 (0x2018) and START (0x201c). DMA run #16 starts at cycle 2224 in fill mode (CTRL 0x11: fill, plus the done interrupt) with a fill value that is already unknown, and its first write, accepted at cycle 2229, puts xxxxxxxx into 0x10c0, which is word 48. The RAM shows it from cycle 2230. The same probe over cycles 2290 to 2385 shows the rest of the chain: DMA run #16 fills words 48 to 62, run #17 starts at cycle 2355 and copies two words from 0x10f4 (word 61) into the peripheral, and the stream check sees one of them at 2385.
The search moved from "somewhere in 2,385 cycles" to "the first write of a zero fill at cycle 2229" in twelve looks and one short log. It also handed the walk back its next hop: the DMA's fill value was unknown when the run started, so the next question is about the CSR block's FILL register, not about RAM, the peripheral or the stream. That hunt is in X in a waveform, on another seed of the same bug.
Notice what the answer is: the first cycle this question could see. A question about the stream would have bisected to 2385, which you already knew. A question about the DMA's fill input at each start would have landed at 2224, earlier still. Choose the sharpest question the symptom suggests, and treat the answer as the place to start walking back, not the root cause.
In dbglab every look is cheap, so you could also check every cycle in one run, and that is the better tool when you can: a per-cycle count of unknown RAM words changes at cycles 1, 8 and 2230, the same answer. Bisection in time earns its keep when a look is expensive or destroys the run.
No, later. The fill writes the bad words from cycle 2229, but until the bench closes run #16 the model has not been updated and the comparison must skip those words, so the question first says bad after the run is closed. Bisection finds the first cycle your question can see, and this question sees the damage only when the model catches up. It still narrows the search well; you then walk back from there.
That the question was already bad near reset, like this lesson's RAM before the preload, or that the clean end was never checked. Look at cycle 3 by hand: if the state is merely uninitialised and settles after reset, pick a clean end after that point and bisect again. A first bad cycle right at reset is either a real reset bug or, more often, a question that does not flip once.
dbglab at HEAD 49c5f04, Icarus Verilog 13.0, Python 3.14.3, 2026-10-17. tb/run.sh random 23 fails at cycle 2385 (STREAM word #41 unknown). look_at.sv compiled next to dbglab into build/look.vvp (iverilog -g2012 -Wno-timescale -I tb -o build/look.vvp <rtl/files.f> tb/bus_rules.sv tb/dbglab_tb.sv look_at.sv); vvp -n build/look.vvp +TEST=random +SEED=23 +AT=1 printed BAD (1024 words), +AT=10 CLEAN.
python3 bisect_time.py random 23 10 2385: 14 runs (2 ends, 12 looks), 27,429 cycles simulated in all, 0.47 s, first bad cycle 2230; with a lower end of 1 it stops at the end check. A per-cycle count of unknown RAM words (one run, xtrace.sv) changes at cycles 1, 8 and 2230, agreeing with the bisection. window_log.sv with +FROM=2220 +TO=2232 printed the window shown, and with +FROM=2290 +TO=2385 the start of run #17 (two words from 0x10f4 to the peripheral, cycle 2355). A full dump of the run (DUMP=1 tb/run.sh random 23) is 963,311 bytes.
Limits: dbglab's runs take well under a second, so the cost argument is shown in cycles, not hours; the scan-dump and emulator uses are described, not run here. One bug, one seed, one question.