Monday morning: the weekend regression shows 300 failures. The team lead splits the list into five piles and hands one to each engineer. By lunch, three of them have found the same bug, a corrupted word in the DMA's data path, from three different tests and seeds. The fourth is still reading a 40 MB log from a test that failed for that same reason, an hour after it was already understood. How do you find out, before anyone opens a log, how many bugs those 300 failures really are?
A failing run's signature is a short description of its first failure: the severity, the message ID, and the message text with the run-specific parts (data words, times, counts) replaced by placeholders. Two runs with the same signature almost always fail for the same reason, whatever test or seed they came from. Triage is grouping failures into signature buckets, picking one run per bucket to debug, and giving each bucket an owner.
A hospital emergency room works the same way. Patients are not seen in arrival order; a nurse first sorts them by their main symptom, so that ten people with the same food poisoning are recognised as one outbreak instead of ten mysteries. The first error is the symptom: everything printed after it may be a consequence (once a word is wrong, a dozen checks downstream can fail with it), so later errors are noise for classification.
The nightly for this lesson is a real one: one build of the bench with the planted data-path bug (+define+DMA_BUG_WORD6, the sixth word of every job is corrupted), and 34 runs from it: dma_rand_test on seeds 1 to 20, dma_check_test on three seeds, seven other tests on seed 1, and four of the bench's broken-bench playbook tests, which stand in for unrelated bugs. Each run writes <test>.<seed>.log.
#!/usr/bin/env python3
"""Bucket regression logs by first-error signature. Usage: triage.py <test>.<seed>.log ..."""
import re, sys
from collections import defaultdict, Counter
FIRST = re.compile(r"^(UVM_ERROR|UVM_FATAL)\b.*?@ (\d+): .*?\[([\w./]+)\]\s*(.*)")
COUNT = re.compile(r"^(UVM_ERROR|UVM_FATAL) :\s+(\d+)")
def normalize(msg):
# every number or hex word becomes <n>, so seeds and data do not split a bucket
return re.sub(r"\b(0x)?[0-9a-fA-F]*\d[0-9a-fA-F]*\b", "<n>", msg).strip()[:64]
def triage(path):
first, counts = None, {}
for line in open(path, errors="replace"):
m = FIRST.match(line)
if m and first is None:
sev, t, rid, msg = m.groups()
first = (f"{sev} [{rid}] {normalize(msg)}", int(t))
c = COUNT.match(line)
if c:
counts[c.group(1)] = int(c.group(2))
if not counts: # no summary: crash, kill or wall-clock limit
return first or ("NO SUMMARY (crash or kill)", 0)
if counts.get("UVM_ERROR", 0) or counts.get("UVM_FATAL", 0):
return first or ("errors counted, none printed", 0)
return None # pass
buckets, passed = defaultdict(list), []
for path in sys.argv[1:]:
run = path.split("/")[-1].removesuffix(".log") # <test>.<seed>
r = triage(path)
if r is None:
passed.append(run)
else:
buckets[r[0]].append((r[1], run))
print(f"{len(sys.argv) - 1} runs: {len(passed)} pass, {sum(map(len, buckets.values()))} fail, "
f"{len(buckets)} signature(s)")
for sig, runs in sorted(buckets.items(), key=lambda kv: -len(kv[1])):
t, run = min(runs) # the earliest failure is the cheapest to debug
tests = Counter(r.rsplit(".", 1)[0] for _, r in runs)
print(f"\n{len(runs):3d} {sig}")
print(f" tests: " + ", ".join(f"{k} x{v}" for k, v in tests.most_common()))
print(f" debug first: {run} (fails at {t} ps)")
print("\npass: " + " ".join(sorted(passed)))Four decisions in that script carry the whole method:
The verdict comes from the summary counts, not from grepping for error lines. A log with no UVM_ERROR : line at all is a crash or a kill, and it fails with its own signature. Grepping for UVM_ERROR lines alone would call it a pass.
Only the first error is used. Later errors are often consequences of the first.
Normalisation keeps the meaning and drops the instance. expected 4735a210, got b8ca5def and expected db9b1c52, got 2464e3ad are the same bug; only the data differs. Times and counts are dropped for the same reason. The ID stays exactly as printed: the sequencer's error uses its full path as the ID, which is still a stable name.
The earliest failure is debugged first. The run that fails soonest in simulated time has the shortest log, the smallest waveform and the least history before the bug.
$ python3 triage.py nightly/*.log
34 runs: 4 pass, 30 fail, 5 signature(s)
26 UVM_ERROR [SB_MISMATCH] expected <n>, got <n>
tests: dma_rand_test x19, dma_check_test x3, dma_backpressure_test x1, dma_drain_test x1, dma_smoke_test x1, dma_vseq_test x1
debug first: dma_rand_test.16 (fails at 345000 ps)
1 UVM_ERROR [SB_EMPTY] no words were compared: the test checked nothing
tests: dma_early_end_test x1
debug first: dma_early_end_test.1 (fails at 155000 ps)
1 UVM_ERROR [uvm_test_top.env.in_agt.sqr] Get_next_item called twice without item_done or get in between
tests: dma_hang_noack_test x1
debug first: dma_hang_noack_test.1 (fails at 175000 ps)
1 UVM_FATAL [WATCHDOG] no bus activity for <n> while the test is still running; last ac
tests: dma_stall_watchdog_test x1
debug first: dma_stall_watchdog_test.1 (fails at 2500000 ps)
1 UVM_FATAL [PH_TIMEOUT] Explicit timeout of <n> hit, indicating a probable testbench iss
tests: dma_timeout_test x1
debug first: dma_timeout_test.1 (fails at 20000000 ps)
pass: dma_rand_test.20 dma_reset_test.1 dma_truncate_test.1 dma_zero_len_test.1Read it from the top. Thirty failures are five problems. The big bucket is the one-bug-many-seeds pattern: 26 runs across six different tests share one signature, and the right response is one ticket, not 26. The script points at dma_rand_test seed 16, which fails at 345 ns, as the cheapest run to debug. Each of the other four buckets is a single run, and each matches one of the playbooks in Debug Toolkit and Playbooks: an early end, a missing item_done, a stall caught by the watchdog, and a phase timeout.
The passing list is evidence too. dma_rand_test seed 20 passed because all three of its jobs were two words long; dma_reset_test, dma_truncate_test and dma_zero_len_test never move six words in one job. None of them can reach word 6, so their green tells you nothing about this bug. When you report "30 of 34 failed", say also which passing tests could not have seen it.
First-fail analysis. For each signature, find the first night it appeared and the commits that landed since the previous clean night. A signature that is new tonight points at those commits; one that has been there for a week is an old bug, which belongs to its existing ticket.
Dedup against open tickets. Keep a table of known signatures and their ticket numbers. New failures that match a known signature are attached to that ticket, which then shows its hit count growing or shrinking night by night.
Owners by signature, not by test. A scoreboard mismatch goes to the engineer who owns that checker and the designer of the block; a PH_TIMEOUT goes to whoever owns the test's end-of-test logic first. The owner of dma_rand_test is not automatically the owner of everything that fails in it.
Watch for buckets that are too wide. A signature like UVM_FATAL [PH_TIMEOUT] says only that something hung. When one bucket mixes several causes, add context to the signature: the last message before the timeout, or the component that still held an objection.
The first version of the triage script on this page replaced 8-digit hex words before decimal numbers, and printed the timeout as Explicit timeout of <hex> hit: the time value 20000000 is eight hex-looking digits. Harmless, but it was a hint that the normaliser was guessing. Removing normalisation entirely shows what is at stake. The same 34 logs, bucketed on the raw message text:
$ python3 triage_raw.py nightly/*.log (variant: no normalisation)
34 runs: 4 pass, 30 fail, 27 signature(s)
2 UVM_ERROR [SB_MISMATCH] expected 09d12529, got f62edad6
tests: dma_check_test x1, dma_rand_test x1
...One bug became 23 "distinct" scoreboard buckets, because every seed corrupts a different data word. (The one bucket of two exists only because dma_check_test and dma_rand_test draw the same jobs from the same seed.) Five engineers handed those buckets would have debugged the same bug five times, which is the opening scene of this lesson. The reverse mistake is as bad: a normaliser so aggressive that it strips the ID would merge a mismatch and a timeout into one bucket. Test your triage script on a night you have already triaged by hand, and check that the bucket count is what you expect.
SB_MISMATCH expected 0000002a, got 0000002b and SB_MISMATCH expected 00000000, got ffffffff. Should they be one bucket?With this normaliser, yes, and usually that is right: one checker, one ID, one kind of failure. But look at the data before closing the bucket: a single flipped low bit and an all-ones word may be different bugs. Signatures are a starting classification; once a bucket's first run is debugged, check a second run from the same bucket matches the root cause.
The old script passed any log without a UVM_ERROR line. A crashed or killed run prints nothing at the end, so it looked clean. Derive the verdict from the summary counts (or from a verdict line printed by report_summarize) and treat a missing summary as a failure with its own signature.
Usually both get an owner today, but the single-run bucket is easy to lose. The large one is probably one bug that will be fixed once; the single run may be a rare, deep corner that will not come back for a week. Size says how loud a bug is, not how important it is.
Next: triage needs logs, seeds and a consistent naming scheme from every run. Regression Infrastructure and CI is how those runs are produced.