Why does the same bug cost a week?

Two engineers meet the same kind of bug, a register left out of reset. The first sees it as an X in her block simulation on a Tuesday afternoon and fixes it before she goes home. The second meets it as "the buffer sometimes holds garbage after power-up" from the bring-up lab, three months after tape-out. Same line of RTL. Why does the second one cost a week of five people's time and, possibly, a new set of masks?

What people usually do, and why it fails

Teams under schedule pressure treat verification as a gate to pass rather than a search for bugs: "the regression is green, ship it to integration". Bugs are then found wherever they happen to show, and each one is debugged with whatever that stage offers. The cost is invisible because it lands on other people, later. The usual result is a bug found in emulation or the lab that an assertion or a targeted test would have shown in block simulation in minutes.

The method: know the curve, act on it

Every stage of a chip's life can find bugs. What changes from one to the next is how long a debug run takes, how many people must be involved, how much of the design you can see, and what a fix costs. The table is illustrative: real numbers depend on the project, the team and the tools, but the direction is the same everywhere.

Three rules follow from the curve:

1. Spend effort early. A check that finds a bug in RTL is worth more than the same check at integration, because every later run costs more. Assertions, lint and targeted tests are cheapest where the curve is lowest.

2. Move the failure back. When a late stage finds a bug, the first job is to reproduce it in the cheapest stage that can show it, usually simulation. Debugging in a late stage is a last resort. Part 6 covers this for each stage.

3. Buy visibility before you need it. Later stages see less. Debug registers, counters and trace hooks designed in at RTL are what let the lab see anything at all.

The picture: the cost curve

The vertical axis is logarithmic, so each grid line is ten times the one below. The rule of thumb many teams use, "ten times dearer per stage", is a habit of speech rather than a law, but no project reports the curve going down.

Do it: one bug, two levels of visibility

Most of that curve cannot be run here: there is no emulator, no gate-level flow for dbglab and no lab. One part of it can be measured honestly: what happens to the number of experiments when visibility drops. Take one real failure, dbglab's random test with seed 17, and localise it twice.

With full visibility: one dump, one script

In simulation you can record every signal. DUMP=1 writes a VCD; a short script then asks the question that matters for an unknown value: which signals were unknown when reset ended, and which turned unknown later, in what order?

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
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54

# not-run: reads the VCD that dbglab writes with DUMP=1 (output below is from a real run)
"""Where do unknowns come from? Reads a VCD and lists, for the design under dbglab_tb.dut:
  1. the signals still unknown (x or z) when reset is released;
  2. the signals that turn unknown later, after holding a known value, earliest first.
usage: first_x.py <file.vcd> [how-many]
Cycle n is the time from the n-th rising edge of dbglab_tb.clk to the next, as the bench counts."""
import sys

path, limit = sys.argv[1], int(sys.argv[2]) if len(sys.argv) > 2 else 12
names, scope, vals = {}, [], {}
at_reset, later = [], {}                     # later: name -> (cycle, time)
clk_id = rst_id = None
released, cycle, rst_cycle = False, 0, 0
unknown = lambda v: any(c in "xXzZ" for c in v)

def step(t, changes):                        # all changes of one time step; the clock edge first
    global cycle, released, rst_cycle, at_reset
    for v, code in changes:
        if code == clk_id and v == "1" and vals.get(code) == "0": cycle += 1
    for v, code in changes:
        if code == rst_id and v == "1" and not released:
            released, rst_cycle = True, cycle
            at_reset = sorted(n for c, val in vals.items() if unknown(val) for n in names.get(c, []))
        if released and unknown(v) and code in vals and not unknown(vals[code]):
            for n in names.get(code, []): later.setdefault(n, (cycle, t))
        vals[code] = v

with open(path) as f:
    for line in f:                           # header: identifier code -> full names
        w = line.split()
        if not w: continue
        if w[0] == "$scope": scope.append(w[2])
        elif w[0] == "$upscope": scope.pop()
        elif w[0] == "$var":
            full = ".".join(scope + [w[4]])
            if full.startswith("dbglab_tb.dut."): names.setdefault(w[3], []).append(full)
            if full == "dbglab_tb.rst_n": rst_id = w[3]
            if full == "dbglab_tb.clk": clk_id = w[3]
        elif w[0] == "$enddefinitions": break
    t, changes = 0, []
    for line in f:                           # value changes, one time step at a time
        line = line.strip()
        if not line or line[0] == "$": continue
        if line[0] == "#":
            step(t, changes); t, changes = int(line[1:]), []; continue
        changes.append(tuple(line[1:].split()) if line[0] in "bBrR" else (line[0], line[1:]))
    step(t, changes)

print(f"unknown at reset release (cycle {rst_cycle}): {len(at_reset)} signals")
for n in at_reset[:limit]: print("  " + n)
if len(at_reset) > limit: print(f"  ... {len(at_reset) - limit} more")
print(f"turned unknown later: {len(later)} signals, earliest first")
for n, (c, tt) in sorted(later.items(), key=lambda kv: (kv[1][1], kv[0]))[:limit]:
    print(f"  cycle {c:5d}  {n}")

$ DUMP=1 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)
$ python3 ../tools/first_x.py dbglab.vcd 12
unknown at reset release (cycle 4): 20 signals
  dbglab_tb.dut.dma_dst
  dbglab_tb.dut.dma_fill
...
  dbglab_tb.dut.u_csr.dst_q
  dbglab_tb.dut.u_csr.fill_q
  dbglab_tb.dut.u_csr.len_q
  dbglab_tb.dut.u_csr.src_q
  ... 8 more
turned unknown later: 19 signals, earliest first
  cycle    31  dbglab_tb.dut.u_dma.fill_val_q
  cycle   486  dbglab_tb.dut.m_wdata
  cycle   486  dbglab_tb.dut.u_dma.m_wdata
  cycle   486  dbglab_tb.dut.u_dma.wdata_q
  cycle   486  dbglab_tb.dut.u_fab.m_wdata
  cycle   488  dbglab_tb.dut.s_wdata
...
  cycle   488  dbglab_tb.dut.u_ram.wdata
  cycle  7948  dbglab_tb.dut.cpu_rdata

Read the second list as a chain. The DMA's copy of the fill value goes unknown at cycle 31, when DMA run #1 latches it (harmless until a fill uses it). At cycle 486 the DMA's write data goes unknown, at 488 it reaches the RAM's write port, and at 7948 the RAM's read data, which the bench reports a cycle later. The first list says where the chain can start: four CSR registers (SRC, DST, LEN and FILL) are unknown when reset ends, with the wires that carry them and the peripheral FIFO's read data, and the chain uses one of them, u_csr.fill_q. (Reset is released during cycle 4; the probe in the previous lesson samples at the next edge and says cycle 5.) One simulation and one script, together about 0.4 seconds, name the signal and the cycle. (The register map says FILL resets to 0, which makes this the fault; the previous lesson walks the same chain with a probe.)

With pass or fail only

Now take away the inside view, as the lab would. Silicon has no X: an unreset flip-flop powers up at whatever value it lands on. Verilator's XRAND=1 mode models that by starting every unreset flip-flop at a random value, chosen by a seed. Run the same test, then power it up five more times with different start values:

$ 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)
$ for n in 1 2 3 4 5; do build/vl/Vdbglab_tb +TEST=random +SEED=17 +verilator+rand+reset+2 +verilator+seed+$n | grep -E '^(PASS|FAIL)'; done
FAIL test=random seed=17 cycle=7949: SCOREBOARD: RAM word 816 (address 00001cc0) read 8f27a164, expected 00000000 (last written by DMA run #4)
FAIL test=random seed=17 cycle=7949: SCOREBOARD: RAM word 816 (address 00001cc0) read 0b8ad843, expected 00000000 (last written by DMA run #4)
FAIL test=random seed=17 cycle=7949: SCOREBOARD: RAM word 816 (address 00001cc0) read 1c50f669, expected 00000000 (last written by DMA run #4)
FAIL test=random seed=17 cycle=7949: SCOREBOARD: RAM word 816 (address 00001cc0) read 3e4e8947, expected 00000000 (last written by DMA run #4)
FAIL test=random seed=17 cycle=7949: SCOREBOARD: RAM word 816 (address 00001cc0) read b95cf52d, expected 00000000 (last written by DMA run #4)

A different wrong value at every power-up. Without the word xxxxxxxx there is nothing to say "uninitialised"; it looks like memory corruption, or a flaky board. And this is still generous: a real chip has no scoreboard naming the DMA run that last wrote the word.

Suppose all you have is whether a run passes, and one knob, the number of operations. The halving search from guessing vs searching still works:

$ XRAND=1 SIM=verilator python3 ../search/ops_search.py halve 17 1500
run    1: OPS= 750 FAIL   suspects left:  750 (ops 1..750)
run    2: OPS= 375 FAIL   suspects left:  375 (ops 1..375)
...
run   10: OPS=  44 pass   suspects left:    2 (ops 45..46)
run   11: OPS=  45 FAIL   suspects left:    1 (ops 45..45)
11 runs: operation 45 is the first that leaves the design wrong

Eleven runs to learn that operation 45, a DMA start, leaves the RAM wrong. That is an operation, not a signal. The next experiments would need hypotheses: read the DMA's registers back through software after reset, try the run with FILL written first, and so on, each one another run.

What the evidence says

In this design every run is cheap, so both columns finish in seconds. Multiply the run counts by the illustrative cost of a run at each stage: 11 runs at a second each is nothing; 11 lab sessions with a team at the bench is a week. That is how the curve is made: lower visibility multiplies the number of runs, and later stages multiply the cost of each run.

Traps

Related topics

• Part 0 · What Debugging Is

• Guessing vs searching: the halving search used here

• Part 6: debug by stage

• Bring-up: failure triage in the lab

• Bring-up: debug interfaces