The scoreboard knows where, not why

dbglab's random test fails with seed 10:

FAIL test=random seed=10 cycle=4895: SCOREBOARD: RAM word 808 (address 00001ca0) read d5202ff9, expected b6c3311c (last written by DMA run #29)

This is a good scoreboard message. It still names a RAM word, and the bug is not in the RAM. In the logging lesson it took a structured log and an awk script to move the blame to DMA run #29. What check would have named the DMA's counter itself, at the cycle it went wrong?

What people usually do, and why it fails

Teams that write assertions tend to write them in one of two places. Some put them at the outputs ("the RAM word read back must match"), which duplicates the scoreboard and fires just as late. Others copy the bus protocol rules from the spec, as dbglab's bus_rules.sv does for valid/ready. Those are valuable, but a DMA that writes 52 correct words instead of 308 breaks no bus rule at all, so they stay silent.

The checks that are missing are the ones on a block's own promises: when I start a run, my counter holds the length I was given. Nobody writes those because "the scoreboard will catch it." It does, later, and somewhere else.

The method: put the probe where the value is made

An assertion is a probe that is always on: it watches every cycle of every test and seed, and it costs almost nothing. Used in the Observe step, it reports the first wrong value instead of a late symptom:

1. Find where the value is created. Follow the bad data back to the first register that could hold it wrong. Here the copy length lives in left_q, loaded from cfg_len on start.

2. State the contract there. One cycle after a start, left_q equals the programmed length. Write it from the specification, never by copying the RTL line.

3. Add a cheap end-of-transaction check too. A run that ends without an error wrote LEN words. It fires later, but it catches causes you did not think of.

4. Make the message a bug report: rule name, cycle, the value seen, the value expected.

5. Bind it, and prove it runs. Keep checks in their own file, bound into the RTL module, and make each one fail once on purpose (or on a known bug) before you trust it to be silent.

The picture: three reports of one bug

Read it from right to left, the order in which you would otherwise debug: the scoreboard at 4895 names a RAM word, the end-of-run check at 4859 names the DMA run, and the check at the load, 452 cycles before the scoreboard, names the register and its two values.

Do it: bind two checks into the DMA

The checks, as concurrent SVA

The checks live in their own module. A bind statement instantiates it inside every dma_engine, and .* connects its ports to the DMA's signals of the same name; the internal left_q is connected by name explicitly, for a reason given below. The RTL is untouched.

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

// not-run: needs dbglab's sources; compile it with them in Verilator (command in the Evidence box)
// dma_checks: two always-on checks on dma_engine, bound into every instance of it.
//   A_LEN_LOAD  at the cause: the cycle after a start, the beat counter holds the programmed LEN
//   A_RUN_WORDS at the end:   a run that finishes without an error has written LEN words
// Concurrent SVA: runs in Verilator. Icarus 13 cannot compile it; see dma_checks_proc.sv.
`timescale 1ns/1ps
module dma_checks (
  input logic       clk, rst_n, start, busy, done, err,
  input logic [9:0] cfg_len,
  input logic [9:0] left_q,                 // dma_engine's beat counter, zero-extended
  input logic       m_valid, m_ready, m_write
);
  int unsigned writes;
  logic [9:0]  len_q;
  always @(posedge clk)
    if (start && !busy) begin writes <= 0; len_q <= cfg_len; end
    else if (m_valid && m_ready && m_write) writes <= writes + 1;

  a_len_load: assert property (@(posedge clk) disable iff (!rst_n)
                 start && !busy |=> left_q == $past(cfg_len))
    else $error("A_LEN_LOAD cycle=%0d: left_q=%0d, LEN was %0d", dbglab_tb.cycle, left_q, $past(cfg_len));
  a_run_words: assert property (@(posedge clk) disable iff (!rst_n)
                 done && !err |-> writes == len_q)
    else $error("A_RUN_WORDS cycle=%0d: run ended after %0d writes, LEN %0d", dbglab_tb.cycle, writes, len_q);
endmodule

bind dma_engine dma_checks u_chk (.*, .left_q(left_q));

Two details matter. The port left_q is declared 10 bits wide, the width of the length it must hold, not the 8 bits the RTL gave it; a narrower counter is zero-extended by the explicit .left_q(left_q) connection (an implicit .* connection needs equal widths), and the comparison sees the difference. And the expected value is $past(cfg_len), the input at the start, not a re-computation of the RTL's CW'(cfg_len), which would carry the bug into the check.

Run it in Verilator

$ ../probes/run-vl-check.sh ../probes/dma_checks.sv random 10
dbglab: test=random seed=10
[44435000] %Error: dma_checks.sv:20: Assertion failed in dbglab_tb.dut.u_dma.u_chk.a_len_load: A_LEN_LOAD cycle=4443: left_q=52, LEN was 308
%Error: ../probes/dma_checks.sv:20: Verilog $stop
Aborting...

Read it line by line. The time in brackets is 44,435 ns, cycle 4443, the first cycle after run #29's start. The hierarchical name says where: inside dbglab_tb.dut.u_dma. The message says what: the counter holds 52, the length was 308. That is the localised bug, 452 cycles before the scoreboard would have spoken, and nobody had to walk back. To see all three reports in one run, let the simulation continue past errors:

$ build/vlchk/Vdbglab_tb +TEST=random +SEED=10 +verilator+error+limit+10
dbglab: test=random seed=10
[44435000] %Error: dma_checks.sv:20: Assertion failed in dbglab_tb.dut.u_dma.u_chk.a_len_load: A_LEN_LOAD cycle=4443: left_q=52, LEN was 308
-Info: ../probes/dma_checks.sv:20: Verilog $stop, ignored due to +verilator+error+limit
[48595000] %Error: dma_checks.sv:23: Assertion failed in dbglab_tb.dut.u_dma.u_chk.a_run_words: A_RUN_WORDS cycle=4859: run ended after 52 writes, LEN 308
FAIL test=random seed=10 cycle=4895: SCOREBOARD: RAM word 808 (address 00001ca0) read d5202ff9, expected b6c3311c (last written by DMA run #29)
[48946000] %Fatal: dbglab_tb.sv:57: Assertion failed in dbglab_tb.fail: test failed
...

The same rules in Icarus

Icarus 13 is the course's main simulator, and it does not run concurrent assertions. On a three-line test module with the property a |=> b:

$ iverilog -g2012 -o t.vvp t.sv
t.sv:2: syntax error
t.sv:2: error: Error in property_spec of concurrent assertion item.
$ iverilog -g2012 -o t.vvp t.sv            # with the simpler property (a && !b)
t.sv:2: sorry: concurrent_assertion_item not supported. Try -gno-assertions or -gsupported-assertions to turn this message off.
$ iverilog -g2012 -gno-assertions -o t.vvp t.sv && vvp -n t.vvp
t.sv:3: $finish called at 52 (1s)

The last run is the dangerous one: the flag the error message suggests compiles the file, runs it, and checks nothing, without a word. For Icarus, write the same rules as clocked code that samples just before the edge, as an assertion does:

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)
// dma_checks_proc: the same two checks as dma_checks.sv, as clocked procedural code with
// hierarchical names, for Icarus 13 (no concurrent assertions, no bind).
`timescale 1ns/1ps
module dma_checks_proc;
  logic        start_q = 1'b0;
  logic [9:0]  len_q;
  int unsigned writes;
  always @(posedge dbglab_tb.clk) begin
    if (dbglab_tb.rst_n) begin
      if (start_q && dbglab_tb.dut.u_dma.left_q != len_q)
        $error("A_LEN_LOAD cycle=%0d: left_q=%0d, LEN was %0d", dbglab_tb.cycle, dbglab_tb.dut.u_dma.left_q, len_q);
      if (dbglab_tb.dut.u_dma.done && !dbglab_tb.dut.u_dma.err && writes != len_q)
        $error("A_RUN_WORDS cycle=%0d: run ended after %0d writes, LEN %0d", dbglab_tb.cycle, writes, len_q);
    end
    start_q <= dbglab_tb.dut.u_dma.start && !dbglab_tb.dut.u_dma.busy;
    if (dbglab_tb.dut.u_dma.start && !dbglab_tb.dut.u_dma.busy) begin
      len_q  <= dbglab_tb.dut.u_dma.cfg_len;
      writes <= 0;
    end else if (dbglab_tb.dut.u_dma.m_valid && dbglab_tb.dut.u_dma.m_ready && dbglab_tb.dut.u_dma.m_write)
      writes <= writes + 1;
  end
endmodule

$ ../probes/run-probe.sh ../probes/dma_checks_proc.sv random 10
dbglab: test=random seed=10
ERROR: ../probes/dma_checks_proc.sv:11: A_LEN_LOAD cycle=4443: left_q=52, LEN was 308
ERROR: ../probes/dma_checks_proc.sv:13: A_RUN_WORDS cycle=4859: run ended after 52 writes, LEN 308
FAIL test=random seed=10 cycle=4895: SCOREBOARD: RAM word 808 (address 00001ca0) read d5202ff9, expected b6c3311c (last written by DMA run #29)

Same cycles, same values, in both simulators. Icarus's $error reports and carries on, so all three reports appear in one run.

Is it a good probe? Check both ways

A probe is only useful if it fires on the bug and stays quiet otherwise. Over seeds 1 to 60 of random, A_LEN_LOAD fires in 10 seeds at HEAD, the ten that fail with a wrong value from this bug. With the counter widened (CW = 10) it fires in none of the 60, and it stays silent on every other test with seeds 1 to 3, including the three that still fail from other bugs.

What the evidence says

The scoreboard, the end-of-run check and the load check all saw the same bug. What differed was how much work each left you. The scoreboard's message started a hunt; the end-of-run check's message ended half of it; the load check's message was the localisation, in the cycle and register where the wrong value was born. That is the whole case for writing checks on a block's internal contracts: each one is a probe that is already in place on the day the bug arrives.

For reading a failing assertion in a waveform, sampled values and the usual misreadings, see the SystemVerilog course's assertion debug lessons; the RTL course's SVA cheat sheet and bug hunt covers the syntax.

Traps

Related topics

• Part 2 · Observe

• Scoreboards report late

• SystemVerilog: assertion debug

• RTL: SVA cheat sheet and bug hunt

• Part 9: fix, prove, prevent