The report

The ticket comes from the driver team, not from verification. Paraphrased:

You own dbglab. Before anything else, run what you have:

$ tb/regress.sh icarus 1 2 3 | grep -E "FAIL|failing"
irq_w1c                  seed 1      FAIL
irq_w1c                  seed 2      FAIL
irq_w1c                  seed 3      FAIL
dma_burst_backpressure   seed 1      FAIL
dma_burst_backpressure   seed 2      FAIL
dma_burst_backpressure   seed 3      FAIL
periph_power             seed 1      FAIL
periph_power             seed 2      FAIL
periph_power             seed 3      FAIL
9 failing run(s)

Three tests fail. Only one has "irq" in its name, and its first step is the driver's exact scenario: start a copy right after reset, with CTRL at its reset value, and check that no interrupt fires (meet dbglab lists the tests). The other two failures are other bugs with other signatures; leave them for now.

Stop here if you want to try it yourself. You know it worked at v0.1 and fails at HEAD. How many runs should it take to find the change, and what exactly should each run test?

The hunt

Reproduce: the report becomes one command

$ tb/run.sh irq_w1c 1
dbglab: test=irq_w1c seed=1
FAIL test=irq_w1c seed=1 cycle=84: IRQ: irq=1 while CTRL=00 enables no interrupt
$ tb/run.sh irq_w1c 1 verilator
dbglab: test=irq_w1c seed=1
FAIL test=irq_w1c seed=1 cycle=84: IRQ: irq=1 while CTRL=00 enables no interrupt

The bench says what the driver said: irq is 1 while the model's CTRL is 00. It fails the same way in both simulators, at the same cycle, so it is not an X or a race. The driver's report and the test now share one signature, which you can quote back on the ticket (a bug report others can act on).

Why bisect first

You could start reading: the interrupt logic in csr_block.sv, the W1C status bits, the DMA's done pulse. Each is a plausible place, and each takes a while to rule out. But you know something more useful than any of them: it passed at v0.1. That makes it a question about history, and history has a cheap, guaranteed answer. Check both ends first:

$ git checkout -q v0.1 && tb/run.sh irq_w1c 1
dbglab: test=irq_w1c seed=1
PASS test=irq_w1c seed=1
$ git checkout -q main && tb/run.sh irq_w1c 1
dbglab: test=irq_w1c seed=1
FAIL test=irq_w1c seed=1 cycle=84: IRQ: irq=1 while CTRL=00 enables no interrupt

Good end good, bad end bad, and the test takes under a second. Eleven commits in between means four runs. Two real dead ends sit on the way, and both are common.

Dead end 1: a suspect picked by its name

Before bisecting, someone scans the log for commits that touched the CSR block:

$ git log --oneline v0.1..HEAD -- rtl/csr_block.sv rtl/dbglab_pkg.sv
b357bd8 csr: no reset on the DMA address and data registers
bc2bb34 dma: fill mode
026f8bf csr: collect register reset values in dbglab_pkg
a60b6f7 periph: power gate model with output isolation
246ff00 dma: stop on an error response and report it

The top line jumps out: a reset bug, and a commit that removes resets. It is tempting to start reading that diff. One run tests the guess, because if b357bd8 introduced the bug, its parent passes:

$ git checkout -q 03ebdc1 && tb/run.sh irq_w1c 1        # the parent of b357bd8
dbglab: test=irq_w1c seed=1
FAIL test=irq_w1c seed=1 cycle=84: IRQ: irq=1 while CTRL=00 enables no interrupt

The parent already fails, so b357bd8 is innocent of this bug. (It is guilty of another one: the X that hid.) A commit's subject tells you what its author meant to change, not what it did change. Choosing a suspect by name is a guess, and a guess here cost one run plus the time spent being sure.

Dead end 2: a signature that is too strict

git bisect run needs a script that exits 0 for good, 1 for bad and 125 to skip. A natural first version calls a commit bad only if HEAD's exact failure line appears in the log:

1
2
3
4
5

#!/bin/sh
# strict.sh: bad only if the exact line from HEAD's log appears.
tb/run.sh irq_w1c 1 > /dev/null
grep -qF 'FAIL test=irq_w1c seed=1 cycle=84: IRQ: irq=1 while CTRL=00 enables no interrupt' build/icarus-irq_w1c-1.log && exit 1
exit 0

$ git bisect start HEAD v0.1
$ git bisect run ../bisect/irq-bug.sh
...
026f8bfe1f4ed59ec2d8f33c866509ac9d197dc1 is the first bad commit
...
    csr: collect register reset values in dbglab_pkg
...
    reset branch. No functional change intended.
...
bisect found first bad commit

Four runs, about a second, and a commit that changes nine lines; bisection in history shows the full log. Compare the two bisects side by side:

• Top row: each verdict halves the range correctly, and the culprit is the first bad commit after a good one: 8 good, 9 bad.

• Bottom row: one wrong verdict, at the first step, decides the whole search. Bisect never checks its own answers, so a single lie is never corrected.

Read the guilty diff

$ git show 026f8bf
...
-      scratch_q <= '0; ctrl_q <= '0; done_q <= 1'b0;
-      src_q <= '0; dst_q <= '0; len_q <= '0;
+      scratch_q <= SCRATCH_RST; ctrl_q <= CTRL_RST; done_q <= 1'b0;
+      src_q <= SRC_RST; dst_q <= DST_RST; len_q <= LEN_RST;
...
+  // Reset values.
+  localparam logic [31:0] SCRATCH_RST = 32'h0000_0000;
+  localparam logic [7:0]  CTRL_RST    = 8'h01;
+  localparam logic [31:0] SRC_RST     = 32'h0000_0000;
+  localparam logic [31:0] DST_RST     = 32'h0000_0000;
+  localparam logic [9:0]  LEN_RST     = 10'd0;
...

Five literals moved into a package. Four kept their value. ctrl_q used to reset to '0 and now resets to 8'h01, which is bit 0 of CTRL: done_ie, the done-interrupt enable. The commit message says "No functional change intended", and the intent was honest. The change was not.

Hypothesise and test: a prediction at both commits

Hypothesis: since commit 9, CTRL comes out of reset with done_ie set, so the first DMA completion raises irq even though software never enabled it. Predictions, each of which could fail: at 026f8bf, ctrl_q is 01 at reset release and irq rises in the same cycle as done_q, with no CPU write to CTRL; at its parent 2e63466, ctrl_q is 00 and irq rises only after the CPU writes CTRL. A probe prints the life of the interrupt, one line per event:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23

// not-run: needs dbglab's sources and bench; compile it next to them (command in the Evidence box)
// irq_story: the life of the interrupt, one line per event: reset release, every CPU write to
// CTRL, every DMA start and done, every change of done_q and irq.
`timescale 1ns/1ps
module irq_story;
  logic irq_q = 1'b0, done_q = 1'b0, rst_q = 1'b0;
  always @(posedge dbglab_tb.clk) begin
    if (dbglab_tb.rst_n && !rst_q)
      $display("cycle %4d  reset released      ctrl_q=%02h", dbglab_tb.cycle, dbglab_tb.dut.u_csr.ctrl_q);
    if (dbglab_tb.dut.m_valid[0] && dbglab_tb.dut.m_ready[0] && dbglab_tb.dut.m_write[0]
        && dbglab_tb.dut.m_addr[0] == 32'h0000_2008)
      $display("cycle %4d  CPU writes CTRL   data=%02h", dbglab_tb.cycle, dbglab_tb.dut.m_wdata[0][7:0]);
    if (dbglab_tb.dut.dma_start) $display("cycle %4d  DMA start", dbglab_tb.cycle);
    if (dbglab_tb.dut.dma_done)  $display("cycle %4d  DMA done", dbglab_tb.cycle);
    if (dbglab_tb.dut.u_csr.done_q !== done_q)
      $display("cycle %4d  done_q -> %b        ctrl_q=%02h", dbglab_tb.cycle, dbglab_tb.dut.u_csr.done_q, dbglab_tb.dut.u_csr.ctrl_q);
    if (dbglab_tb.irq !== irq_q)
      $display("cycle %4d  irq    -> %b        ctrl_q=%02h", dbglab_tb.cycle, dbglab_tb.irq, dbglab_tb.dut.u_csr.ctrl_q);
    rst_q  = dbglab_tb.rst_n;
    done_q = dbglab_tb.dut.u_csr.done_q;
    irq_q  = dbglab_tb.irq;
  end
endmodule

$ git checkout -q 026f8bf && ../probes/run-probe.sh ../probes/irq_story.sv irq_w1c 1
dbglab: test=irq_w1c seed=1
cycle    0  done_q -> x        ctrl_q=xx
cycle    0  irq    -> x        ctrl_q=xx
cycle    1  done_q -> 0        ctrl_q=01
cycle    1  irq    -> 0        ctrl_q=01
cycle    4  reset released      ctrl_q=01
cycle   18  DMA start
cycle  115  DMA done
cycle  116  done_q -> 1        ctrl_q=01
cycle  116  irq    -> 1        ctrl_q=01
FAIL test=irq_w1c seed=1 cycle=116: IRQ: irq=1 while CTRL=00 enables no interrupt
$ git checkout -q 2e63466 && ../probes/run-probe.sh ../probes/irq_story.sv irq_w1c 1 | head -14
dbglab: test=irq_w1c seed=1
cycle    0  done_q -> x        ctrl_q=xx
cycle    0  irq    -> x        ctrl_q=xx
cycle    1  done_q -> 0        ctrl_q=00
cycle    1  irq    -> 0        ctrl_q=00
cycle    4  reset released      ctrl_q=00
cycle   18  DMA start
cycle  115  DMA done
cycle  116  done_q -> 1        ctrl_q=00
cycle  119  CPU writes CTRL   data=01
cycle  120  irq    -> 1        ctrl_q=01
cycle  130  done_q -> 0        ctrl_q=01
cycle  130  irq    -> 0        ctrl_q=01
cycle  145  DMA start

• Cycle 1, both commits: reset acts. The only difference between the two runs is here: ctrl_q=01 against ctrl_q=00. The first wrong value exists from reset, 115 cycles before anything fails.

• Cycle 116 at 026f8bf: done_q and irq rise together, and no line says the CPU wrote CTRL. The enable was there from reset.

• Cycles 116 to 120 at 2e63466: done_q rises alone. irq follows only after the test writes CTRL=01 at cycle 119, which is step 2 of the test working as designed.

Both predictions hold, at both commits. Bisect named the commit, the diff named the line, and the probe shows the line's effect and nothing else. (Cycles 0 and 1 show X before reset acts; that is normal for a four-state simulator.)

The fix and the lesson

Fix: put the register map's value back

// snippet: the fix, rtl/dbglab_pkg.sv line 39
  localparam logic [7:0]  CTRL_RST    = 8'h00;

Prove: the repro, more seeds, both simulators, nothing new

$ tb/run.sh irq_w1c 1 && tb/run.sh irq_w1c 1 verilator
dbglab: test=irq_w1c seed=1
PASS test=irq_w1c seed=1 cycles=316 time=3156 ns
dbglab: test=irq_w1c seed=1
PASS test=irq_w1c seed=1 cycles=316 time=3156 ns
$ for s in $(seq 1 20); do tb/run.sh irq_w1c $s | tail -1; done | cut -c1-4 | sort | uniq -c
  20 PASS
$ tb/regress.sh icarus 1 2 3 | grep -E "FAIL|failing"
dma_burst_backpressure   seed 1      FAIL
dma_burst_backpressure   seed 2      FAIL
dma_burst_backpressure   seed 3      FAIL
periph_power             seed 1      FAIL
periph_power             seed 2      FAIL
periph_power             seed 3      FAIL
6 failing run(s)
$ tb/regress.sh verilator 1 2 3 | tail -1
6 failing run(s)

The repro passes in both simulators, twenty seeds pass, and the regression's remaining failures are the two other bugs it had before, with their own signatures (the deadlock under back-pressure is one). Tell the driver team they can remove their mask. A workaround left in software outlives the bug it covered.

Prevent: three habits, each cheap

• Test reset values directly. Only irq_w1c noticed, and only by luck: it is the one test that starts a DMA before writing CTRL. A test that reads every register after reset and compares it with the register map catches this before any DMA runs. The bench's model keeps its own reset values instead of importing the package's on purpose; had it imported CTRL_RST, model and RTL would agree and nothing would fail (when the bug is in the test).

• Check "no functional change" claims. A refactor can be proved equal to its parent. Equivalence failures runs that check on this very commit and gets the counterexample.

• Keep the bisect scripts. irq-bug.sh is now a test of this bug's signature. Keep it next to the bench, outside the tree being bisected, so the next regression from a known-good release is one command.

Which step won this hunt? Localise, through history. Reading code would have found the line eventually, but only by guessing where to read. Four runs of a correct script found it without guessing. The two dead ends were both failures of judgement about bisect, and both were cheap to expose: one run at a parent, and one look at the first verdict.

Related topics

• Part 10 · Case Studies

• Bisection in history

• Configuration and register-map bugs

• X and reset bugs

• Case study: the off-by-one that fails at wrap

• Case study: the X that hid