A read that fails 8,000 cycles in

dbglab's random test fails on seed 17. The scoreboard read RAM word 816 at cycle 7949 and got xxxxxxxx, an unknown value, where it expected zero. The message even names the last writer: DMA run #4. A colleague has a fix ready: "the RAM should never store an X; clamp it to zero on the way in." The regression goes green. Is the bug fixed?

What people usually do, and why it fails

Most debugging starts where the failure is reported, which is natural: the FAIL line names a module, a cycle and a value. The trap is to stop there. The scoreboard is a reporter. It checks at certain moments, and it reports whatever was wrong by then. The RAM is a carrier: it stored the value it was given. Neither is necessarily where the design went wrong. A change at the reporter or the carrier makes the message go away, and in a four-state simulator that can look exactly like a fix. It is not, and the run below shows how you find out.

The method: three words, kept apart

Use three words, each for one thing, and do not let them blur:

Between the fault and the symptom lies a chain of wrong values, each produced by the one before it. Every link in that chain is a consequence, not a cause. Four rules follow:

• Write the symptom down exactly and do not edit it into a theory. "Word 816 read X at 7949", not "the RAM is corrupt".

• Walk back, one link at a time, asking who wrote this value, and was their input right? Stop when a block's inputs are right and its output is wrong. That output is the fault.

• The cause is in the code or the decision, not in time. Ask why the fault happened: a line, a missing reset, a wrong assumption in a commit message.

• Test a fix where symptom and cause would disagree. A fix that only hides the symptom must fail somewhere the real fix passes. Find that place before you believe either.

The picture: how far apart they are

Almost all of the axis is empty. The design went wrong in the first 500 cycles and said nothing for the next 7,461. A waveform opened at the symptom would show a perfectly healthy RAM read.

Do it: walk back from the symptom

The symptom, reproduced

$ tb/run.sh random 17
dbglab: test=random seed=17
FAIL test=random seed=17 cycle=7949: SCOREBOARD: RAM word 816 (address 00001cc0) read xxxxxxxx, expected 00000000 (last written by DMA run #4)

Read it as a symptom, nothing more: one word, one cycle, one check. The message gives one useful pointer back: the model believes DMA run #4 wrote this word last, so that run is the next link to look at.

The chain, link by link

A probe module, compiled next to the design as in the debug loop, prints the FILL register at reset release, every DMA run in fill mode, the first write of an unknown value into the RAM, and the read of word 816. It only reads signals; it changes nothing.

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

// not-run: needs dbglab's sources and bench; compile it next to them (command in the Evidence box)
// x_probe: follows an unknown value from the register that holds it to the RAM. It only reads the design.
`timescale 1ns/1ps
module x_probe;
  int unsigned run = 0, xwrites = 0;
  bit seen_rst = 1'b0;
  always @(posedge dbglab_tb.clk) begin
    #0.5;                                                     // just after the edge
    if (!seen_rst && dbglab_tb.rst_n) begin
      seen_rst = 1'b1;
      $display("cycle %0d: reset released, FILL register (u_csr.fill_q) = %h", dbglab_tb.cycle, dbglab_tb.dut.u_csr.fill_q);
    end
    if (dbglab_tb.dut.u_dma.start && !dbglab_tb.dut.u_dma.busy) begin
      run++;
      if (dbglab_tb.dut.u_dma.cfg_ctrl[4])
        $display("cycle %0d: DMA run #%0d start, fill mode, LEN=%0d DST=%h FILL=%h", dbglab_tb.cycle, run,
                 dbglab_tb.dut.u_dma.cfg_len, dbglab_tb.dut.u_dma.cfg_dst, dbglab_tb.dut.u_dma.cfg_fill);
    end
    if (dbglab_tb.dut.u_ram.req && dbglab_tb.dut.u_ram.write && $isunknown(dbglab_tb.dut.u_ram.wdata)) begin
      xwrites++;
      if (xwrites == 1)
        $display("cycle %0d: first write of an unknown value: RAM word %0d (address %h) <= %h",
                 dbglab_tb.cycle, dbglab_tb.dut.u_ram.addr[11:2], dbglab_tb.dut.u_ram.addr, dbglab_tb.dut.u_ram.wdata);
    end
    if (dbglab_tb.dut.u_ram.req && !dbglab_tb.dut.u_ram.write && dbglab_tb.dut.u_ram.addr[11:2] == 816)
      $display("cycle %0d: CPU reads RAM word 816 (unknown writes so far: %0d)", dbglab_tb.cycle, xwrites);
  end
endmodule

$ ../probes/run-probe.sh ../probes/x_probe.sv random 17
dbglab: test=random seed=17
cycle 5: reset released, FILL register (u_csr.fill_q) = xxxxxxxx
cycle 483: DMA run #4 start, fill mode, LEN=9 DST=00001ca8 FILL=xxxxxxxx
cycle 488: first write of an unknown value: RAM word 810 (address 00001ca8) <= xxxxxxxx
cycle 823: DMA run #6 start, fill mode, LEN=17 DST=00001ea4 FILL=3578a189
...
cycle 7947: CPU reads RAM word 816 (unknown writes so far: 9)
FAIL test=random seed=17 cycle=7949: SCOREBOARD: RAM word 816 (address 00001cc0) read xxxxxxxx, expected 00000000 (last written by DMA run #4)

Read it backwards, from the symptom to the fault:

• Cycle 7947: the CPU reads word 816, which the bench reports two cycles later. The RAM returns what it holds. The RAM is a carrier, so keep walking.

• Cycle 488: DMA run #4 writes X into word 810, the start of a 9-word fill from 0x1ca8. Words 810 to 818 all receive X by cycle 524 (the nine unknown writes the probe counts, word 816 among them). The DMA wrote what it was told to write, so keep walking.

• Cycle 483: run #4 starts in fill mode with FILL=xxxxxxxx. Fill mode writes the FILL register's value to every word. A zero fill relies on FILL holding its documented reset value of 0, and the bench's model expects zeros for that reason.

• Cycle 5: reset is released and FILL is already X. The register map says FILL resets to 0. This is the first wrong value: the fault. Nothing before it is wrong, because nothing came before it.

Notice run #6 at cycle 823: also a fill, with a real value. Software wrote FILL before that run, so it was fine. Only a fill that comes before any write to FILL exposes the fault, which is why this needs a particular seed.

From the fault to the cause

Why is FILL unknown after reset? Its register is written here:

1
2
3
4
5
6
7
8
9
10
11

// snippet: rtl/csr_block.sv at HEAD, lines 55-64
  // Datapath registers: always programmed before START, so they need no reset.
  always_ff @(posedge clk)
    if (wr) begin
      case (off)
        CSR_SRC:  src_q  <= wdata;
        CSR_DST:  dst_q  <= wdata;
        CSR_LEN:  len_q  <= wdata[9:0];
        CSR_FILL: fill_q <= wdata;
        default: ;
      endcase

No reset. The comment states the assumption: these registers are always programmed before START. That is true of SRC, DST and LEN, and false of FILL, whose specification promises 0. The commit that made the change, b357bd8 ("csr: no reset on the DMA address and data registers"), is the cause: a wrong assumption written into line 62. How you would find that commit without reading it is bisection in history.

What the evidence says: test both fixes where they disagree

Two candidate fixes. The symptom patch makes the RAM store 0 whenever it is handed an unknown value. The cause fix gives FILL its reset back. In Icarus both look identical:

// snippet: the symptom patch, rtl/ram_slave.sv line 14
        if (write) mem[addr[11:2]] <= $isunknown(wdata) ? 32'h0 : wdata;  // symptom patch

1
2
3
4

// snippet: the cause fix, rtl/csr_block.sv: FILL joins the registers with a reset
      err_q <= 1'b0; err_addr_q <= '0; fill_q <= FILL_RST;      // in the reset branch
          CSR_FILL:    fill_q    <= wdata;                         // in the write case, which has a reset
      // ...and the CSR_FILL line is removed from the block without reset

Run random with seeds 1 to 60 for HEAD and each fix. Then run them again with XRAND=1 in Verilator, which starts every flip-flop without a reset at a random value, the way silicon powers up, instead of at X:

In Icarus the two fixes give exactly the same twelve failures, line for line; those twelve are a different bug, the one from the debug-loop lesson. A regression run only in a four-state simulator cannot tell the fixes apart. With random power-up values the patch fixes nothing:

$ cd symfix && XRAND=1 tb/run.sh random 17 verilator
dbglab: test=random seed=17
FAIL test=random seed=17 cycle=7949: SCOREBOARD: RAM word 816 (address 00001cc0) read 5d88e2dd, expected 00000000 (last written by DMA run #4)
$ cd ../causefix && XRAND=1 tb/run.sh random 17 verilator
dbglab: test=random seed=17
PASS test=random seed=17 cycles=18442 time=184416 ns

Same cycle, same word, same DMA run, but the value is now 5d88e2dd instead of X. In silicon there is no X: an unreset register powers up at whatever value it lands on. The patch only catches the simulator's picture of the fault. The real chip would fill the buffer with junk, and no check in the RAM can know that the junk is wrong. The cause fix passes, because the register now starts at the value the specification promises.

Traps

Related topics

• Part 0 · What Debugging Is

• The debug loop

• Guessing vs searching: finding cycle 488 without knowing where to look

• Part 2: Observe, including X in a waveform

• RTL: reset architecture