Searching Logs and Reports

Part II · Module 24 · Chapter 24.4 · Searching Logs and Reports

The log used throughout this chapter is real output from a real run. A testbench in chip_a emits UVM-shaped messages and vvp wrote the file:

$ wc -l run_2026_10_09/axi_burst_test.log
4021 run_2026_10_09/axi_burst_test.log
$ wc -c run_2026_10_09/axi_burst_test.log | awk '{printf "%.0f KB\n", $1/1024}'
463 KB

Four thousand lines is small. The structure is the same at four million.

1. Source Text and Machine Text Are Opposite Problems

On source you reach for a better pattern. On a log you reach for a count — because a count is a number you can act on and four thousand matching lines are not.

2. Counting a Severity Reports Something That Did Not Happen

The obvious census:

$ for s in UVM_INFO UVM_WARNING UVM_ERROR UVM_FATAL; do
>   printf '%-13s %s\n' "$s" "$(/usr/bin/grep -c "^$s" run_2026_10_09/axi_burst_test.log)"
> done
UVM_INFO      4004
UVM_WARNING   9
UVM_ERROR     3
UVM_FATAL     1

One fatal error. That is the sort of number that stops a release.

Now read what the log itself says:

$ /usr/bin/sed -n '/--- UVM Report Summary ---/,$p' run_2026_10_09/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)

Zero fatals and two errors. Every one of the four counts disagrees with the grep, and in the same direction.

The cause is visible the moment you stop counting and look:

$ /usr/bin/grep -n '^UVM_ERROR' run_2026_10_09/axi_burst_test.log
1344:UVM_ERROR tb/env/axi_sb.sv(201) @ 13370: uvm_test_top.env.sb [MISMATCH] expected 0xdeadbeef got 0xdeadbee0
2911:UVM_ERROR tb/env/axi_sb.sv(201) @ 29000: uvm_test_top.env.sb [MISMATCH] expected 0xcafe0001 got 0xcafe0000
4018:UVM_ERROR : 2
$ /usr/bin/grep -n '^UVM_FATAL' run_2026_10_09/axi_burst_test.log
4019:UVM_FATAL : 0

The summary lines match the pattern. UVM_ERROR : 2 begins with UVM_ERROR, so it is counted as an error; UVM_FATAL : 0 is the only line beginning with UVM_FATAL, so a log with no fatal at all reports one.

That is the defining hazard of searching machine text: the tool writes about its own output, in the same format as its output. Nothing is malformed, nothing errors, and the number is wrong in the direction that causes the most alarm.

3. Finding the First Real Error

In a long log the first error is the one worth reading, because everything after it may be a consequence.

$ /usr/bin/grep -n -m1 '^UVM_ERROR' run_2026_10_09/axi_burst_test.log
1344:UVM_ERROR tb/env/axi_sb.sv(201) @ 13370: uvm_test_top.env.sb [MISMATCH] expected 0xdeadbeef got 0xdeadbee0

-m1 stops after the first match, which on a multi-gigabyte log is the difference between instant and slow — grep stops reading the file, it does not merely stop printing.

With context, which is almost always what you want:

$ /usr/bin/grep -n -m1 -B2 -E '^UVM_ERROR [^ ]*\([0-9]+\) @ ' run_2026_10_09/axi_burst_test.log
1342-UVM_INFO tb/agents/axi_mon.sv(142) @ 13360: uvm_test_top.env.axi_agent.mon [AXI_MON] ad…
1343-UVM_INFO tb/agents/axi_mon.sv(142) @ 13370: uvm_test_top.env.axi_agent.mon [AXI_MON] ad…
1344:UVM_ERROR tb/env/axi_sb.sv(201) @ 13370: uvm_test_top.env.sb [MISMATCH] expected 0xdead…

Note the separator: context lines are joined with - and the match with :. That is how you tell them apart when the output is piped onward, and it is why a downstream cut -d: -f1 on context lines gets the wrong field.

-B2 is before, -A5 after, -C3 both. For a first-error investigation -B is the useful one, because the lines before an error describe what was happening when it occurred; the lines after describe the aftermath.

Three further facts from the same line, extracted rather than eyeballed:

$ /usr/bin/grep -m1 -E '^UVM_ERROR [^ ]*\([0-9]+\) @ ' run_2026_10_09/axi_burst_test.log | sed 's/.*@ \([0-9]*\):.*/\1/'
13370
$ /usr/bin/grep -n -m1 -E '^UVM_ERROR [^ ]*\([0-9]+\) @ ' run_2026_10_09/axi_burst_test.log | cut -d: -f1
1344

Simulation time 13370, log line 1344. Both numbers matter and they are different things: the line number is where to look in the file, and the simulation time is where to look in a waveform.

4. Counting by Category, Not by Line

Four thousand lines is not an answer. Categories are.

By message id, which is the field a UVM message puts in brackets:

$ /usr/bin/grep -oE '\[[A-Z_]+\]' run_2026_10_09/axi_burst_test.log | sort | uniq -c | sort -rn
4000 [AXI_MON]
   8 [SB_LATE]
   2 [MISMATCH]
   1 [TEST_DONE]
   1 [RNTST]
   1 [BUILD]

Six categories, and the whole log in six lines. 4000 of the 4021 lines are one monitor printing one kind of message — which tells you immediately that the log's volume is a verbosity setting, not information.

-o prints only the matched part rather than the whole line, which is what makes this a census rather than a dump. Chapter 14.1 introduced it; on machine text it is the single most useful flag, because the matched part is the category.

By severity and id together, for the ones that matter:

$ /usr/bin/grep -E '^UVM_(ERROR|WARNING) [^ ]*\([0-9]+\) @ ' run_2026_10_09/axi_burst_test.log |
>   sed 's/^\(UVM_[A-Z]*\).*\[\([A-Z_]*\)\].*/\1 \2/' | sort | uniq -c | sort -rn
   8 UVM_WARNING SB_LATE
   2 UVM_ERROR MISMATCH

By source location, which is where to go and fix it:

$ /usr/bin/grep -E '^UVM_(ERROR|WARNING) [^ ]*\([0-9]+\) @ ' run_2026_10_09/axi_burst_test.log |
>   sed 's/^UVM_[A-Z]* \([^ ]*\) @.*/\1/' | sort | uniq -c | sort -rn
   8 tb/env/axi_sb.sv(88)
   2 tb/env/axi_sb.sv(201)

Two lines of one file account for every warning and error in the run. That is an answer — it fits in a message to a colleague, and it names the file and line to open.

And by scope, which says which part of the testbench noticed:

$ /usr/bin/grep -E '^UVM_ERROR [^ ]*\([0-9]+\) @ ' run_2026_10_09/axi_burst_test.log |
>   sed 's/.*: \([^ ]*\) \[.*/\1/' | sort -u
uvm_test_top.env.sb

One scope: the scoreboard. Which is a hierarchy path, and Chapter 23.4 turns it into a file and a line.

5. The Verdict Is Not the Severity Count

Chapter 22.2 §3 measured that a failing test exits 0. So the verdict has to come from the log, and it is a separate question from "how many errors":

$ /usr/bin/grep -E '^(TEST PASSED|TEST FAILED)' run_2026_10_09/axi_burst_test.log
TEST FAILED

Three states, not two, and conflating them is the mistake:

The third is the one that needs its own handling, and Chapter 21.8 §5 gave it its own exit code for exactly this reason. A regression script that treats "no verdict" as a failure sends someone to debug a design that was never exercised; one that treats it as a pass is worse.

6. The Script

#!/usr/bin/env bash
# logsum — summarise a simulation log: verdict, counts, first error, categories
#
# usage: logsum [-q] <log>
#   -q  the one-line form, for a regression table
# exit: 0 passed · 1 failed · 2 no verdict or unusable
set -o nounset

GREP=${GREP:-/usr/bin/grep}
quiet=0
while getopts ':q' o; do
  case $o in
    q) quiet=1 ;;
    \?) printf 'logsum: unknown option -%s\n' "$OPTARG" >&2; exit 2 ;;
  esac
done
shift $(( OPTIND - 1 ))

[ $# -eq 1 ] || { printf 'usage: logsum [-q] <log>\n' >&2; exit 2; }
log=$1
[ -r "$log" ] || { printf 'logsum: cannot read %s\n' "$log" >&2; exit 2; }
[ -s "$log" ] || { printf 'logsum: %s is empty\n' "$log" >&2; exit 2; }

# the message shape, which the report-summary lines deliberately do not match
shape='[^ ]*\([0-9]+\) @ '
count() { "$GREP" -cE "^$1 $shape" "$log"; }

errs=$(count UVM_ERROR)
fatals=$(count UVM_FATAL)
warns=$(count UVM_WARNING)

if   "$GREP" -qE '^TEST PASSED' "$log"; then verdict=PASS
elif "$GREP" -qE '^TEST FAILED' "$log"; then verdict=FAIL
else verdict=NO-VERDICT
fi

# cross-check against the tool's own summary, if it wrote one
claimed=$("$GREP" -E '^UVM_ERROR[[:space:]]*:' "$log" | awk '{print $NF}' | tail -1)

if [ "$quiet" -eq 1 ]; then
  printf '%-10s E=%-4s F=%-3s W=%-4s %s\n' "$verdict" "$errs" "$fatals" "$warns" "${log##*/}"
else
  printf '== %s\n' "$log"
  printf '   verdict     %s\n' "$verdict"
  printf '   errors      %s' "$errs"
  if [ -n "$claimed" ] && [ "$claimed" != "$errs" ]; then
    printf '   (the log says %s — the run may not have finished)' "$claimed"
  fi
  printf '\n'
  printf '   fatals      %s\n' "$fatals"
  printf '   warnings    %s\n' "$warns"
  printf '   lines       %s\n' "$("$GREP" -c '' "$log")"

  if [ "$errs" -gt 0 ] || [ "$fatals" -gt 0 ]; then
    printf '\n   -- first error\n'
    "$GREP" -n -m1 -B2 -E "^UVM_(ERROR|FATAL) $shape" "$log" | cut -c1-96 | sed 's/^/      /'
    printf '\n   -- by source location\n'
    "$GREP" -E "^UVM_(ERROR|FATAL|WARNING) $shape" "$log" |
      sed 's/^UVM_[A-Z]* \([^ ]*\) @.*/\1/' | sort | uniq -c | sort -rn | sed 's/^/      /'
  fi

  printf '\n   -- message categories\n'
  "$GREP" -oE '\[[A-Z_]+\]' "$log" | sort | uniq -c | sort -rn | head -8 | sed 's/^/      /'
fi

case $verdict in
  PASS) [ "$errs" -eq 0 ] && [ "$fatals" -eq 0 ] ;;
  FAIL) exit 1 ;;
  *)    exit 2 ;;
esac

$ ./logsum run_2026_10_09/axi_burst_test.log
== run_2026_10_09/axi_burst_test.log
   verdict     FAIL
   errors      2
   fatals      0
   warnings    8
   lines       4021

   -- first error
      1342-UVM_INFO tb/agents/axi_mon.sv(142) @ 13360: uvm_test_top.env.axi_agent.mon [AXI_MON] …
      1343-UVM_INFO tb/agents/axi_mon.sv(142) @ 13370: uvm_test_top.env.axi_agent.mon [AXI_MON] …
      1344:UVM_ERROR tb/env/axi_sb.sv(201) @ 13370: uvm_test_top.env.sb [MISMATCH] expected …

   -- by source location
         8 tb/env/axi_sb.sv(88)
         2 tb/env/axi_sb.sv(201)

   -- message categories
      4000 [AXI_MON]
         8 [SB_LATE]
         2 [MISMATCH]
         1 [TEST_DONE]
         1 [RNTST]
         1 [BUILD]
$ echo $?
1
$ ./logsum -q run_2026_10_09/axi_burst_test.log
FAIL       E=2    F=0   W=8    axi_burst_test.log

Eight decisions:

The shape is defined once, in a variable, and every count uses it. A pattern repeated four times is a pattern that will be fixed in three places.

-s as well as -r. A zero-byte log is a distinct failure — the tool was launched and wrote nothing — and treating it as "no errors found" is how a crashed run is reported as clean.

The verdict is if/elif/else with three outcomes, never a boolean. §5's third state has its own exit code.

The tool's own count is cross-checked and the disagreement reported, not silently preferred. If the anchored count and the summary differ, the run probably died before writing the summary — and that sentence in the output saves the next person twenty minutes.

grep -c '' for the line count rather than wc -l, because it counts a final line with no trailing newline the same way grep counts everything else. Chapter 17.5 §4 measured that a missing final newline is a real thing in truncated logs — which is precisely the file this script is pointed at.

-q produces one aligned line, because the common use is a hundred of these in a regression table, which is Chapter 32.5.

cut -c1-96 on the first-error block, because a UVM message line is routinely 150 characters and a wrapped line in a summary is unreadable. Truncating for display is fine; truncating before counting would not be.

And ${log##*/} for the basename in the quiet form, with no basename process. Chapter 8.3.

Practice

1. Count a severity in a real log with grep -c '^SEVERITY'. Then find the log's own summary and compare.
2. Print every line matching ^UVM_FATAL (or your tool's equivalent) in a log with no fatals. What do you get?
3. Write the shape-anchored pattern for your tool's message format and confirm it agrees with the summary.
4. Use sed -n '1,/banner/p' to bound a log before counting. What is your tool's banner?
5. Find a log where the anchored count and the summary disagree. What happened to that run?
6. Find the first error with -m1 -B5. Do the five preceding lines explain it?
7. Extract the simulation time and the log line number of the first error. Which would you give a colleague, and when?
8. Run command -v tac. If it is absent, confirm tail -r reverses.
9. Build the message-id census with -oE. What fraction of the log is one category?
10. Produce a by-source-location table. How many distinct lines of code account for every error?
11. Find a log with neither verdict string. Was it a crash, a timeout or a kill?
12. Write logsum and run it on a passing log, a failing log, an empty file and a truncated log. Confirm 0, 1, 2, 2.
13. Then delete the -s check and point it at /dev/null. What does it report?

Check Your Understanding

1. In what way are source and machine text opposite problems?
2. Why did grep -c '^UVM_ERROR' report 3 when the log said 2?
3. Why is the reported UVM_FATAL count of 1 worse than merely wrong?
4. Name the three corrected counting methods.
5. What does it mean when the anchored count and the log's own summary disagree?
6. What does -m1 save on a very large log?
7. How do you tell a context line from a match in grep -B output?
8. Why is -B more useful than -A for a first-error investigation?
9. Why reverse the match list rather than the file?
10. What are the three verdict states, and why does the third need its own code?
11. Why does logsum check -s?

Chapter 29.3 measures what happens when that search is pointed at a report summary: grep -c UVM_FATAL returned 1 on a run that had none.

7. Remember

• Source and logs are opposite problems. Narrow the pattern on source; count first on a log.
• A tool writes about its own output in its own format, so summary lines match your severity pattern.
• Measured: grep -c '^UVM_ERROR' gave 3 where the log said 2, and ^UVM_FATAL gave 1 where there were none.
• Anchor on the message shape — a source location, an @ time, a scope — or bound the file at the summary banner, or read the summary's own number. All three agreed.
• When the methods disagree, the run probably died before writing the summary. Say so.
• -m1 stops reading the file, which matters at gigabyte scale.
• In -B/-A output, a match uses : and context uses -.
• -B beats -A for a first error: before is cause, after is aftermath.
• Both numbers matter: the log line tells you where to read, the simulation time where to look in a waveform.
• -oE turns a log into a census — 4000 of 4021 lines were one message id.
• A by-source-location table is an answer: two lines of one file produced every error.
• tac is GNU-only; tail -r is BSD. Reverse the small list, not the large file.
• Three verdict states, not two. "Neither" needs its own exit code.
• Check that the log is non-empty, or a crashed run reports clean.

8. What Is Next

Chapter 24.5 searches the third kind of text — the build description — to answer "why does this compile differently for you than for me", including a measured case where a -D on the command line is silently ignored.