Message Severity and Report Summaries

Part II · Module 29 · Chapter 29.3 · Message Severity and Report Summaries

Chapter 29.1 found the summary region at line 4014 of 4021. This chapter reads it, and the reading turns out to be the most error-prone operation in the whole module — because the summary is made of text that looks exactly like the thing it is counting.

1. The Summary Region

$ sed -n '/Report Summary/,$p' axi_burst_test.log
--- UVM Report Summary ---
** Report counts by severity
UVM_INFO :  4002
UVM_WARNING : 8
UVM_ERROR : 2
UVM_FATAL : 0
TEST FAILED
tb/tests/tb_regress.sv:33: $finish called at 0 (1s)

Eight lines, and they answer the three questions a reader has. sed -n '/pattern/,$p' prints from the first match to the end of file, which is the right tool here because the summary is the tail of the document and its length varies between tools.

Note what is and is not in there. There are counts by severity and a verdict — and no exit status, because the summary is written by the design and the status is produced by the process. Those are two different authorities, and Module 27 measured them disagreeing: this run says TEST FAILED and the process exited 0.

2. The Obvious Command Is Wrong for Every Severity

$ for s in UVM_INFO UVM_WARNING UVM_ERROR UVM_FATAL; do
>   g=$(grep -c "$s" axi_burst_test.log)
>   r=$(grep -E "^$s *:" axi_burst_test.log | tail -1 | sed 's/.*: *//')
>   printf '  %-13s %8s %8s %+d\n' "$s" "$g" "$r" "$((g-r))"
> done
  SEVERITY       grep -c  SUMMARY DELTA
  UVM_INFO          4004     4002 +2
  UVM_WARNING          9        8 +1
  UVM_ERROR            3        2 +1
  UVM_FATAL            1        0 +1

Every row is wrong, and the last one is wrong in the way that matters:

$ grep -n UVM_FATAL axi_burst_test.log
4019:UVM_FATAL : 0

The only UVM_FATAL in the entire 4,021-line log is the summary line stating that there were none. A naive count reports a fatal error on a run that had zero.

3. Two Fixes, and Which One to Trust

Fix one: read the summary instead of counting. The tool already did the work:

# the authoritative numbers, from the run's own accounting
summary=$(sed -n '/Report Summary/,$p' "$log")
errors=$(printf '%s\n' "$summary"  | sed -n 's/^UVM_ERROR *: *\([0-9]*\).*/\1/p')
fatals=$(printf '%s\n' "$summary"  | sed -n 's/^UVM_FATAL *: *\([0-9]*\).*/\1/p')
printf 'errors=%s fatals=%s\n' "${errors:-?}" "${fatals:-?}"

errors=2 fatals=0

Fix two: count the messages, but only in the message region, anchored. Two changes: cut the file at the summary, and require the severity at the start of a line followed by a space (a message line) rather than a colon (a summary line):

$ end=$(grep -n 'Report Summary' axi_burst_test.log | head -1 | cut -d: -f1)
$ for s in UVM_INFO UVM_WARNING UVM_ERROR UVM_FATAL; do
>   printf '  %-13s %s\n' "$s" "$(head -n $((end-1)) axi_burst_test.log | grep -cE "^$s ")"
> done
  UVM_INFO      4003
  UVM_WARNING   8
  UVM_ERROR     2
  UVM_FATAL     0

UVM_FATAL is now 0 and the warning and error counts match the summary exactly. UVM_INFO is 4003 against the summary's 4002 — still one out.

4. Chasing the Last Discrepancy

It would be easy to stop here and call the fix correct, and that one line is the difference between a tool you trust and a tool you tolerate. The tags from Chapter 29.1 resolve it:

$ head -4013 axi_burst_test.log | grep -E '^UVM_INFO ' \
>   | sed 's/.*\[\([A-Z_]*\)\].*/\1/' | sort | uniq -c | sort -rn
4000 AXI_MON
   1 TEST_DONE
   1 RNTST
   1 BUILD

4000 + 1 + 1 + 1 = 4003 message lines, and the summary says 4002. Which one is uncounted?

$ head -4013 axi_burst_test.log | grep -E '^UVM_INFO ' | tail -1
UVM_INFO @ 40000: reporter [TEST_DONE] 'run' phase is ready to proceed

The last informational message before the summary is the phase-boundary announcement at line 4013 — emitted as the run phase ends, which is after the report server took the snapshot it prints. So the delta is one, it is explained, and it is stable.

5. A Severity Reader

#!/bin/bash
# severity LOG — the run's own counts, cross-checked against the messages.
set -u
log=${1:?usage: severity LOG}
[ -r "$log" ] || { echo "severity: cannot read $log" >&2; exit 2; }

end=$(grep -n -e 'Report Summary' "$log" 2>/dev/null | head -1 | cut -d: -f1)

if [ -z "${end:-}" ]; then
  # no summary at all: a killed or hung run. Count messages and SAY so.
  printf '%-14s %8s %8s\n' SEVERITY MESSAGES REPORTED
  for s in UVM_INFO UVM_WARNING UVM_ERROR UVM_FATAL; do
    printf '%-14s %8s %8s\n' "$s" "$(grep -cE "^$s " "$log")" "-"
  done
  printf 'severity: no report summary in %s -- the run did not finish\n' "$log" >&2
  exit 1
fi

printf '%-14s %8s %8s  %s\n' SEVERITY MESSAGES REPORTED DELTA
rc=0
for s in UVM_INFO UVM_WARNING UVM_ERROR UVM_FATAL; do
  msgs=$(head -n $((end - 1)) "$log" | grep -cE "^$s ")
  rep=$(sed -n "s/^$s *: *\([0-9][0-9]*\).*/\1/p" "$log" | tail -1)
  d=$(( msgs - ${rep:-0} ))
  printf '%-14s %8s %8s  %+d\n' "$s" "$msgs" "${rep:-?}" "$d"
done

verdict=$(grep -oE 'TEST (PASSED|FAILED)' "$log" | tail -1)
printf '\nverdict: %s\n' "${verdict:-NO-VERDICT}"

# the gate: the REPORTED counts decide, not the message counts
e=$(sed -n 's/^UVM_ERROR *: *\([0-9][0-9]*\).*/\1/p' "$log" | tail -1)
f=$(sed -n 's/^UVM_FATAL *: *\([0-9][0-9]*\).*/\1/p' "$log" | tail -1)
if [ "${f:-0}" -gt 0 ] || [ "${e:-0}" -gt 0 ] || [ "${verdict:-}" = "TEST FAILED" ]; then rc=1; fi
exit $rc

$ severity axi_burst_test.log
SEVERITY       MESSAGES REPORTED  DELTA
UVM_INFO           4003     4002  +1
UVM_WARNING           8        8  +0
UVM_ERROR             2        2  +0
UVM_FATAL             0        0  +0

verdict: TEST FAILED
$ echo $?
1

Four decisions.

The deltas are printed, not hidden. A +1 that is always +1 is a known system; the column is there so a change in it is visible. Hiding it would mean the first unexplained discrepancy arrives as a wrong number rather than as a question.

A missing summary is a failure, with a different table. It prints message counts and - for reported, says the run did not finish, and exits 1. That is the NO-VERDICT case again, and conflating it with "zero errors" is how a killed run becomes a pass.

The gate uses the reported counts, not the message counts. §3's reasoning: the report server's accounting is the authority. The message counts are there to be compared, not to decide.

The verdict is also consulted. A run can report zero errors and still fail — an end-of-test check that calls $fatal with no prior error message, or a scoreboard that was never activated. Three independent conditions, any of which fails the run.

6. Severity Is Not a Single Scale

One last complication worth naming, because it determines whether any of this is usable across a project.

Severity is set by whoever wrote the message, and the convention varies. A UVM_WARNING for a protocol timing margin and a UVM_WARNING for an unconnected debug port are the same severity and not remotely the same problem — which is why Chapter 29.6 selects by class rather than by severity.

Severity can be changed at run time. UVM provides mechanisms to demote an error to a warning or promote a warning to an error, usually to work around a known issue. The summary then reports post-demotion counts, which means a run with a demoted error reports zero errors and is, by its own accounting, clean. The only trace is the demotion itself, which appears in the log as a configuration message rather than as a failure — and this is the single best reason to read the top of a log occasionally.

A zero count is not the same as a check that ran. UVM_ERROR : 0 means nothing complained. It does not mean anything looked. Chapter 27.2 measured the version of this that matters most — checks=0 errors=0, a run that examined nothing — and the summary region is exactly where that is invisible, because a scoreboard that was never built emits no errors at all.

So the complete gate is three questions, and the summary answers only the first:

1. did anything complain? — the reported counts
2. did the run finish? — the verdict line
3. did anything actually get checked? — a count of checks, which the summary does not carry

The third has to come from the testbench, which is why the fixture's testbench prints checks=N errors=M and why that habit is worth imposing on a testbench you control.

Practice

1. Print the summary region of one of your logs with sed -n '/pattern/,$p' and count its lines.
2. Note what is absent from it, and which authority produces that instead.
3. Run grep -c for each severity and compare against the summary. Record the deltas.
4. Find every UVM_FATAL line in a log that had no fatal errors, and explain the match.
5. Explain why a manufactured fatal is worse than a manufactured warning, in terms of what happens next.
6. Extract the reported error count with sed and no counting at all.
7. Count the messages properly: cut at the summary and anchor the pattern. Confirm the fatal count becomes 0.
8. Chase any remaining delta to a specific line. Do not stop until you can name it.
9. Write severity with its delta column and confirm it exits 1 on a failing run.
10. Run it on a log with no summary and confirm it says the run did not finish rather than reporting zeros.
11. Make the gate use the message counts instead of the reported ones, and work out which log would then be misjudged.
12. Find out whether your project demotes any severities, and where that appears in the log.
13. Check whether your summary carries a count of checks. If not, decide where that number would come from.

Check Your Understanding

1. What does sed -n '/Report Summary/,$p' do, and why is it right for this region?
2. What is in the summary region, and which important thing is not?
3. What did grep -c UVM_FATAL return, and what was the truth?
4. Where did that single match come from?
5. Why is a manufactured fatal worse than a manufactured warning?
6. What two changes make a message count correct?
7. After both changes, which severity still disagreed, and by how much?
8. What explained that remaining difference?
9. State the three-clause conclusion about the summary and your grep.
10. Why does severity print the deltas rather than hiding them?
11. Why must a missing summary be a failure rather than zero errors?
12. Which counts does the gate use, and why?
13. Give two reasons UVM_ERROR : 0 does not mean the run was correct.

7. Remember

• sed -n '/Report Summary/,$p' prints the summary region, whose length varies between tools.
• The summary carries no exit status. The design writes one and the process produces the other, and they disagreed here: TEST FAILED with status 0.
• A naive grep -c was wrong for every severity, and grep -c UVM_FATAL returned 1 on a run with zero — the only match being the line saying so.
• That is the worst direction to be wrong in: it manufactures the severity that fails a regression, and then it destroys trust in the report.
• Cut at the summary and anchor the pattern to fix it.
• Chase the last discrepancy to a named line. A +1 you can explain is a system; a +1 you cannot is an unknown.
• The summary is the authority, your grep is a cross-check, and the delta must be nameable.
• Print the deltas. A hidden constant becomes an invisible change.
• A missing summary is a failure, not zero errors.
• UVM_ERROR : 0 is not correctness: severities can be demoted, and nothing complaining is not the same as something checking.

8. What Is Next

One log's counts are trustworthy. Chapter 29.4 does it across a directory of them — where the same summary-line contamination arrives multiplied by the number of runs, and where the question becomes which kinds of failure a regression has rather than how many.