Linux & Bash · Part II · Module 29 · Log and Report Investigation

Counting and Classifying Failures Across Many Logs

A regression produces hundreds of logs and the useful output is not a number but a short list of distinct failures with counts. Getting there needs two things nobody expects: a normalisation step, because every failure line is unique; and more than one classifier, because the obvious one calls a failed compile a pass.

Intermediate22 min readLinuxPart IILogsRegressionClassification

Part II · Module 29 · Chapter 29.4 · Counting and Classifying Failures Across Many Logs

Chapter 29.3 made one log's counts trustworthy. A regression has hundreds, and the question changes: not "how many errors" but "how many kinds of failure, and which is the biggest". This chapter works on twelve real runs.

1. The Regression Under Examination

Twelve run directories, built from the fixture arbiter plus three mutated versions of it, so every failure is a real simulation failing:

run	verdict	errors	note
`pass_s1`, `pass_s2`, `pass_s3`	`TEST PASSED`	0	genuinely clean
`noreset_s1`	`TEST PASSED`	0	the DUT has no reset
`stuck_s1`, `stuck_s2`, `stuck_s3`	`TEST FAILED`	2	output stuck at zero
`xor_s1`, `xor_s2`	`TEST FAILED`	3	one bit inverted
`liar_s1`	`TEST PASSED`	—	1 error line, and PASSED
`killed`	none	—	1,257 lines, no verdict
`badcompile`	none	—	syntax error, no executable

Two of those rows are the chapter. noreset_s1 passed with a broken design because the test never exercised reset — nothing in any log will reveal it. And liar_s1 printed an error and then printed TEST PASSED, which is what a testbench does when its verdict is not derived from its error count.

2. The Recommended Pipeline, and What It Actually Groups

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

$ grep -h ERROR regress/*/run.log | sort | uniq -c | sort -rn
   3 TB  ERROR @55 dout=00 expected 5a
   3 TB  ERROR @35 dout=00 expected a5
   2 TB  ERROR @75 dout=01 expected 00
   2 TB  ERROR @55 dout=5b expected 5a
   2 TB  ERROR @35 dout=a4 expected a5
   1 TB ERROR dout=a4 expected a5

-h suppresses the filename so the lines can be grouped, and sort | uniq -c | sort -rn is the standard frequency pipeline from Chapter 13.4.

It worked here — six groups from thirteen lines — and it worked because this fixture is tiny and deterministic. Count what it is grouping on:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

13 error lines, 6 unique

Every line carries a simulated time and a data value, so two runs that fail the same way at different times do not group at all. On a real regression with randomised seeds, that pipeline returns one group per line and tells you nothing.

3. Normalisation, and the Regex That Eats the Message

The fix is to remove the varying parts before grouping. The obvious attempt destroys the line:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

$ echo 'TB  ERROR @35 dout=a4 expected a5' | sed 's/[0-9a-f][0-9a-f]*/N/g'
TB  ERROR @N Nout=N NxpNtN N

d, a, e, c, f and b are hex digits

dout begins with d. expected contains e, c and d. A character class of [0-9a-f] matches letters that are also ordinary English, so a pattern intended for hex values consumed most of the words in the message.

The output is still groupable — every line normalises to the same thing — which is what makes this dangerous: the pipeline appears to work, the counts look plausible, and the signature it reports is unreadable. A report that says 12 TB ERROR @T Nout=N NxpNtN N will be read as a tool bug.

The general rule: a hex character class needs a context, not just a length. Anchor it to what precedes the value:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

$ echo 'TB  ERROR @35 dout=a4 expected a5' \
>   | sed 's/@[0-9][0-9]*/@T/g; s/=[0-9a-f][0-9a-f]*/=V/g; s/ [0-9a-f][0-9a-f]*$/ V/'
TB  ERROR @T dout=V expected V

@ then digits for the time, = then hex for an assignment, and a trailing field at end-of-line. Each pattern says where the value is, which is the information [0-9a-f] alone cannot carry. The same reasoning applies to addresses, instance paths and cycle counts: normalise by position, never by alphabet.

With that, the regression collapses to something a person can read:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

$ grep -h -E '(TB +ERROR|UVM_ERROR)' regress/*/run.log \
>   | sed 's/@[0-9][0-9]*/@T/g; s/=[0-9a-f][0-9a-f]*/=V/g; s/ [0-9a-f][0-9a-f]*$/ V/; s/  */ /g' \
>   | sort | uniq -c | sort -rn
  12 TB ERROR @T dout=V expected V
   1 TB ERROR dout=V expected V

Thirteen lines, two signatures. The s/ */ /g at the end collapses runs of spaces, which is what separates the two here — one testbench prints TB ERROR with two spaces and another prints TB ERROR with one. Without it there would be three signatures for two kinds of problem, and whitespace differences are the single most common cause of spurious groups.

4. The Residual Tension, Which Has No Clean Answer

Look at what merged:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

$ for d in regress/*/; do
>   sig=$(grep -h -E '(TB +ERROR|UVM_ERROR)' $d/run.log 2>/dev/null \
>         | sed 's/@[0-9][0-9]*/@T/g; s/=[0-9a-f][0-9a-f]*/=V/g; s/ [0-9a-f][0-9a-f]*$/ V/; s/  */ /g' \
>         | sort -u | head -1)
>   printf '  %-13s %s\n' "$(basename $d)" "${sig:-<no error lines>}"
> done
  badcompile    <no error lines>
  killed        <no error lines>
  liar_s1       TB ERROR dout=V expected V
  noreset_s1    <no error lines>
  pass_s1       <no error lines>
  pass_s2       <no error lines>
  pass_s3       <no error lines>
  stuck_s1      TB ERROR @T dout=V expected V
  stuck_s2      TB ERROR @T dout=V expected V
  stuck_s3      TB ERROR @T dout=V expected V
  xor_s1        TB ERROR @T dout=V expected V
  xor_s2        TB ERROR @T dout=V expected V

stuck_* and xor_* have the same signature and are different bugs — one drives the output to zero, the other inverts a bit. The normalisation that made grouping possible is exactly what erased the distinction.

There is no setting that fixes this, because the two requirements are opposed: normalise too little and nothing groups; normalise too much and distinct failures merge. The practical resolution is not a better regex, it is to report both:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

# the signature groups the runs; a representative line keeps the real values
printf '%6s  %s\n         e.g. %s\n' "$count" "$signature" "$example"

A report that says "5 runs: TB ERROR @T dout=V expected V, e.g. dout=00 expected a5" is actionable, because the example distinguishes stuck-at-zero from an inverted bit at a glance. The count tells you how big the problem is; the example tells you what it is.

5. Three Classifiers, and Why You Need More Than One

Now the more serious issue. Classify each run three ways — by its verdict line, by whether it emitted error lines, and by whether the compile produced an executable:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

  RUN           by verdict   by err lines by artifact  AGREE
  badcompile    NO-VERDICT   PASS         NO-EXE       ** NO
  killed        NO-VERDICT   PASS         ran          ** NO
  liar_s1       PASS         FAIL         ran          ** NO
  noreset_s1    PASS         PASS         ran          yes
  pass_s1       PASS         PASS         ran          yes
  pass_s2       PASS         PASS         ran          yes
  pass_s3       PASS         PASS         ran          yes
  stuck_s1      FAIL         FAIL         ran          yes
  stuck_s2      FAIL         FAIL         ran          yes
  stuck_s3      FAIL         FAIL         ran          yes
  xor_s1        FAIL         FAIL         ran          yes
  xor_s2        FAIL         FAIL         ran          yes

They disagree on three of twelve runs, and each disagreement is a different lesson.

badcompile and killed are PASS by error lines. Counting error lines asks "did anything complain", and a run that never happened complains about nothing. This is the most common defect in a homegrown regression report: grep -c ERROR returns 0 for a compile that failed and for a job the scheduler killed, so both land in the pass column and the report's pass rate is wrong upward.

liar_s1 is PASS by verdict and FAIL by error lines, and here the error-line classifier is right. The testbench printed an error and then printed TEST PASSED, because its verdict was not derived from its error count. No amount of log processing fixes that testbench — but the disagreement is detectable, and a report that surfaces it is doing its job:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

# the two classifiers disagree -- that is information, not an inconvenience
if [ "$by_verdict" != "$by_errors" ]; then
  printf 'INCONSISTENT %-14s verdict says %s, error lines say %s\n' "$n" "$by_verdict" "$by_errors"
fi

And the run no classifier catches

noreset_s1 is PASS by all three. The DUT has no reset at all — the condition that clears the output register was replaced with 1'b0 — and the test passed because it never checked behaviour during or immediately after reset.

Nothing in any log reveals this. There is no error, no warning, no missing artifact, no absent verdict. The run is correct about everything it looked at.

This is Chapter 27.2's checks=0 problem in its more common form: not zero checks, but the wrong three. A log-processing chapter has to be honest about the boundary here — log analysis can tell you that something complained, and it cannot tell you that enough was examined. That question is answered by coverage, by reviewing what the checks actually assert, and by deliberately breaking the design to see whether the suite notices. The fixture's noreset_s1 exists precisely because the mutation was not noticed.

What a report can do is carry the check count, so a run with suspiciously few is visible:

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

checks=$(sed -n 's/.*checks=\([0-9][0-9]*\).*/\1/p' "$log" | tail -1)

Three checks on an arbiter is thin, and a column of 3s next to a column of 4000s invites the right question.

6. The Classifier

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

#!/bin/bash
# classify-runs RUNS — one line per run, four independent signals.
set -u
base=${1:-regress}
[ -d "$base" ] || { echo "classify-runs: no such directory: $base" >&2; exit 2; }

norm='s/@[0-9][0-9]*/@T/g; s/=[0-9a-f][0-9a-f]*/=V/g; s/ [0-9a-f][0-9a-f]*$/ V/; s/  */ /g'
bad=0

printf '%-14s %-11s %-7s %-7s %s\n' RUN VERDICT ERRS CHECKS SIGNATURE
for d in "$base"/*/; do
  [ -d "$d" ] || continue
  n=$(basename "$d")
  log="$d/run.log"
  [ -r "$log" ] || { printf '%-14s %-11s %-7s %-7s %s\n' "$n" NO-LOG - - -; bad=1; continue; }

  if   grep -q 'TEST PASSED' "$log"; then v=PASS
  elif grep -q 'TEST FAILED' "$log"; then v=FAIL
  else v=NO-VERDICT; fi

  e=$(grep -cE '(TB +ERROR|UVM_ERROR|UVM_FATAL)' "$log")
  c=$(sed -n 's/.*checks=\([0-9][0-9]*\).*/\1/p' "$log" | tail -1)
  sig=$(grep -h -E '(TB +ERROR|UVM_ERROR)' "$log" 2>/dev/null | sed "$norm" | sort -u | head -1)

  printf '%-14s %-11s %-7s %-7s %s\n' "$n" "$v" "$e" "${c:--}" "${sig:--}"

  # the cross-checks, reported rather than resolved
  byerr=$( [ "$e" -gt 0 ] && echo FAIL || echo PASS )
  [ "$v" = "NO-VERDICT" ] && { printf '  ** %s did not finish\n' "$n"; bad=1; }
  [ "$v" != "NO-VERDICT" ] && [ "$v" != "$byerr" ] && {
    printf '  ** %s INCONSISTENT: verdict %s, error lines say %s\n' "$n" "$v" "$byerr"; bad=1; }
  [ -s "$d/sim.vvp" ] || { printf '  ** %s has no executable -- the compile failed\n' "$n"; bad=1; }
done

printf '\n-- failure signatures, most common first --\n'
grep -h -E '(TB +ERROR|UVM_ERROR)' "$base"/*/run.log 2>/dev/null \
  | sed "$norm" | sort | uniq -c | sort -rn
exit $bad

Azvya Education Pvt. Ltd.VLSI Mentor

Snippet

$ classify-runs regress
RUN            VERDICT     ERRS    CHECKS  SIGNATURE
badcompile     NO-VERDICT  0       -       -
  ** badcompile did not finish
  ** badcompile has no executable -- the compile failed
killed         NO-VERDICT  0       -       -
  ** killed did not finish
liar_s1        PASS        1       -       TB ERROR dout=V expected V
  ** liar_s1 INCONSISTENT: verdict PASS, error lines say FAIL
noreset_s1     PASS        0       3       -
pass_s1        PASS        0       3       -
pass_s2        PASS        0       3       -
pass_s3        PASS        0       3       -
stuck_s1       FAIL        2       3       TB ERROR @T dout=V expected V
stuck_s2       FAIL        2       3       TB ERROR @T dout=V expected V
stuck_s3       FAIL        2       3       TB ERROR @T dout=V expected V
xor_s1         FAIL        3       3       TB ERROR @T dout=V expected V
xor_s2         FAIL        3       3       TB ERROR @T dout=V expected V

-- failure signatures, most common first --
  12 TB ERROR @T dout=V expected V
   1 TB ERROR dout=V expected V
$ echo $?
1

Four decisions.

It prints four independent signals and resolves none of them. The verdict, the error count, the check count and the signature. A single PASS/FAIL column would have had to choose between the verdict and the error lines for liar_s1, and whichever it chose would have been silently wrong for some other run.

Disagreements are printed as ** lines, inline. They belong next to the run they concern, not in a footer, because the person reading is scanning for their own test.

The check count is a column. §5's note: it cannot detect noreset_s1, and it makes a thin test visible.

It exits non-zero if anything was anomalous, so the regression driver can gate on it — including on inconsistency and a missing executable, not just on failures.

Practice

Run the frequency pipeline over your own regression logs and count how many groups it produces versus how many lines.
Normalise with s/[0-9a-f][0-9a-f]*/N/g on one real error line and read the result.
Explain which letters caused that, and write a positional normalisation instead.
Add the whitespace collapse and count how many spurious groups it removes.
Find two different bugs that share one signature in your own data.
Report a representative line alongside each signature and check whether the two bugs are now distinguishable.
Classify every run three ways and list the disagreements.
Confirm that grep -c ERROR calls a failed compile a pass, and say why.
Build a run whose testbench prints an error and then PASSED, and decide which classifier you would trust.
Mutate your design somewhere your tests do not look, run the regression, and confirm it passes.
Add a check-count column and look for the runs with suspiciously few.
Write classify-runs and confirm it exits non-zero for an inconsistent run even when nothing failed.

Check Your Understanding

Why does grep -h matter in the frequency pipeline?
The pipeline produced six groups from thirteen lines. Why would it produce thirteen on a real regression?
What did s/[0-9a-f][0-9a-f]*/N/g do to dout and expected, and why?
Why is that failure more dangerous than a crash?
What does a positional normalisation express that a character class cannot?
What does s/ */ /g fix, and how many signatures did it merge here?
State the tension that has no clean answer.
How is it resolved in practice?
Which three runs did the classifiers disagree on, and which classifier was right for each?
Why does counting error lines call a failed compile a pass?
For liar_s1, which classifier is correct, and what is the underlying defect?
Why can no log-based classifier detect noreset_s1?
Why does classify-runs print four signals instead of one verdict?

Answers

It suppresses the filename prefix, so identical lines from different files group together instead of each being unique.
Because every line carries a simulated time and a data value. With randomised seeds no two runs produce identical text, so each line becomes its own group.
It replaced them with N, producing Nout and NxpNtN, because d, a, e, c, f and b are hex digits and the class matches ordinary letters.
Because the output is still groupable — every line normalises identically — so the counts look plausible and only the signature is unreadable. It will be read as a tool bug rather than a script bug.
Where the value is: after @, after =, at end of line. A character class can only say what characters a value is made of, which ordinary words share.
Differing runs of whitespace between tools — one testbench prints TB ERROR and another TB ERROR. It merged what would otherwise have been three signatures into two.
Normalise too little and nothing groups; normalise too much and distinct failures merge. stuck_* and xor_* share one signature and are different bugs.
Report both — the signature to group and count, and a representative line with real values so the kinds are distinguishable at a glance.
badcompile and killed, where the verdict classifier is right (they did not finish); and liar_s1, where the error-line classifier is right.
Because it asks "did anything complain", and a run that never happened complains about nothing — so it lands in the pass column and the pass rate is wrong upward.
The error-line classifier. The testbench's verdict is not derived from its error count, so it printed an error and then TEST PASSED.
Because there is nothing in the log to detect: no error, no warning, no missing artifact, no absent verdict. The run was correct about everything it looked at, and it did not look at reset.
Because collapsing them would force a choice between the verdict and the error lines, and whichever was chosen would be silently wrong for some run. The disagreement is information.

7. Remember

Chapter 33.7 applies this normalisation to a whole regression, where grouping on the message alone merged four distinct bugs into two groups of ten.
grep -h … | sort | uniq -c | sort -rn is the frequency pipeline; -h is what lets lines group.
It groups almost nothing on real data, because every failure line carries a time and a value.
[0-9a-f] matches ordinary letters. It turned dout expected into Nout NxpNtN — and the result still grouped, which is what makes it dangerous.
Normalise by position, not by alphabet: after @, after =, at end of line.
Collapse whitespace — differing space runs between tools are the commonest source of spurious groups.
Normalise too little and nothing groups; too much and distinct bugs merge. Report a signature and a representative line.
Counting error lines called a failed compile and a killed run PASS, because a run that never happened complains about nothing.
A verdict classifier called an inconsistent testbench PASS. Neither classifier is sufficient; the disagreement is the finding.
No log-based classifier can detect a bug the tests do not look at. Carry the check count so a thin test is visible.
Print the signals, resolve nothing, and exit non-zero on any anomaly.

8. What Is Next

The runs that produced logs are classified. Chapter 29.5 takes the two that did not — and finds that a simulation which runs out of events does not hang at all: it exits zero, with no verdict, in under a second.

Where this fits

Part of the Linux & Bash curriculum.