Your First Simulation-Log Checker

Part II · Module 20 · Chapter 20.2 · Your First Simulation-Log Checker

1. Five Lines

Here is the whole thing, as the canonical sketch writes it:

errors = 0
for line in open("sim.log"):
    if "UVM_ERROR" in line:
        errors += 1
print(errors)

An accumulator, a loop over a file, a membership test and a print — Chapters 10.10, 15.4, 4.6 and 1.8, with nothing new in it at all. That is worth noticing: the first genuinely useful tool in this curriculum needs no feature you have not already met.

Section 5 explains the one change between that sketch and the version below. First, let it run.

2. It Works

A real simulation produces a log like this — the body of a run, with the messages in the order the simulator emitted them:

UVM_INFO @ 0: reporter [RNTST] Running test axi_smoke_test...
UVM_INFO tb_top.sv(142) @ 0: uvm_test_top [CFG] clk period 2000 ps
UVM_WARNING mon.sv(51) @ 99300: uvm_test_top.env.agt.mon [SMP] late sample ignored
UVM_ERROR drv.sv(88) @ 141900: uvm_test_top.env.agt.drv [WR] bad handshake
UVM_INFO scb.sv(120) @ 160000: uvm_test_top.env.scb [CHK] 160 transactions compared
UVM_ERROR drv.sv(104) @ 180400: uvm_test_top.env.agt.drv [WR] response timeout
UVM_INFO seq.sv(140) @ 200000: uvm_test_top.env.agt.seqr [SEQ] axi_wr_rd_seq done

errors = 0
with open("run.log", encoding="utf-8") as handle:
    for line in handle:
        if "UVM_ERROR" in line:
            errors += 1
print(errors)

2

Two errors, which is correct — the log has exactly two UVM_ERROR messages, at 141900 and 180400. The script read the file one line at a time, kept a single integer, and printed it.

That is already a useful thing to own. Run it after a long simulation and you have the answer without scrolling.

3. A Number Is Not a Verdict

2 makes a person do arithmetic. Chapter 20.1's fourth part says the output should be something a human or a tool can act on:

UVM_INFO @ 0: reporter [RNTST] Running test axi_smoke_test...
UVM_WARNING mon.sv(51) @ 99300: uvm_test_top.env.agt.mon [SMP] late sample ignored
UVM_ERROR drv.sv(88) @ 141900: uvm_test_top.env.agt.drv [WR] bad handshake
UVM_ERROR drv.sv(104) @ 180400: uvm_test_top.env.agt.drv [WR] response timeout
UVM_INFO seq.sv(140) @ 200000: uvm_test_top.env.agt.seqr [SEQ] axi_wr_rd_seq done

errors = 0
with open("run.log", encoding="utf-8") as handle:
    for line in handle:
        if "UVM_ERROR" in line:
            errors += 1

verdict = "PASS" if errors == 0 else "FAIL"
print(f"{verdict}  errors={errors}")

FAIL  errors=2

One line, both things. The verdict is what a person scans for and the count is what they act on — and the split between the two is Chapter 20.1 Section 4: the counting is a fact, the errors == 0 is a policy, and they are on separate lines so that either can change alone.

4. Wrapping It So It Can Be Used Twice

The moment you want to check two logs, the top-level script stops being enough:

UVM_INFO @ 0: reporter [RNTST] Running test axi_smoke_test...
UVM_ERROR drv.sv(88) @ 141900: uvm_test_top.env.agt.drv [WR] bad handshake
UVM_ERROR drv.sv(104) @ 180400: uvm_test_top.env.agt.drv [WR] response timeout

UVM_INFO @ 0: reporter [RNTST] Running test axi_reset_test...
UVM_INFO scb.sv(120) @ 160000: uvm_test_top.env.scb [CHK] 96 transactions compared

def count_errors(path):
    """How many lines of this log mention UVM_ERROR."""
    errors = 0
    with open(path, encoding="utf-8") as handle:
        for line in handle:
            if "UVM_ERROR" in line:
                errors += 1
    return errors


for path in ["run.log", "reset.log"]:
    n = count_errors(path)
    print(f"{path:<10} {'PASS' if n == 0 else 'FAIL'}  errors={n}")

run.log    FAIL  errors=2
reset.log  PASS  errors=0

The five lines became a function and the script became a loop over logs. Nothing about the counting changed — Chapter 11.2's point, and the first sign that this is going to become a real tool rather than a one-off.

5. Why the Sketch Says open and the Code Says with

The canonical sketch iterates a bare open():

for line in open("sim.log"):

Every executed example above uses with. That is deliberate, and the reason is Chapter 15.5: a bare open() in a for statement leaves the file object with no name, so nothing closes it until the interpreter happens to collect it. On CPython that is usually immediate and usually invisible — and "usually" is doing a lot of work in a script that opens a thousand logs in a loop, where the limit on open file descriptors is a real number you can reach.

So: the four-line sketch is how the idea is written down; with is how the file is written. The sketch stays in this curriculum because it is how the code is discussed and how you will see it in other people's scripts, and because recognising it is part of reading Chapter 17.12's inherited script.

6. Now Run It on a Complete Log

Everything so far used the body of a run. A log a simulator actually writes does not end there — it ends with a report summary:

UVM_INFO @ 0: reporter [RNTST] Running test axi_smoke_test...
UVM_WARNING mon.sv(51) @ 99300: uvm_test_top.env.agt.mon [SMP] late sample ignored
UVM_ERROR drv.sv(88) @ 141900: uvm_test_top.env.agt.drv [WR] bad handshake
UVM_ERROR drv.sv(104) @ 180400: uvm_test_top.env.agt.drv [WR] response timeout
UVM_INFO seq.sv(140) @ 200000: uvm_test_top.env.agt.seqr [SEQ] axi_wr_rd_seq done
--- UVM Report Summary ---
** Report counts by severity
UVM_INFO :    3
UVM_WARNING :    1
UVM_ERROR :    2
UVM_FATAL :    0
TEST DONE

def count_errors(path):
    errors = 0
    with open(path, encoding="utf-8") as handle:
        for line in handle:
            if "UVM_ERROR" in line:
                errors += 1
    return errors


print("counted:", count_errors("sim.log"))

print("the lines it counted:")
with open("sim.log", encoding="utf-8") as handle:
    for number, line in enumerate(handle, 1):
        if "UVM_ERROR" in line:
            print(f"  {number:>2}  {line.rstrip()}")

counted: 3
the lines it counted:
   3  UVM_ERROR drv.sv(88) @ 141900: uvm_test_top.env.agt.drv [WR] bad handshake
   4  UVM_ERROR drv.sv(104) @ 180400: uvm_test_top.env.agt.drv [WR] response timeout
  10  UVM_ERROR :    2

Three. The log has two errors and the tool's own summary says so on line 10 — and the checker counted that summary line as a third error, because the string UVM_ERROR appears in it.

This is not a trick log. Every UVM simulation ends with that block; it is how the methodology reports its own tallies, and the severity names necessarily appear in it. A substring test cannot tell a message from a count of messages.

The verdict here is still FAIL, which is the dangerous part — the bug changed the number and not the answer, so nothing in the output looks wrong.

7. The Run It Reports Wrongly

Now the same checker on a log from a test that passed:

UVM_INFO @ 0: reporter [RNTST] Running test axi_reset_test...
UVM_INFO tb_top.sv(142) @ 0: uvm_test_top [CFG] clk period 2000 ps
UVM_INFO scb.sv(120) @ 160000: uvm_test_top.env.scb [CHK] 96 transactions compared
UVM_INFO seq.sv(140) @ 200000: uvm_test_top.env.agt.seqr [SEQ] axi_reset_seq done
--- UVM Report Summary ---
** Report counts by severity
UVM_INFO :    4
UVM_WARNING :    0
UVM_ERROR :    0
UVM_FATAL :    0
TEST DONE

errors = 0
with open("clean.log", encoding="utf-8") as handle:
    for line in handle:
        if "UVM_ERROR" in line:
            errors += 1

print("counted:", errors)
print("verdict:", "PASS" if errors == 0 else "FAIL")
print("truth  : the run had zero errors")

with open("clean.log", encoding="utf-8") as handle:
    for number, line in enumerate(handle, 1):
        if "UVM_ERROR" in line:
            print(f"the one line it found: {number} {line.rstrip()!r}")

counted: 1
verdict: FAIL
truth  : the run had zero errors
the one line it found: 9 'UVM_ERROR :    0'

The only line in that file containing UVM_ERROR is the summary line saying there were none, and the checker read it as one. A test that passed is reported as failed.

That is a different class of problem from Section 6. An over-count on a failing run is embarrassing. A clean run reported as a failure is the kind of thing that gets a checker switched off — and once a team stops trusting an automated check, they stop reading it, which is worse than never having written it.

8. What the Fix Is Not

Before the next chapters get to it, two fixes that look obvious and do not work. Both are worth seeing fail now, because both get written:

LINES = [
    "UVM_ERROR drv.sv(88) @ 141900: uvm_test_top.env.agt.drv [WR] bad handshake",
    "UVM_ERROR :    2",
]

for line in LINES:
    starts = line.startswith("UVM_ERROR")
    has_token = len(line.split()) > 1 and line.split()[1] != ":"
    print(f"{line[:46]!r:<48} startswith={starts}  second-token={has_token}")

'UVM_ERROR drv.sv(88) @ 141900: uvm_test_top.en' startswith=True  second-token=True
'UVM_ERROR :    2'                               startswith=True  second-token=False

startswith does not help — the summary line starts with UVM_ERROR too. Requiring a second token that is not a bare colon does work on these two lines, and it is the beginning of the right idea: a real message has a shape the summary line does not have.

Getting that shape right — and checking the result against the tool's own summary, which is sitting right there in the file — is Chapter 20.7. The intervening chapters make the script worth fixing first: Chapter 20.3 accounts for every line of it, and Chapters 20.4 and 20.5 stop it being about one specific file.

9. Predict, Run, Observe

LOG = [
    "UVM_INFO @ 0: reporter [RNTST] starting",
    "UVM_ERROR drv.sv(88) @ 141900: bad handshake",
    "UVM_ERROR :    1",
    "UVM_FATAL :    0",
]

# A
print("A:", sum(1 for line in LOG if "UVM_ERROR" in line))

# B
print("B:", sum(1 for line in LOG if "UVM_FATAL" in line))

# C
print("C:", any("UVM_FATAL" in line for line in LOG))

# D
print("D:", sum(1 for line in LOG if line.startswith("UVM_ERROR")))

# E
errors = 0
for line in LOG:
    if "UVM_ERROR" in line:
        errors += 1
print("E:", "PASS" if errors == 0 else "FAIL")

# F
print("F:", sum(1 for line in LOG if "@" in line and "UVM_ERROR" in line))

The verified output:

A: 2
B: 1
C: True
D: 2
E: FAIL
F: 1

A — one real error and one summary line, counted as two.

B — one, from a summary line reporting zero fatals.

C — True. A fatal check built on a substring test is constant: it is true for every complete UVM log.

D — startswith changes nothing here. Both lines start with the severity.

E — the verdict the log actually deserves is FAIL, and it is right for the wrong reason: one real error, one phantom.

F — requiring an @ as well gets the right answer on this data, because a real message carries a simulation time and a summary line does not. That is the shape Chapter 20.7 builds on.

10. Exercises

Exercise 1 — run it. Write the five-line checker and run it against a log extract of your own with two error lines in it. Confirm the count.

Exercise 2 — verdict and count. Add a PASS/FAIL line that also reports the number. Say why both belong on one line.

Exercise 3 — two logs. Wrap the counting in a function and run it over two logs, one failing and one clean. Print an aligned row per log.

Exercise 4 — the bare open. Write the version with for line in open(path) and the version with with. Say what the first one leaves undone and when that becomes a real problem.

Exercise 5 — the whole file. Replace the line loop with handle.read().splitlines(). Confirm the same answer, then say what changes on a 20 GB log.

Exercise 6 — add the summary block. Append a UVM report summary to your Exercise 1 log and re-run the checker. Record the new count and identify the extra line by number.

Exercise 7 — the clean run. Build a log with zero errors and a complete summary block. Record what your checker reports, and write the one-sentence bug report you would file.

Exercise 8 — the constant check. Show that "UVM_FATAL" in line is true for every complete log you have. Say what a script relying on it reports, always.

Exercise 9 — why not startswith. Demonstrate that startswith("UVM_ERROR") does not fix either problem, and say what the summary line and a real message have in common.

Exercise 10 — the shape. Without writing a regex, find one thing that is present in every real UVM message and absent from every summary line. Test it against both.

11. Summary

• Five lines make a genuinely useful checker: an accumulator, a loop over a file, a membership test and a print.
• Nothing in it is new — Chapters 10.10, 15.4, 4.6 and 1.8 between them.
• Print the verdict and the count together. The verdict is what a person scans for; the number is what they act on.
• The counting is a fact and errors == 0 is a policy, kept on separate lines so either can change alone.
• The sketch iterates a bare open(); written code uses with — Chapter 15.5's rule, which matters once you open a thousand logs in a loop.
• for line in handle streams, so the five-liner is already the version that survives a 20 GB log.
• Every complete UVM log ends with a report summary block whose own lines contain the severity names.
• A substring test counts those, so the checker reports three errors on a log with two.
• On a failing run that changes the number and not the verdict, which is why the bug survives.
• On a clean run the only UVM_ERROR line is the summary saying there were none — and the checker reports FAIL on a test that passed.
• A UVM_FATAL substring check is constant: true for every complete log, clean or not.
• startswith does not fix it. The summary line starts with the severity too.
• A real message has a shape the summary line does not — it carries a simulation time — and that is where Chapter 20.7 starts.

The next chapter goes back through this script one line at a time and accounts for every character of it, because a tool you cannot explain is a tool you cannot change.