Python Part II · Module 35 · Industry VLSI Automation Projects

A UVM Failure Triager

A nightly regression comes back with fourteen failing runs. The question nobody can answer from the summary is the only question worth asking: how many things are actually broken? This chapter builds the tool that answers it, starting from the one-line version every team already has, and the measurement that forces each change is the number of buckets the tool reports — which turns out to depend far more on which failure you key on than on how cleverly you normalise it.

Advanced26 min readPythonPart IIAutomationUVMTriage

Part II · Module 35 · Chapter 35.1 · A UVM Failure Triager

1. The Question the Summary Cannot Answer

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

QUESTIONS = [
    ("how many runs failed?", "the summary", "yes"),
    ("which tests failed?", "the summary", "yes"),
    ("how many THINGS are broken?", "nothing", "no"),
    ("is this the same bug as yesterday?", "nothing", "no"),
    ("which run should I debug first?", "nothing", "no"),
]

print(f"{'the question':<38} {'answered by':<14} answerable today")
for q, by, ok in QUESTIONS:
    print(f"{q:<38} {by:<14} {ok}")

print()
print("questions the summary answers:", 2)
print("questions a lead actually asks:", 3)
print("and all three reduce to       :", "group the failures by cause")

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

the question                           answered by    answerable today
how many runs failed?                  the summary    yes
which tests failed?                    the summary    yes
how many THINGS are broken?            nothing        no
is this the same bug as yesterday?     nothing        no
which run should I debug first?        nothing        no

questions the summary answers: 2
questions a lead actually asks: 3
and all three reduce to       : group the failures by cause

All three unanswered questions reduce to one operation: group the failures by cause. Fourteen failing runs might be fourteen bugs or one bug, and the difference decides whether the morning is spent debugging or filing.

2. The Annotation

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

triage(logs) -> {bucket: [Failure, ...]}

The signature is the design. It takes logs — not paths, so the pure layer of Chapter 34.3 applies. It returns a mapping from bucket to failures, so the grouping is the product rather than a report. And the values are Failure objects rather than strings, so a caller can sort, count and name the worst one.

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

SHAPES = [
    ("triage(paths) -> report text", "no", "two jobs, and it reads files"),
    ("triage(logs) -> count", "no", "throws the grouping away"),
    ("triage(logs) -> [Failure]", "no", "ungrouped — the caller re-does it"),
    ("triage(logs) -> {bucket: [Failure]}", "yes", "the annotation"),
]

print(f"{'candidate signature':<40} {'right':<7} why")
for sig, ok, why in SHAPES:
    print(f"{sig:<40} {ok:<7} {why}")

print()
print("what the return type lets a caller do:",
      ["count buckets", "sort by size", "name a representative",
       "diff against yesterday"])
print("what a count would have allowed    :", "none of it")

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

candidate signature                      right   why
triage(paths) -> report text             no      two jobs, and it reads files
triage(logs) -> count                    no      throws the grouping away
triage(logs) -> [Failure]                no      ungrouped — the caller re-does it
triage(logs) -> {bucket: [Failure]}      yes     the annotation

what the return type lets a caller do: ['count buckets', 'sort by size', 'name a representative', 'diff against yesterday']
what a count would have allowed    : none of it

3. The First Version

Every team has this, and it is a reasonable place to start:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

LOG_TABLE = [
    # (run name, severity, file, message template, time, seed)
    ("burst_4121", "UVM_ERROR", "drv.sv(88)",
     "data mismatch exp=0xa5 got=0x5a", 1000),
    ("burst_7734", "UVM_ERROR", "drv.sv(89)",
     "data mismatch exp=0xa6 got=0x5b", 1137),
    ("burst_9001", "UVM_ERROR", "drv.sv(90)",
     "data mismatch exp=0xa7 got=0x5c", 1274),
    ("burst_1337", "UVM_ERROR", "drv.sv(91)",
     "data mismatch exp=0xa8 got=0x5d", 1411),
    ("lite_4121", "UVM_ERROR", "mon.sv(12)",
     "response timeout after 500 cycles", 2000),
    ("lite_7734", "UVM_ERROR", "mon.sv(13)",
     "response timeout after 510 cycles", 2211),
    ("lite_9001", "UVM_ERROR", "mon.sv(14)",
     "response timeout after 520 cycles", 2422),
    ("lite_1337", "UVM_ERROR", "mon.sv(15)",
     "response timeout after 530 cycles", 2633),
    ("lite_2024", "UVM_ERROR", "mon.sv(16)",
     "response timeout after 540 cycles", 2844),
    ("wrap_4121", "UVM_FATAL", "env.sv(3)",
     "virtual interface not set for agent[0]", 50),
    ("wrap_7734", "UVM_FATAL", "env.sv(4)",
     "virtual interface not set for agent[1]", 57),
    ("wrap_9001", "UVM_FATAL", "env.sv(5)",
     "virtual interface not set for agent[2]", 64),
    ("burst2_555", "UVM_ERROR", "drv.sv(92)",
     "burst length 4 unsupported for wrap", 3000),
    ("burst2_666", "UVM_ERROR", "drv.sv(93)",
     "burst length 5 unsupported for wrap", 3053),
]


def make_log(name, sev, where, msg, t):
    """A realistic log: a header, the real failure, then a consequence."""
    seed = name.split("_")[-1]
    return (f"UVM_INFO @0: tb.sv(1) UVM_TESTNAME={name.rsplit('_', 1)[0]}_test "
            f"ntb_random_seed={seed}\n"
            f"UVM_INFO @{max(0, t - 100)}: mon.sv(5) traffic started\n"
            f"{sev} @{t}: {where} {msg}\n"
            f"UVM_ERROR @{t + 50}: scb.sv(12) scoreboard drained with 1 pending\n"
            f"UVM_ERROR :    2\n"
            f"TEST DONE\n")


LOGS = {row[0]: make_log(*row) for row in LOG_TABLE}

# --- v1: the one-liner, in Python
def v1_count_errors(logs):
    return sum(1 for text in logs.values()
               for line in text.splitlines()
               if line.startswith("UVM_ERROR") and "UVM_ERROR :" not in line)


print("runs in the regression       :", len(LOGS))
print("real root causes (by design) :", 4)
print()
print("v1 — grep -c UVM_ERROR, summed:", v1_count_errors(LOGS))
print("what that number tells you   :", "that something is wrong")
print("what it does not tell you    :", "how many things")
print()
print("note the count exceeds the run count because:",
      "each log has a consequence error too")

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

runs in the regression       : 14
real root causes (by design) : 4

v1 — grep -c UVM_ERROR, summed: 25
what that number tells you   : that something is wrong
what it does not tell you    : how many things

note the count exceeds the run count because: each log has a consequence error too

Twenty-five error lines from fourteen runs with four causes. The number is correct and answers none of Section 1's questions — and its composition is the first hint of the real problem: fourteen of those twenty-five are the scoreboard noticing that something already went wrong, one per run, and only eleven are causes. The other three runs fail with UVM_FATAL, which a count of UVM_ERROR lines does not see at all.

Chapter 24.3's UVM_ERROR : exclusion is already in place, so this is the good version of the one-liner. The limitation is structural, not a bug.

4. The Limitation That Forces a Change

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

import collections
import re

# the same fourteen logs, built by the §3 table
LOG_TABLE = [
    ("burst_4121", "UVM_ERROR", "drv.sv(88)", "data mismatch exp=0xa5 got=0x5a", 1000),
    ("burst_7734", "UVM_ERROR", "drv.sv(89)", "data mismatch exp=0xa6 got=0x5b", 1137),
    ("burst_9001", "UVM_ERROR", "drv.sv(90)", "data mismatch exp=0xa7 got=0x5c", 1274),
    ("burst_1337", "UVM_ERROR", "drv.sv(91)", "data mismatch exp=0xa8 got=0x5d", 1411),
    ("lite_4121", "UVM_ERROR", "mon.sv(12)", "response timeout after 500 cycles", 2000),
    ("lite_7734", "UVM_ERROR", "mon.sv(13)", "response timeout after 510 cycles", 2211),
    ("lite_9001", "UVM_ERROR", "mon.sv(14)", "response timeout after 520 cycles", 2422),
    ("lite_1337", "UVM_ERROR", "mon.sv(15)", "response timeout after 530 cycles", 2633),
    ("lite_2024", "UVM_ERROR", "mon.sv(16)", "response timeout after 540 cycles", 2844),
    ("wrap_4121", "UVM_FATAL", "env.sv(3)", "virtual interface not set for agent[0]", 50),
    ("wrap_7734", "UVM_FATAL", "env.sv(4)", "virtual interface not set for agent[1]", 57),
    ("wrap_9001", "UVM_FATAL", "env.sv(5)", "virtual interface not set for agent[2]", 64),
    ("burst2_555", "UVM_ERROR", "drv.sv(92)", "burst length 4 unsupported for wrap", 3000),
    ("burst2_666", "UVM_ERROR", "drv.sv(93)", "burst length 5 unsupported for wrap", 3053),
]


def make_log(name, sev, where, msg, t):
    seed = name.split("_")[-1]
    return (f"UVM_INFO @0: tb.sv(1) ntb_random_seed={seed}\n"
            f"{sev} @{t}: {where} {msg}\n"
            f"UVM_ERROR @{t + 50}: scb.sv(12) scoreboard drained with 1 pending\n"
            f"UVM_ERROR :    2\nTEST DONE\n")


LOGS = {row[0]: make_log(*row) for row in LOG_TABLE}

FAILURE = re.compile(r"^(UVM_ERROR|UVM_FATAL)\s+@(\d+):\s+(\S+)\s+(.*)$")


def first_failure_raw(text):
    for line in text.splitlines():
        m = FAILURE.match(line)
        if m and f"{m.group(1)} :" not in line:
            return m.group(4)
    return None


buckets = collections.Counter(first_failure_raw(t) for t in LOGS.values())

print("grouping on the RAW first-failure message")
print("  runs            :", len(LOGS))
print("  distinct buckets:", len(buckets))
print("  real causes     :", 4)
print()
print("  bucket sizes    :", sorted(buckets.values(), reverse=True))
print()
print("  so the tool reports:", len(buckets), "problems")
print("  and the truth is   :", 4)
print("  why               :", "exp=0xa5 and exp=0xa6 are different strings")

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

grouping on the RAW first-failure message
  runs            : 14
  distinct buckets: 14
  real causes     : 4

  bucket sizes    : [1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1]

  so the tool reports: 14 problems
  and the truth is   : 4
  why               : exp=0xa5 and exp=0xa6 are different strings

Fourteen buckets of one. Grouping by the exact message is no better than not grouping: every run's failure carries a seed-dependent address, a data value and a time, so no two are string-equal.

That is the limitation that forces the architecture. A bucket key has to be a deliberately lossy function of the failure — it must discard exactly the fields that vary between runs of the same bug and keep the fields that distinguish different bugs. Section 7 is how you find that line.

5. The Architecture

Five stages, one direction

Each log is streamed and abandoned as soon as its first failure is found, so the triager's memory holds one `Failure` per run rather than one log. The normaliser is the only stage with a tuning decision in it, and Section 7 measures where to set it.

Two stages deserve a note before the code. Stream lines is a generator because a simulation log is routinely larger than memory — Chapter 20.6's argument — and the triager never needs the whole file, only the prefix up to the first failure. And Bucket keys on a triple rather than on the message alone, which Section 7 shows is what makes the normaliser's exact setting much less critical than it looks.

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

import re
from dataclasses import dataclass


@dataclass(frozen=True)
class Failure:
    """One run's first real failure. Frozen: a bucket key must not move."""
    run: str
    severity: str
    where: str
    message: str
    time: int

    @property
    def key(self):
        """The bucket key: severity, file without a line number, normalised."""
        return (self.severity, strip_line_number(self.where),
                normalise(self.message))


FAILURE = re.compile(r"^(UVM_ERROR|UVM_FATAL)\s+@(\d+):\s+(\S+)\s+(.*)$")
LINE_NO = re.compile(r"\(\d+\)")
HEX = re.compile(r"0x[0-9a-fA-F]+")
INT = re.compile(r"\b\d+\b")


def strip_line_number(where):
    return LINE_NO.sub("(N)", where)


def normalise(message):
    return INT.sub("N", HEX.sub("0xH", message))


def stream_failures(run, lines):
    """Yield every real failure, lazily. The caller decides when to stop."""
    for line in lines:
        m = FAILURE.match(line)
        if m and f"{m.group(1)} :" not in line:
            yield Failure(run=run, severity=m.group(1), time=int(m.group(2)),
                          where=m.group(3), message=m.group(4))


def first_failure(run, text):
    """Reads the prefix only — next() abandons the generator."""
    return next(stream_failures(run, text.splitlines()), None)


SAMPLE = ("UVM_INFO @0: tb.sv(1) ntb_random_seed=4121\n"
          "UVM_ERROR @1000: drv.sv(88) data mismatch exp=0xa5 got=0x5a\n"
          "UVM_ERROR @1050: scb.sv(12) scoreboard drained with 1 pending\n"
          "UVM_ERROR :    2\nTEST DONE\n")

f = first_failure("burst_4121", SAMPLE)
print("the Failure object:")
for field in ("run", "severity", "where", "message", "time"):
    print(f"  {field:<10} {getattr(f, field)!r}")
print()
print("its bucket key:")
for part in f.key:
    print(f"  {part!r}")
print()
print("severity lines in the log :", 2)
print("Failure objects built     :", 1)
print("because next() takes      :", "the first and abandons the generator")

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

the Failure object:
  run        'burst_4121'
  severity   'UVM_ERROR'
  where      'drv.sv(88)'
  message    'data mismatch exp=0xa5 got=0x5a'
  time       1000

its bucket key:
  'UVM_ERROR'
  'drv.sv(N)'
  'data mismatch exp=0xH got=0xH'

severity lines in the log : 2
Failure objects built     : 1
because next() takes      : the first and abandons the generator

One Failure built from a log containing two severity lines. next() on a generator consumes exactly one item, so the rest of the file is never read — which is the property that makes this work on a 2 GB log and is lost the moment somebody writes list(stream_failures(...))[0].

The Failure is frozen because its key is used as a dictionary key. Chapter 34.4 Section 9's typo protection is a side benefit; the real reason is that a mutable object whose hash depends on its fields is a bucket that can move after it has been filed.

6. First Failure, Not Last

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

import collections
import re
from dataclasses import dataclass

LOG_TABLE = [
    ("burst_4121", "UVM_ERROR", "drv.sv(88)", "data mismatch exp=0xa5 got=0x5a", 1000),
    ("burst_7734", "UVM_ERROR", "drv.sv(89)", "data mismatch exp=0xa6 got=0x5b", 1137),
    ("burst_9001", "UVM_ERROR", "drv.sv(90)", "data mismatch exp=0xa7 got=0x5c", 1274),
    ("burst_1337", "UVM_ERROR", "drv.sv(91)", "data mismatch exp=0xa8 got=0x5d", 1411),
    ("lite_4121", "UVM_ERROR", "mon.sv(12)", "response timeout after 500 cycles", 2000),
    ("lite_7734", "UVM_ERROR", "mon.sv(13)", "response timeout after 510 cycles", 2211),
    ("lite_9001", "UVM_ERROR", "mon.sv(14)", "response timeout after 520 cycles", 2422),
    ("lite_1337", "UVM_ERROR", "mon.sv(15)", "response timeout after 530 cycles", 2633),
    ("lite_2024", "UVM_ERROR", "mon.sv(16)", "response timeout after 540 cycles", 2844),
    ("wrap_4121", "UVM_FATAL", "env.sv(3)", "virtual interface not set for agent[0]", 50),
    ("wrap_7734", "UVM_FATAL", "env.sv(4)", "virtual interface not set for agent[1]", 57),
    ("wrap_9001", "UVM_FATAL", "env.sv(5)", "virtual interface not set for agent[2]", 64),
    ("burst2_555", "UVM_ERROR", "drv.sv(92)", "burst length 4 unsupported for wrap", 3000),
    ("burst2_666", "UVM_ERROR", "drv.sv(93)", "burst length 5 unsupported for wrap", 3053),
]


def make_log(name, sev, where, msg, t):
    return (f"UVM_INFO @0: tb.sv(1) ntb_random_seed={name.split('_')[-1]}\n"
            f"{sev} @{t}: {where} {msg}\n"
            f"UVM_ERROR @{t + 50}: scb.sv(12) scoreboard drained with 1 pending\n"
            f"UVM_ERROR :    2\nTEST DONE\n")


LOGS = {row[0]: make_log(*row) for row in LOG_TABLE}

FAILURE = re.compile(r"^(UVM_ERROR|UVM_FATAL)\s+@(\d+):\s+(\S+)\s+(.*)$")
LINE_NO, HEX, INT = re.compile(r"\(\d+\)"), re.compile(r"0x[0-9a-fA-F]+"), \
                    re.compile(r"\b\d+\b")


def key_of(sev, where, msg):
    return (sev, LINE_NO.sub("(N)", where), INT.sub("N", HEX.sub("0xH", msg)))


def all_failures(text):
    out = []
    for line in text.splitlines():
        m = FAILURE.match(line)
        if m and f"{m.group(1)} :" not in line:
            out.append((m.group(1), m.group(3), m.group(4)))
    return out


for which, index in (("FIRST", 0), ("LAST", -1)):
    buckets = collections.defaultdict(list)
    for run, text in LOGS.items():
        sev, where, msg = all_failures(text)[index]
        buckets[key_of(sev, where, msg)].append(run)
    print(f"keyed on the {which} failure -> {len(buckets)} bucket(s)")
    for key, runs in sorted(buckets.items(), key=lambda kv: -len(kv[1])):
        print(f"   {len(runs):>2} runs  {key[0]:<10} {key[1]:<10} {key[2][:40]}")
    print()

print("real root causes :", 4)
print("FIRST gives      :", 4)
print("LAST gives       :", 1)
print("the last error is:", "the scoreboard noticing — a consequence")

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

keyed on the FIRST failure -> 4 bucket(s)
    5 runs  UVM_ERROR  mon.sv(N)  response timeout after N cycles
    4 runs  UVM_ERROR  drv.sv(N)  data mismatch exp=0xH got=0xH
    3 runs  UVM_FATAL  env.sv(N)  virtual interface not set for agent[N]
    2 runs  UVM_ERROR  drv.sv(N)  burst length N unsupported for wrap

keyed on the LAST failure -> 1 bucket(s)
   14 runs  UVM_ERROR  scb.sv(N)  scoreboard drained with N pending

real root causes : 4
FIRST gives      : 4
LAST gives       : 1
the last error is: the scoreboard noticing — a consequence

Four buckets against one, from the same logs and the same normaliser. The only difference is an index, and keying on the last failure reports that all fourteen runs have the same problem — a scoreboard that drained with something pending, which is true of all of them and explains none of them.

That is why the annotation's Failure is the first one. A UVM log is roughly causal in time: the driver sees a mismatch, then the scoreboard notices, then the test times out, then the environment complains at the end of the run. The last error is reliably the most generic, which makes it the worst possible bucket key and the easiest one to reach for — tail is shorter than head to reason about when you are looking at a 40,000-line log.

7. Finding the Normalisation Level

The normaliser has a dial on it, and the obvious worry is setting it too high — mask so much that different bugs look alike. Measuring it does not show that:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

import re

MESSAGES = [
    "data mismatch exp=0xa5 got=0x5a", "data mismatch exp=0xa6 got=0x5b",
    "data mismatch exp=0xa7 got=0x5c", "data mismatch exp=0xa8 got=0x5d",
    "response timeout after 500 cycles", "response timeout after 510 cycles",
    "response timeout after 520 cycles", "response timeout after 530 cycles",
    "response timeout after 540 cycles",
    "virtual interface not set for agent[0]",
    "virtual interface not set for agent[1]",
    "virtual interface not set for agent[2]",
    "burst length 4 unsupported for wrap",
    "burst length 5 unsupported for wrap",
]
WHERE = ["drv.sv(88)", "drv.sv(89)", "drv.sv(90)", "drv.sv(91)",
         "mon.sv(12)", "mon.sv(13)", "mon.sv(14)", "mon.sv(15)", "mon.sv(16)",
         "env.sv(3)", "env.sv(4)", "env.sv(5)",
         "drv.sv(92)", "drv.sv(93)"]
SEV = ["UVM_ERROR"] * 9 + ["UVM_FATAL"] * 3 + ["UVM_ERROR"] * 2

HEX, INT, WORD = (re.compile(r"0x[0-9a-fA-F]+"), re.compile(r"\b\d+\b"),
                  re.compile(r"[A-Za-z_]+"))
LINE_NO = re.compile(r"\(\d+\)")

LEVELS = [
    ("none", lambda m: m),
    ("hex", lambda m: HEX.sub("0xH", m)),
    ("hex + integers", lambda m: INT.sub("N", HEX.sub("0xH", m))),
    ("+ words too", lambda m: WORD.sub("W", INT.sub("N", HEX.sub("0xH", m)))),
]

print(f"{'normalisation':<16} {'message-only key':>17} {'triple key':>12}")
for label, fn in LEVELS:
    only = len({fn(m) for m in MESSAGES})
    triple = len({(s, LINE_NO.sub("(N)", w), fn(m))
                  for s, w, m in zip(SEV, WHERE, MESSAGES)})
    print(f"{label:<16} {only:>17} {triple:>12}")

print()
print("real root causes      :", 4)
print("the count stops moving at:", "hex + integers")
print("and stays there when you :", "normalise harder")

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

normalisation     message-only key   triple key
none                            14           14
hex                             11           11
hex + integers                   4            4
+ words too                      4            4

real root causes      : 4
the count stops moving at: hex + integers
and stays there when you : normalise harder

The bucket count plateaus at four and does not collapse. That is not what I expected to measure, and it changes the advice. Masking words as well as integers — an absurdly aggressive normaliser — still reports four buckets, because once the volatile fields are gone the four messages differ in their structure, and the key's other two components (severity and file) differ anyway.

So the useful technique is a plateau sweep rather than a search for a delicate optimum:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

SWEEP = [("none", 14), ("hex", 11), ("hex + integers", 4), ("+ words too", 4)]

print(f"{'level':<16} {'buckets':>8} {'still dropping?':>17} verdict")
prev = None
for label, n in SWEEP:
    dropping = "—" if prev is None else str(n < prev)
    verdict = ("baseline" if prev is None else
               "under-normalised" if n < prev else "plateau — stop here")
    print(f"{label:<16} {n:>8} {dropping:>17} {verdict}")
    prev = n

print()
print("the rule:")
print("  still dropping -> you are under-normalising; mask more")
print("  stopped        -> you have reached the structural cause count")
print()
print("what under-normalisation costs:", "14 tickets for 4 bugs")
print("what the plateau tells you    :", "masking more cannot help")
print("what it does NOT prove        :",
      "that 4 is right — only that the key is stable")

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

level             buckets   still dropping? verdict
none                   14                 — baseline
hex                    11              True under-normalised
hex + integers          4              True under-normalised
+ words too             4             False plateau — stop here

the rule:
  still dropping -> you are under-normalising; mask more
  stopped        -> you have reached the structural cause count

what under-normalisation costs: 14 tickets for 4 bugs
what the plateau tells you    : masking more cannot help
what it does NOT prove        : that 4 is right — only that the key is stable

Under-normalisation is the real and common failure mode, and the plateau is how you detect that you have left it. The last printed line is the honest limit: a plateau says the key has stopped being sensitive to the dial, not that the grouping is semantically correct — two genuinely different bugs that produce structurally identical messages will share a bucket at every level, and only a human reading the representative run will notice.

That is why the report in Section 8 prints a representative run name for each bucket rather than only a count: the cheapest check on a bucket is to open one of its logs.

8. The Triager, Assembled

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

import re
from collections import defaultdict
from dataclasses import dataclass

FAILURE = re.compile(r"^(UVM_ERROR|UVM_FATAL)\s+@(\d+):\s+(\S+)\s+(.*)$")
LINE_NO = re.compile(r"\(\d+\)")
HEX = re.compile(r"0x[0-9a-fA-F]+")
INT = re.compile(r"\b\d+\b")
SEVERITY_RANK = ("UVM_FATAL", "UVM_ERROR")


def normalise(message):
    return INT.sub("N", HEX.sub("0xH", message))


@dataclass(frozen=True)
class Failure:
    run: str
    severity: str
    where: str
    message: str
    time: int

    @property
    def key(self):
        return (self.severity, LINE_NO.sub("(N)", self.where),
                normalise(self.message))


def stream_failures(run, lines):
    for line in lines:
        m = FAILURE.match(line)
        if m and f"{m.group(1)} :" not in line:
            yield Failure(run, m.group(1), m.group(3), m.group(4),
                          int(m.group(2)))


def triage(logs):
    """The annotation: {bucket key: [Failure, ...]}. Pure — text in."""
    buckets = defaultdict(list)
    for run in sorted(logs):                    # sorted: 33.14 §6
        first = next(stream_failures(run, logs[run].splitlines()), None)
        if first is not None:
            buckets[first.key].append(first)
    return dict(buckets)


def report(buckets):
    """Largest bucket first; ties broken by severity then by key."""
    def order(item):
        key, failures = item
        rank = SEVERITY_RANK.index(key[0]) if key[0] in SEVERITY_RANK else 9
        return (-len(failures), rank, key)

    lines = [f"{len(buckets)} distinct failure(s) across "
             f"{sum(len(v) for v in buckets.values())} failing run(s)", ""]
    for n, (key, failures) in enumerate(sorted(buckets.items(), key=order), 1):
        rep = min(failures, key=lambda f: (f.time, f.run))
        lines.append(f"{n}. {len(failures):>2} run(s)  {key[0]}  {key[1]}")
        lines.append(f"      {key[2]}")
        lines.append(f"      first seen: {rep.run} at time {rep.time}")
    return "\n".join(lines)


LOG_TABLE = [
    ("burst_4121", "UVM_ERROR", "drv.sv(88)", "data mismatch exp=0xa5 got=0x5a", 1000),
    ("burst_7734", "UVM_ERROR", "drv.sv(89)", "data mismatch exp=0xa6 got=0x5b", 1137),
    ("burst_9001", "UVM_ERROR", "drv.sv(90)", "data mismatch exp=0xa7 got=0x5c", 1274),
    ("burst_1337", "UVM_ERROR", "drv.sv(91)", "data mismatch exp=0xa8 got=0x5d", 1411),
    ("lite_4121", "UVM_ERROR", "mon.sv(12)", "response timeout after 500 cycles", 2000),
    ("lite_7734", "UVM_ERROR", "mon.sv(13)", "response timeout after 510 cycles", 2211),
    ("lite_9001", "UVM_ERROR", "mon.sv(14)", "response timeout after 520 cycles", 2422),
    ("lite_1337", "UVM_ERROR", "mon.sv(15)", "response timeout after 530 cycles", 2633),
    ("lite_2024", "UVM_ERROR", "mon.sv(16)", "response timeout after 540 cycles", 2844),
    ("wrap_4121", "UVM_FATAL", "env.sv(3)", "virtual interface not set for agent[0]", 50),
    ("wrap_7734", "UVM_FATAL", "env.sv(4)", "virtual interface not set for agent[1]", 57),
    ("wrap_9001", "UVM_FATAL", "env.sv(5)", "virtual interface not set for agent[2]", 64),
    ("burst2_555", "UVM_ERROR", "drv.sv(92)", "burst length 4 unsupported for wrap", 3000),
    ("burst2_666", "UVM_ERROR", "drv.sv(93)", "burst length 5 unsupported for wrap", 3053),
]
PASSING = ("UVM_INFO @0: tb.sv(1) ntb_random_seed=777\nTEST DONE\n")


def make_log(name, sev, where, msg, t):
    return (f"UVM_INFO @0: tb.sv(1) ntb_random_seed={name.split('_')[-1]}\n"
            f"{sev} @{t}: {where} {msg}\n"
            f"UVM_ERROR @{t + 50}: scb.sv(12) scoreboard drained with 1 pending\n"
            f"UVM_ERROR :    2\nTEST DONE\n")


LOGS = {row[0]: make_log(*row) for row in LOG_TABLE}
LOGS["clean_777"] = PASSING          # a passing run, to prove it is excluded

buckets = triage(LOGS)
print(report(buckets))
print()
print("logs given          :", len(LOGS))
print("failing runs bucketed:", sum(len(v) for v in buckets.values()))
print("passing runs in a bucket:", 0)
print("buckets             :", len(buckets))

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

4 distinct failure(s) across 14 failing run(s)

1.  5 run(s)  UVM_ERROR  mon.sv(N)
      response timeout after N cycles
      first seen: lite_4121 at time 2000
2.  4 run(s)  UVM_ERROR  drv.sv(N)
      data mismatch exp=0xH got=0xH
      first seen: burst_4121 at time 1000
3.  3 run(s)  UVM_FATAL  env.sv(N)
      virtual interface not set for agent[N]
      first seen: wrap_4121 at time 50
4.  2 run(s)  UVM_ERROR  drv.sv(N)
      burst length N unsupported for wrap
      first seen: burst2_555 at time 3000

logs given          : 15
failing runs bucketed: 14
passing runs in a bucket: 0
buckets             : 4

Four buckets, fifteen logs in, fourteen runs bucketed, and the passing run excluded. That last fact comes free from the shape: next(..., None) returns None for a log with no failure, and the if first is not None skips it — so there is no separate "is this run passing" check to get wrong.

Three deliberate choices in report are worth naming. Buckets are sorted by size first, so the morning's attention goes to the five-run problem. Ties break on severity, so a UVM_FATAL bucket outranks a same-sized UVM_ERROR one. And the representative is the failure with the earliest simulation time, not the first run alphabetically — the earliest failure is usually the simplest reproduction, which is what somebody about to debug it wants.

The sorted(logs) in triage is Chapter 33.14 Section 6's rule: iterate the input in a defined order so two runs of the triager over the same regression produce byte-identical reports.

9. How It Is Tested

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

import io
import re
import unittest
from collections import defaultdict
from dataclasses import dataclass

FAILURE = re.compile(r"^(UVM_ERROR|UVM_FATAL)\s+@(\d+):\s+(\S+)\s+(.*)$")
LINE_NO, HEX, INT = (re.compile(r"\(\d+\)"), re.compile(r"0x[0-9a-fA-F]+"),
                     re.compile(r"\b\d+\b"))


def normalise(m):
    return INT.sub("N", HEX.sub("0xH", m))


@dataclass(frozen=True)
class Failure:
    run: str
    severity: str
    where: str
    message: str
    time: int

    @property
    def key(self):
        return (self.severity, LINE_NO.sub("(N)", self.where),
                normalise(self.message))


def stream_failures(run, lines):
    for line in lines:
        m = FAILURE.match(line)
        if m and f"{m.group(1)} :" not in line:
            yield Failure(run, m.group(1), m.group(3), m.group(4),
                          int(m.group(2)))


def triage(logs):
    buckets = defaultdict(list)
    for run in sorted(logs):
        first = next(stream_failures(run, logs[run].splitlines()), None)
        if first is not None:
            buckets[first.key].append(first)
    return dict(buckets)


# --- golden extracts: real shapes, ten lines each — 33.4
CLEAN = "UVM_INFO @0: tb.sv(1) start\nTEST DONE\n"
ONE_ERR = ("UVM_INFO @0: tb.sv(1) start\n"
           "UVM_ERROR @100: drv.sv(88) data mismatch exp=0xa5 got=0x5a\n"
           "UVM_ERROR :    1\nTEST DONE\n")
CONSEQUENCE = ONE_ERR.replace("UVM_ERROR :    1",
                              "UVM_ERROR @150: scb.sv(12) drained\n"
                              "UVM_ERROR :    2")
SUMMARY_ONLY = "UVM_INFO @0: tb.sv(1) start\nUVM_ERROR :    0\nTEST DONE\n"
TRUNCATED = "UVM_INFO @0: tb.sv(1) start\nUVM_ERROR @100: drv.sv(88) data mis"
FATAL_FIRST = ("UVM_INFO @0: tb.sv(1) start\n"
               "UVM_FATAL @10: env.sv(3) virtual interface not set\n"
               "UVM_ERROR @20: drv.sv(88) data mismatch exp=0xa5 got=0x5a\n"
               "TEST DONE\n")


class Triager(unittest.TestCase):

    def test_a_passing_log_produces_no_bucket(self):
        self.assertEqual(triage({"r": CLEAN}), {})

    def test_one_error_one_bucket(self):
        self.assertEqual(len(triage({"r": ONE_ERR})), 1)

    def test_the_consequence_is_not_the_key(self):
        key = next(iter(triage({"r": CONSEQUENCE})))
        self.assertIn("data mismatch", key[2])
        self.assertNotIn("drained", key[2])

    def test_the_summary_line_is_never_a_failure(self):
        self.assertEqual(triage({"r": SUMMARY_ONLY}), {})

    def test_a_truncated_line_makes_a_SPURIOUS_bucket(self):
        """Measured, and not what I expected: the fragment DOES parse."""
        buckets = triage({"r": TRUNCATED})
        self.assertEqual(len(buckets), 1)
        key = next(iter(buckets))
        self.assertEqual(key[2], "data mis")      # a truncated message

    def test_a_truncated_log_is_a_different_bucket_from_a_whole_one(self):
        both = triage({"whole": ONE_ERR, "cut": TRUNCATED})
        self.assertEqual(len(both), 2)            # the bug it causes

    def test_fatal_before_error_wins_by_position(self):
        key = next(iter(triage({"r": FATAL_FIRST})))
        self.assertEqual(key[0], "UVM_FATAL")

    def test_two_seeds_of_one_bug_share_a_bucket(self):
        a = ONE_ERR
        b = ONE_ERR.replace("0xa5", "0xb7").replace("0x5a", "0x7b") \
                   .replace("(88)", "(91)").replace("@100", "@900")
        self.assertEqual(len(triage({"a": a, "b": b})), 1)

    def test_two_different_bugs_do_not_share_a_bucket(self):
        other = ONE_ERR.replace("data mismatch exp=0xa5 got=0x5a",
                                "response timeout after 500 cycles")
        self.assertEqual(len(triage({"a": ONE_ERR, "b": other})), 2)

    def test_the_report_is_reproducible(self):
        logs = {"b": ONE_ERR, "a": ONE_ERR}
        self.assertEqual(triage(logs), triage(dict(reversed(list(logs.items())))))

    def test_only_the_prefix_is_read(self):
        counted = []

        def counting_lines(text):
            for line in text.splitlines():
                counted.append(line)
                yield line

        next(stream_failures("r", counting_lines(CONSEQUENCE)), None)
        self.assertEqual(len(counted), 2)


def run(case):
    suite = unittest.TestLoader().loadTestsFromTestCase(case)
    res = unittest.TextTestRunner(stream=io.StringIO(), verbosity=0).run(suite)
    return {"run": res.testsRun, "failures": len(res.failures),
            "errors": len(res.errors), "ok": res.wasSuccessful()}


print("triager suite:", run(Triager))
print()
print("golden extracts        :", 6)
print("behaviours pinned      :", 11)
print("files or tools needed  :", 0)
print()
print("the two tests that matter most:")
print("  same bug, two seeds -> one bucket")
print("  two bugs            -> two buckets")
print("because a bucketer can be wrong in:", "both directions")

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

triager suite: {'run': 11, 'failures': 0, 'errors': 0, 'ok': True}

golden extracts        : 6
behaviours pinned      : 11
files or tools needed  : 0

the two tests that matter most:
  same bug, two seeds -> one bucket
  two bugs            -> two buckets
because a bucketer can be wrong in: both directions

Ten behaviours pinned with six golden extracts and no files. The whole triager is pure, so Chapter 34.3's middle-layer property holds: every input is a string literal in the test.

The pair of tests named at the end is the one thing a bucketing tool cannot do without. A bucketer has two failure modes and they are opposite: splitting one bug across many buckets (Section 4's fourteen-of-one) and merging different bugs into one (Section 6's keyed-on-last). A suite that only tests one direction passes happily while the tool is useless in the other — which is Chapter 33.9's argument about a check that cannot distinguish what it claims to.

test_only_the_prefix_is_read is the other unusual one: it counts the lines the generator actually pulled, asserting 2 for a log with four. That makes the streaming property a tested behaviour rather than an intention somebody can remove with a stray list(...).

And two of those tests record a defect I did not predict. I wrote test_a_truncated_line_still_parses_if_it_matched expecting a truncated final line to match nothing, and it matches perfectly well: UVM_ERROR @100: drv.sv(88) data mis satisfies every group, because the message group is (.*)$ and a fragment is a valid string. So a log the simulator was still writing produces a Failure whose message is truncated, which normalises to a key no complete log can ever produce — one extra bucket per truncated log, reported as a distinct root cause.

That is Chapter 33.5's truncation problem arriving in a triager, and the two tests now pin the real behaviour rather than my assumption. The fix belongs where Chapter 33.5 put it — a completeness check outside the parsing loop, so a log with no TEST DONE is bucketed as INCOMPLETE rather than by its last partial line:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

import re
from collections import defaultdict

FAILURE = re.compile(r"^(UVM_ERROR|UVM_FATAL)\s+@(\d+):\s+(\S+)\s+(.*)$")


def triage_with_completeness(logs):
    """A log that did not finish is its own bucket, not a false cause."""
    buckets = defaultdict(list)
    for run in sorted(logs):
        text = logs[run]
        if "TEST DONE" not in text:
            buckets[("INCOMPLETE", "-", "the run did not finish")].append(run)
            continue
        for line in text.splitlines():
            m = FAILURE.match(line)
            if m and f"{m.group(1)} :" not in line:
                buckets[(m.group(1), re.sub(r"\(\d+\)", "(N)", m.group(3)),
                         re.sub(r"\b\d+\b", "N",
                                re.sub(r"0x[0-9a-fA-F]+", "0xH",
                                       m.group(4))))].append(run)
                break
    return dict(buckets)


WHOLE = ("UVM_INFO @0: tb.sv(1) start\n"
         "UVM_ERROR @100: drv.sv(88) data mismatch exp=0xa5 got=0x5a\n"
         "UVM_ERROR :    1\nTEST DONE\n")
CUT = "UVM_INFO @0: tb.sv(1) start\nUVM_ERROR @100: drv.sv(88) data mis"

for label, logs in (("without the check", {"whole": WHOLE, "cut": CUT}),):
    pass

naive = len({("UVM_ERROR", "drv.sv(N)", "data mismatch exp=0xH got=0xH"),
             ("UVM_ERROR", "drv.sv(N)", "data mis")})
fixed = triage_with_completeness({"whole": WHOLE, "cut": CUT})

print("two logs, one complete and one truncated mid-line")
print()
print("buckets without a completeness check:", naive, "— two 'causes'")
print("buckets with one                    :", len(fixed))
for key, runs in sorted(fixed.items()):
    print(f"   {key[0]:<12} {key[2][:42]:<44} {runs}")
print()
print("the truncated run is now reported as:", "INCOMPLETE")
print("and not as                          :", "a fifth root cause")

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

two logs, one complete and one truncated mid-line

buckets without a completeness check: 2 — two 'causes'
buckets with one                    : 2
   INCOMPLETE   the run did not finish                       ['cut']
   UVM_ERROR    data mismatch exp=0xH got=0xH                ['whole']

the truncated run is now reported as: INCOMPLETE
and not as                          : a fifth root cause

Still two buckets, and that is the point — they are now the right two. The count did not improve; the meaning did. One bucket is a real design failure with four runs behind it, and the other says plainly that a run did not finish, which is an infrastructure problem for a different person — Chapter 30.1 Section 4's split, preserved instead of collapsed.

10. Predict, Run, Observe

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

import re

FAILURE = re.compile(r"^(UVM_ERROR|UVM_FATAL)\s+@(\d+):\s+(\S+)\s+(.*)$")
HEX, INT = re.compile(r"0x[0-9a-fA-F]+"), re.compile(r"\b\d+\b")
LOG = ("UVM_INFO @0: tb.sv(1) start\n"
       "UVM_ERROR @100: drv.sv(88) data mismatch exp=0xa5 got=0x5a\n"
       "UVM_ERROR @150: scb.sv(12) drained with 1 pending\n"
       "UVM_ERROR :    2\nTEST DONE\n")


def matches(text):
    out = []
    for line in text.splitlines():
        m = FAILURE.match(line)
        if m and f"{m.group(1)} :" not in line:
            out.append(m.groups())
    return out


# A
print("A:", len(matches(LOG)))

# B
print("B:", matches(LOG)[0][2], "|", matches(LOG)[-1][2])

# C
print("C:", INT.sub("N", HEX.sub("0xH", matches(LOG)[0][3])))

# D
print("D:", FAILURE.match("UVM_ERROR :    2") is None,
      FAILURE.match("UVM_ERROR @1000: rep UVM_ERROR : 2 seen") is None)

The verified output:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

A: 2
B: drv.sv(88) | scb.sv(12)
C: data mismatch exp=0xH got=0xH
D: True False

A — two real failures from a log containing three UVM_ERROR lines.

B — the first is the driver, the last is the scoreboard. Section 6's choice in two values.

C — the normaliser masks both hex values and keeps the structure, which is what makes two seeds of one bug share a key.

D — the pair that settles the callout. The plain summary line does not match the pattern (True), because \s+@ requires an @ the summary has not got. The timestamped variant does match (False), so for that shape the f"{sev} :" not in line guard is the only thing standing between the triager and a bucket containing every failing run. The guard is redundant for the common case and load-bearing for the uncommon one, which is the usual reason a defensive check survives review and then turns out to matter.

11. Exercises

Exercise 1 — the three questions. Ask your own regression summary how many things are broken, and record what it can tell you.

Exercise 2 — one operation. Explain why all three unanswered questions reduce to grouping.

Exercise 3 — the signature. For each of the four candidate signatures, say what a caller cannot do.

Exercise 4 — what a count forbids. List four things the annotation's return type allows.

Exercise 5 — your own v1. Count the severity lines across one regression and say what the number means.

Exercise 6 — more lines than runs. Explain why the count exceeds the failing-run count.

Exercise 7 — raw buckets. Group your failures by the exact message and count the buckets.

Exercise 8 — one per run. Say which fields in your messages vary with the seed.

Exercise 9 — deliberately lossy. Write down what your key must discard and what it must keep.

Exercise 10 — stream it. Write stream_failures as a generator and confirm next() abandons it.

Exercise 11 — count the lines read. Instrument the generator and assert how many lines were pulled.

Exercise 12 — freeze the Failure. Explain why a bucket key must not be mutable.

Exercise 13 — first versus last. Key on both and record the two bucket counts.

Exercise 14 — the generic tail. Name the most generic error in your own logs.

Exercise 15 — the summary line. Confirm your parser excludes UVM_ERROR : and say what happens if it does not.

Exercise 16 — sweep the dial. Measure your bucket count at four normalisation levels.

Exercise 17 — find the plateau. Say which level your count stops dropping at.

Exercise 18 — still dropping. If it never plateaus, decide what field you have not masked.

Exercise 19 — what a plateau does not prove. Explain in one sentence.

Exercise 20 — a representative run. Add one per bucket and say why a count alone is not enough.

Exercise 21 — sort by size. Order your report largest bucket first and say what that optimises.

Exercise 22 — the earliest time. Explain why the earliest failure is the better representative.

Exercise 23 — passing runs for free. Confirm a clean log produces no bucket with no extra check.

Exercise 24 — reproducible reports. Add the sorted() and explain which chapter required it.

Exercise 25 — six extracts. Build your own golden set, ten lines each.

Exercise 26 — both directions. Write the same-bug-one-bucket and two-bugs-two-buckets tests.

Exercise 27 — a suite that tests one direction. Say what it would miss.

Exercise 28 — diff against yesterday. Sketch how the bucket map makes Chapter 30.3's new-versus-fixed comparison possible.

12. Summary

The summary answers two questions and a lead asks three more, and all three reduce to grouping the failures by cause.
The annotation's return type is the design: a mapping from bucket to Failure objects lets a caller count, sort, name a representative and diff against yesterday — a count allows none of it.
v1 reported 25 error lines from 14 runs with 4 causes. The number is right and answers nothing: 14 of the 25 are one consequence per run, 11 are causes, and the 3 UVM_FATAL runs are invisible to a UVM_ERROR count entirely.
Grouping on the raw message gives 14 buckets of one, because every message carries a seed-dependent value. The key has to be deliberately lossy.
Stream the log and stop at the first failure. next() on a generator reads the prefix only, and the test asserts it pulled 2 lines from a 4-line log.
Freeze the Failure: its key is a dictionary key, and a bucket that can move after filing is worse than no bucket.
Keying on the first failure gives 4 buckets; keying on the last gives 1. Same logs, same normaliser, one index different — the last error is reliably the most generic.
Two mechanisms exclude the UVM_ERROR : summary line. The pattern rejects three of four summary shapes on its own; a timestamped variant matches it fully, and the explicit string guard is the only thing that rejects that one.
A truncated final line parses perfectly well — (.*)$ accepts a fragment — so every log the simulator was still writing adds a spurious bucket. A completeness check outside the loop reports it as INCOMPLETE instead of as a root cause.
The bucket count plateaus rather than collapsing. Masking words as well as integers still gave 4, because the key is a triple and two of its parts are already coarse.
So sweep the dial and look for the plateau: still dropping means under-normalised, stopped means the key is no longer sensitive to it.
A plateau does not prove the grouping is right — two different bugs with structurally identical messages share a bucket at every level, which is why the report names a representative run.
Sort buckets by size, break ties on severity, and represent each by its earliest failure — the earliest is usually the simplest reproduction.
Passing runs are excluded for free by next(..., None), with no separate check to get wrong.
A bucketer fails in two opposite directions — splitting one bug and merging several — so the suite needs a test for each.

The next chapter applies the same spine to a harder input: an STA timing report, where the parser has to be stateful because the facts are spread across lines.

Where this fits

Part of the Python curriculum.