awk Part III · Module 9 · Simulation and UVM Log Analysis
Counting Warnings and Errors
A triage reads two or three numbers before anything else: how many errors, how many warnings, did anything fatal happen. Producing them looks like the simplest job in this module and it contains the module's sharpest trap — the obvious count is wrong, and the reflex fix of anchoring the pattern does not help, because the log's own report summary begins with the same word you are matching. Past that, a harder question: the number you have just computed counts message records, and a triage wants failures. On the fixture here, nine error records are two distinct failures.
Intermediate16 min readawkPart IIIUVMTriageCounting
Part III · Module 9 · Chapter 9.3 · Counting Warnings and Errors
1. Why This Matters
This is the most-written awk command in verification: count the errors in a log. It appears in every regression script, usually as a grep -c, and it is usually wrong.
It is rated critical because of where the number goes. An error count decides whether a nightly job reports success, whether a test is retried, and whether anybody looks at the log at all. A count that is high by one makes a clean run look dirty; a count that is low by one makes a failing run pass.
2. The Obvious Count
Chronologic VCS simulator copyright 1991-2024
Compiler version X-2024.03; Runtime version X-2024.03; Oct 12 14:30 2026
UVM_INFO @ 0: reporter [RNTST] Running test alu_smoke_test...
UVM_INFO ../tb/env/alu_env.sv(87) @ 0: uvm_test_top.env [BUILD] env built with 2 agents
UVM_INFO ../tb/seq/alu_seq.sv(42) @ 1000: uvm_test_top.env.agt.seqr@@seq [SEQ] starting 50 items
UVM_WARNING ../tb/env/alu_sb.sv(210) @ 15500: uvm_test_top.env.sb [UNUSED_CLK] clock gate never toggled
UVM_WARNING ../tb/env/alu_sb.sv(210) @ 16000: uvm_test_top.env.sb [UNUSED_CLK] clock gate never toggled
UVM_ERROR ../tb/env/alu_sb.sv(145) @ 20500: uvm_test_top.env.sb [MISMATCH] exp=32'hdead act=32'hbeef
UVM_ERROR ../tb/env/alu_sb.sv(145) @ 21000: uvm_test_top.env.sb [MISMATCH] exp=32'hcafe act=32'h0000
UVM_INFO ../tb/seq/alu_seq.sv(99) @ 30000: uvm_test_top.env.agt.seqr@@seq [SEQ] done
UVM_FATAL ../tb/env/alu_env.sv(300) @ 30500: uvm_test_top.env [DEADLOCK] no response for 500ns
--- UVM Report Summary ---
** Report counts by severity
UVM_INFO : 4
UVM_WARNING : 2
UVM_ERROR : 2
UVM_FATAL : 1
$finish called from file "../tb/top.sv", line 55.The log has two error records. Count them:
grep -c UVM_ERROR sim.log3awk '/UVM_INFO/ { i++ } /UVM_WARNING/ { w++ } /UVM_ERROR/ { e++ } /UVM_FATAL/ { f++ } END { printf "INFO=%d WARNING=%d ERROR=%d FATAL=%d (of %d lines)\n", i + 0, w + 0, e + 0, f + 0, NR }' sim.logINFO=5 WARNING=3 ERROR=3 FATAL=2 (of 18 lines)Every count is high by one, and the log itself says so three lines from the end: UVM_INFO : 4, UVM_WARNING : 2, UVM_ERROR : 2, UVM_FATAL : 1.
3. Why, and Why Anchoring Does Not Help
Printing what matched settles the cause:
awk '/UVM_ERROR/ { printf "line %d: %s\n", NR, $0 }' sim.logline 8: UVM_ERROR ../tb/env/alu_sb.sv(145) @ 20500: uvm_test_top.env.sb [MISMATCH] exp=32'hdead act=32'hbeef
line 9: UVM_ERROR ../tb/env/alu_sb.sv(145) @ 21000: uvm_test_top.env.sb [MISMATCH] exp=32'hcafe act=32'h0000
line 16: UVM_ERROR : 2Line 16 is from the report summary — the log's own count of errors, matched as if it were an error.
The reflex fix is to anchor the pattern to the start of the line. It does not work:
awk '/^UVM_INFO/ { i++ } /^UVM_WARNING/ { w++ } /^UVM_ERROR/ { e++ } /^UVM_FATAL/ { f++ } END { printf "INFO=%d WARNING=%d ERROR=%d FATAL=%d\n", i + 0, w + 0, e + 0, f + 0 }' sim.logINFO=5 WARNING=3 ERROR=3 FATAL=2Identical. UVM_ERROR : 2 also starts with UVM_ERROR, so the anchor excludes nothing.
4. Three Fixes
Skip the summary region. The structural answer — once past the marker, nothing is a record:
awk '/^--- UVM Report Summary ---/ { insum = 1 } insum { next } /^UVM_INFO/ { i++ } /^UVM_WARNING/ { w++ } /^UVM_ERROR/ { e++ } /^UVM_FATAL/ { f++ } END { printf "INFO=%d WARNING=%d ERROR=%d FATAL=%d\n", i + 0, w + 0, e + 0, f + 0 }' sim.logINFO=4 WARNING=2 ERROR=2 FATAL=1Require the second field not to be a colon. The summary's layout is SEVERITY : N, so $2 is : there and a path or @ in a record:
awk '$2 != ":" && /^UVM_INFO/ { i++ } $2 != ":" && /^UVM_WARNING/ { w++ } $2 != ":" && /^UVM_ERROR/ { e++ } $2 != ":" && /^UVM_FATAL/ { f++ } END { printf "INFO=%d WARNING=%d ERROR=%d FATAL=%d\n", i + 0, w + 0, e + 0, f + 0 }' sim.logINFO=4 WARNING=2 ERROR=2 FATAL=1A positive record pattern. Describe a record: a severity, a space, then a path or an at-sign:
awk '/^UVM_(INFO|WARNING|ERROR|FATAL) (\.|\/|@)/ { n[$1]++ } END { printf "INFO=%d WARNING=%d ERROR=%d FATAL=%d\n", n["UVM_INFO"] + 0, n["UVM_WARNING"] + 0, n["UVM_ERROR"] + 0, n["UVM_FATAL"] + 0 }' sim.logINFO=4 WARNING=2 ERROR=2 FATAL=1All three correct. They differ in what they assume:
| Fix | Assumes | Breaks if |
|---|---|---|
| skip the summary | the marker text | a tool uses different wording |
$2 != ":" | the summary's spacing | the summary is reformatted |
| positive pattern | a record's own shape | a record format is added that it does not cover |
The third is used throughout Module 9, and its failure mode is the mildest — it under-counts rather than over-counts, and Chapter 9.1 section 6's cross-check catches that.
5. Checking the Count Against the Log
With the count correct, verify it rather than trusting it:
awk '/^--- UVM Report Summary ---/ { insum = 1; next } insum && /^UVM_[A-Z]+ *:/ { line = $0; gsub(/ /, "", line); split(line, p, ":"); claimed[p[1]] = p[2] } !insum && /^UVM_(INFO|WARNING|ERROR|FATAL) (\.|\/|@)/ { counted[$1]++ } END { bad = 0; for (s in claimed) { ok = (counted[s] + 0 == claimed[s] + 0); printf "%-12s counted=%d log=%s %s\n", s, counted[s] + 0, claimed[s], (ok ? "agree" : "DISAGREE"); if (!ok) bad++ } exit (bad ? 1 : 0) }' sim.log | sortUVM_ERROR counted=2 log=2 agree
UVM_FATAL counted=1 log=1 agree
UVM_INFO counted=4 log=4 agree
UVM_WARNING counted=2 log=2 agreeFour for four. The exit status makes it a gate: a disagreement means the pattern missed a record format, and the script should stop rather than report a number it cannot defend.
The naive version fails that gate immediately:
awk '/^--- UVM Report Summary ---/ { insum = 1; next } insum && /^UVM_[A-Z]+ *:/ { line = $0; gsub(/ /, "", line); split(line, p, ":"); claimed[p[1]] = p[2]; next } /^UVM_[A-Z]+/ { counted[$1]++ } END { for (s in claimed) printf "%-12s counted=%d log=%s %s\n", s, counted[s] + 0, claimed[s], (counted[s] + 0 == claimed[s] + 0 ? "agree" : "DISAGREE") }' sim.log | sortUVM_ERROR counted=2 log=2 agree
UVM_FATAL counted=1 log=1 agree
UVM_INFO counted=4 log=4 agree
UVM_WARNING counted=2 log=2 agreeThat one agrees too — because consuming the summary lines with next happens to remove exactly the lines that were causing the over-count. It is correct by accident: the next was written to stop summary lines reaching the counter, which is fix A in a different spelling.
6. The Triage Numbers
What a triage actually wants is three numbers and a verdict:
awk '/^--- UVM Report Summary ---/ { insum = 1 } insum { next } /^UVM_(INFO|WARNING|ERROR|FATAL) (\.|\/|@)/ { n[$1]++ } END { e = n["UVM_ERROR"] + 0; f = n["UVM_FATAL"] + 0; w = n["UVM_WARNING"] + 0; printf "%d error(s), %d fatal, %d warning(s) -> %s\n", e, f, w, (f ? "FATAL" : (e ? "FAIL" : "PASS")) }' sim.log2 error(s), 1 fatal, 2 warning(s) -> FATALThe verdict order matters and is an engineering decision, not a formatting one. A UVM_FATAL means the simulation stopped — so whatever else the log contains, it is incomplete, and treating the run as merely "failing" understates it. Chapter 9.5 makes FATAL a distinct status for exactly this reason.
Warnings are reported and do not affect the verdict here, which is the common convention and worth stating explicitly rather than leaving implicit — a project that gates on warnings needs a different rule, and a reader should be able to see which this script implements.
7. A Count of Records Is Not a Count of Failures
The second half of the chapter, and the harder half. A log with many errors:
UVM_INFO @ 0: reporter [RNTST] Running test alu_test...
UVM_ERROR ../tb/env/alu_sb.sv(145) @ 1000: uvm_test_top.env.sb [MISMATCH] exp!=act
UVM_ERROR ../tb/env/alu_sb.sv(145) @ 1100: uvm_test_top.env.sb [MISMATCH] exp!=act
UVM_ERROR ../tb/env/alu_sb.sv(145) @ 1200: uvm_test_top.env.sb [MISMATCH] exp!=act
UVM_ERROR ../tb/env/alu_sb.sv(145) @ 1300: uvm_test_top.env.sb [MISMATCH] exp!=act
UVM_ERROR ../tb/env/alu_sb.sv(145) @ 1400: uvm_test_top.env.sb [MISMATCH] exp!=act
UVM_ERROR ../tb/env/alu_sb.sv(145) @ 1500: uvm_test_top.env.sb [MISMATCH] exp!=act
UVM_ERROR ../tb/env/alu_sb.sv(145) @ 1600: uvm_test_top.env.sb [MISMATCH] exp!=act
UVM_ERROR ../tb/env/alu_sb.sv(145) @ 1700: uvm_test_top.env.sb [MISMATCH] exp!=act
UVM_ERROR ../tb/env/alu_cov.sv(77) @ 2000: uvm_test_top.env.cov [NO_HIT] bin never hit
--- UVM Report Summary ---
UVM_ERROR : 9awk '/^--- UVM Report Summary ---/ { insum = 1 } insum { next } /^UVM_ERROR (\.|\/|@)/ { e++ } END { printf "%d error record(s)\n", e + 0 }' logs/alu.log9 error record(s)Nine, agreeing with the log. Now count distinct failures, keying on the id and the source location:
awk '/^--- UVM Report Summary ---/ { insum = 1 } insum { next } /^UVM_ERROR (\.|\/|@)/ { recs++; id = $0; sub(/^[^[]*\[/, "", id); sub(/\].*$/, "", id); sig[id SUBSEP $2]++ } END { c = 0; for (k in sig) c++; printf "%d error record(s) collapse to %d distinct signature(s)\n", recs, c }' logs/alu.log9 error record(s) collapse to 2 distinct signature(s)Nine records, two signatures. Both numbers are true and they answer different questions:
awk '/^--- UVM Report Summary ---/ { insum = 1 } insum { next } /^UVM_ERROR (\.|\/|@)/ { id = $0; sub(/^[^[]*\[/, "", id); sub(/\].*$/, "", id); loc = $2; sub(/\(/, ":", loc); sub(/\)/, "", loc); sig[id SUBSEP loc]++ } END { for (k in sig) { split(k, p, SUBSEP); printf "%-12s %-28s %d record(s)\n", p[1], p[2], sig[k] } }' logs/alu.log | sort -k3 -rnMISMATCH ../tb/env/alu_sb.sv:145 8 record(s)
NO_HIT ../tb/env/alu_cov.sv:77 1 record(s)8. Both Numbers, Side by Side
The command a regression script should actually run:
awk '/^--- UVM Report Summary ---/ { insum = 1 } insum { next } /^UVM_(ERROR|FATAL) (\.|\/|@)/ { recs++; id = $0; sub(/^[^[]*\[/, "", id); sub(/\].*$/, "", id); sig[id SUBSEP $2]++; if ($1 == "UVM_FATAL") fatal++ } END { c = 0; for (k in sig) c++; printf "%d record(s), %d distinct signature(s), %d fatal -> %s\n", recs + 0, c, fatal + 0, (fatal ? "FATAL" : (recs ? "FAIL" : "PASS")) }' logs/alu.log9 record(s), 2 distinct signature(s), 0 fatal -> FAILAnd on the Chapter 9.1 fixture, where the counts are small and the fatal is present:
awk '/^--- UVM Report Summary ---/ { insum = 1 } insum { next } /^UVM_(ERROR|FATAL) (\.|\/|@)/ { recs++; id = $0; sub(/^[^[]*\[/, "", id); sub(/\].*$/, "", id); sig[id SUBSEP $2]++; if ($1 == "UVM_FATAL") fatal++ } END { c = 0; for (k in sig) c++; printf "%d record(s), %d distinct signature(s), %d fatal -> %s\n", recs + 0, c, fatal + 0, (fatal ? "FATAL" : (recs ? "FAIL" : "PASS")) }' sim.log3 record(s), 2 distinct signature(s), 1 fatal -> FATALThree records, two signatures, one fatal. The MISMATCH pair collapses to one signature and the DEADLOCK is the other.
Note the signature key uses $2 — the raw file(line) — rather than the id alone. Two checkers can share an id, and the same checker at two lines is usually two different checks, so the pair is the more honest grouping. Chapter 9.4 examines that choice.
9. Common Mistakes
grep -c UVM_ERROR. The report summary matches — section 2.
Anchoring and assuming it is fixed. The summary line also starts with the severity — section 3.
A negative pattern listing exceptions. Only as complete as your imagination.
Not checking against the log's own summary. It is a free independent count — section 5.
Treating a record count as a failure count. Nine records, two failures — section 7.
Comparing error counts between runs of different length. The count partly measures the test length.
Ranking a triage table by record count. The loudest failure is rarely the most important — Chapter 6.2 §6.
Reporting FAIL when a fatal occurred. The run stopped, so the log is incomplete — section 6.
Leaving the warning policy implicit. State whether warnings gate.
10. Exercises
Exercise 1 — Reproduce the over-count
awk '/UVM_ERROR/ { e++ } END { printf "naive=%d\n", e + 0 }' sim.log
awk '/^UVM_ERROR/ { e++ } END { printf "anchored=%d\n", e + 0 }' sim.lognaive=3
anchored=3Both wrong, and identically so.
Exercise 2 — Find the extra match
awk '/UVM_ERROR/ { printf "line %d: %s\n", NR, $0 }' sim.log | tail -1line 16: UVM_ERROR : 2The log's own error count, counted as an error.
Exercise 3 — Count correctly
awk '/^UVM_(INFO|WARNING|ERROR|FATAL) (\.|\/|@)/ { n[$1]++ } END { for (s in n) printf "%-12s %d\n", s, n[s] | "sort" }' sim.logUVM_ERROR 2
UVM_FATAL 1
UVM_INFO 4
UVM_WARNING 2Exercise 4 — Collapse records to signatures
UVM_INFO @ 0: reporter [RNTST] Running test alu_test...
UVM_ERROR ../tb/env/alu_sb.sv(145) @ 1000: uvm_test_top.env.sb [MISMATCH] exp!=act
UVM_ERROR ../tb/env/alu_sb.sv(145) @ 1100: uvm_test_top.env.sb [MISMATCH] exp!=act
UVM_ERROR ../tb/env/alu_sb.sv(145) @ 1200: uvm_test_top.env.sb [MISMATCH] exp!=act
UVM_ERROR ../tb/env/alu_sb.sv(145) @ 1300: uvm_test_top.env.sb [MISMATCH] exp!=act
UVM_ERROR ../tb/env/alu_sb.sv(145) @ 1400: uvm_test_top.env.sb [MISMATCH] exp!=act
UVM_ERROR ../tb/env/alu_sb.sv(145) @ 1500: uvm_test_top.env.sb [MISMATCH] exp!=act
UVM_ERROR ../tb/env/alu_sb.sv(145) @ 1600: uvm_test_top.env.sb [MISMATCH] exp!=act
UVM_ERROR ../tb/env/alu_sb.sv(145) @ 1700: uvm_test_top.env.sb [MISMATCH] exp!=act
UVM_ERROR ../tb/env/alu_cov.sv(77) @ 2000: uvm_test_top.env.cov [NO_HIT] bin never hit
--- UVM Report Summary ---
UVM_ERROR : 9awk '/^--- UVM Report Summary ---/ { insum = 1 } insum { next } /^UVM_ERROR (\.|\/|@)/ { recs++; id = $0; sub(/^[^[]*\[/, "", id); sub(/\].*$/, "", id); sig[id SUBSEP $2]++ } END { c = 0; for (k in sig) c++; printf "%d record(s) -> %d signature(s)\n", recs, c }' logs/alu.log9 record(s) -> 2 signature(s)Exercise 5 — Engineering application
Produce a triage header for a log: both counts, the fatal flag, a verdict, and a cross-check against the log's own summary with a non-zero status if they disagree.
awk '
/^--- UVM Report Summary ---/ { insum = 1 }
insum && /^UVM_[A-Z]+ *:/ { line = $0; gsub(/ /, "", line); split(line, p, ":"); claimed[p[1]] = p[2] }
insum { next }
/^UVM_(INFO|WARNING|ERROR|FATAL) (\.|\/|@)/ {
counted[$1]++
if ($1 == "UVM_ERROR" || $1 == "UVM_FATAL") {
id = $0; sub(/^[^[]*\[/, "", id); sub(/\].*$/, "", id)
sig[id SUBSEP $2]++
}
}
END {
if (!NR) { print "ERROR: empty log" > "/dev/stderr"; exit 2 }
e = counted["UVM_ERROR"] + 0; f = counted["UVM_FATAL"] + 0; w = counted["UVM_WARNING"] + 0
c = 0; for (k in sig) c++
printf "%d error(s) + %d fatal in %d distinct signature(s); %d warning(s) -> %s\n", e, f, c, w, (f ? "FATAL" : (e ? "FAIL" : "PASS"))
bad = 0
for (s in claimed) if (counted[s] + 0 != claimed[s] + 0) { printf "CROSS-CHECK FAILED %s: parsed %d, log says %s\n", s, counted[s] + 0, claimed[s] > "/dev/stderr"; bad++ }
if (bad) exit 2
if (f || e) exit 1
}' sim.log
echo "status: $?"2 error(s) + 1 fatal in 2 distinct signature(s); 2 warning(s) -> FATAL
status: 1Everything a triage needs in one line, with the record count and the signature count both present so neither can be mistaken for the other.
The status convention is Chapter 8.3 section 10's: 1 for a run that failed, 2 for a log that could not be trusted. A cross-check failure produces 2 rather than 1 — because if the parser disagrees with the log, the verdict it just printed is not reliable either.
The engineering caveat: 2 distinct signature(s) groups on (id, file(line)), which treats two checkers with the same id at different lines as different failures and the same checker firing on different data as one. Both are defensible readings and Chapter 9.4 is where the choice gets examined rather than assumed.
Exercise 6 — Challenge: show the record count tracking the test length
The claim in section 7 is that a record count partly measures the stimulus. Demonstrate it.
awk 'BEGIN { print "UVM_INFO @ 0: reporter [RNTST] Running test short..." ; for (i = 1; i <= 3; i++) printf "UVM_ERROR ../tb/env/alu_sb.sv(145) @ %d: uvm_test_top.env.sb [MISMATCH] exp!=act\n", i * 100 }' > short.log
awk 'BEGIN { print "UVM_INFO @ 0: reporter [RNTST] Running test long..." ; for (i = 1; i <= 40; i++) printf "UVM_ERROR ../tb/env/alu_sb.sv(145) @ %d: uvm_test_top.env.sb [MISMATCH] exp!=act\n", i * 100 }' > long.log
for f in short.log long.log; do
printf "%-10s " "$f"
awk '/^UVM_ERROR (\.|\/|@)/ { recs++; id = $0; sub(/^[^[]*\[/, "", id); sub(/\].*$/, "", id); sig[id SUBSEP $2]++ } END { c = 0; for (k in sig) c++; printf "%3d record(s), %d signature(s)\n", recs + 0, c }' "$f"
doneshort.log 3 record(s), 1 signature(s)
long.log 40 record(s), 1 signature(s)The record count differs by a factor of 13 and the signature count is identical. Both logs contain the same single bug reported by the same checker; the only difference is how many transactions the test ran before giving up.
So a dashboard tracking error counts over time would show this bug getting thirteen times worse when somebody lengthened the test. A dashboard tracking distinct signatures would show no change — correctly, because nothing about the design changed.
That is the argument for the signature count in one measurement. The record count is not useless: 40 records from 40 transactions says the failure is fully reproducible, where 1 record in 40 would say it is intermittent, and that distinction matters for debugging. It is simply not a measure of how much is wrong.
11. Summary
grep -c UVM_ERRORover-counts, because the log's report summary contains the severity name.- Anchoring the pattern does not fix it — the summary line starts with the severity too.
- Three fixes work: skip the summary region, require
$2 != ":", or use a positive record pattern. Prefer the positive pattern. - Cross-check the count against the log's own summary and exit non-zero on a disagreement.
- A
UVM_FATALmeans the run stopped, so it deserves a status distinct fromFAIL. - State the warning policy rather than leaving it implicit.
- A record count is not a failure count. Nine records collapsed to two signatures here.
- The record count partly measures the test length — the same bug gave 3 records and 40 on different-length runs, with 1 signature both times.
- Report both numbers, and rank a triage by the signature count.
- The record count still tells you reproducibility, which is why it is worth keeping.
Two numbers now exist for every log. Chapter 9.4 — Grouping Errors for Triage builds the table those numbers summarise: errors grouped by id and source so a hundred identical messages become one row, with the question of which key to group on examined rather than assumed.
Where this fits
Part of the awk curriculum.
