Filtering Real Logs and Reports

Part I · Module 4 · Chapter 4.7 · Filtering Real Logs and Reports

1. Why This Matters

The module's six previous chapters each taught one tool against one fixture. That is how you learn them and it is not how you use them.

A real triage asks several questions of several files in one pass, and the answers go into an email that somebody reads at 8am. So this chapter has two jobs: assemble the pieces, and be honest about the result.

Every number a triage script prints is a count of records matching a pattern. Whether it means what its label says is a separate question.

Two synthetic logs in a directory:

100 UVM_INFO Test started
420 UVM_ERROR Data mismatch
500 UVM_INFO Test finished

100 UVM_INFO Test started
250 UVM_WARNING Retry
480 UVM_ERROR Addr mismatch
520 UVM_FATAL Bus hung

2. FILENAME: Knowing Which File

When awk reads several files, FILENAME holds the name of the one currently being read. It is the minimum you need for multi-file output to be useful, and it is the registry's own example for this chapter:

awk '/UVM_ERROR/ { print FILENAME ": " $0 }' logs/*.log

logs/alu.log: 420 UVM_ERROR Data mismatch
logs/uart.log: 480 UVM_ERROR Addr mismatch

The shell expanded logs/*.log into both filenames and awk read them in turn, as one continuous stream of records. Without FILENAME the two error lines would be indistinguishable, which is useless when the next step is to open the failing test's log.

FILENAME and its companion FNR belong to Chapter 7.4, and Chapter 7.5 covers multi-file processing properly. They appear here because this chapter's subject cannot be demonstrated on one file.

3. Field-Anchored, Not Whole-Record

That first command uses a whole-record match, and Chapter 4.1 spent a chapter explaining why that is the loose choice. Anchoring to the severity column:

awk '$2 == "UVM_ERROR" { print FILENAME, $1, $3, $4 }' logs/*.log

logs/alu.log 420 Data mismatch
logs/uart.log 480 Addr mismatch

Same two records here, because neither log happens to contain a message mentioning the word. Chapter 4.1's sim.log did contain one, and on that input the two commands differ by a record.

The lesson from 4.1 applies in full: use == for a closed vocabulary like a severity, and keep the loose match for free-form message text. Both appear in the same rule in section 6.

Accepting either failing severity, with the anchored alternation from Chapter 4.4:

awk '$2 ~ /^UVM_(ERROR|FATAL)$/ { print FILENAME, $1, $2 }' logs/*.log

logs/alu.log 420 UVM_ERROR
logs/uart.log 480 UVM_ERROR
logs/uart.log 520 UVM_FATAL

The ^ and $ anchor to the field, so the alternation cannot match a substring of a longer severity and cannot match a message.

4. Several Categories in One Pass

Reading a directory twice to count two things is wasteful and can disagree with itself if the files change between passes. One pass, several counters:

awk '$2 == "UVM_ERROR" { e++ } $2 == "UVM_WARNING" { w++ } $2 == "UVM_FATAL" { f++ } END { printf "errors=%d warnings=%d fatals=%d\n", e+0, w+0, f+0 }' logs/*.log

errors=2 warnings=1 fatals=1

Three rules, each counting its own category, and an END block reporting all three. Chapter 2.3 explained why this works: every rule is tried against every record, so one pass can answer any number of independent questions.

Adding a verdict derived from the counts, with the ternary from Chapter 4.6:

awk '$2 == "UVM_ERROR" { e++ } $2 == "UVM_WARNING" { w++ } $2 == "UVM_FATAL" { f++ } END { printf "errors=%d warnings=%d fatals=%d verdict=%s\n", e+0, w+0, f+0, (f+0 > 0 ? "FATAL" : (e+0 > 0 ? "FAIL" : "CLEAN")) }' logs/*.log

errors=2 warnings=1 fatals=1 verdict=FATAL

The nested ternary reads as a priority order: a fatal outranks an error, an error outranks a clean run. That ordering is an engineering decision, not a property of awk, and it belongs somewhere a reviewer can see it.

5. Per-File Counts

An aggregate across a directory hides which test failed. Getting a count per file without arrays takes a boundary trick:

awk 'FNR == 1 && NR > 1 { print f, n+0; n = 0 } FNR == 1 { f = FILENAME } $2 == "UVM_ERROR" { n++ } END { print f, n+0 }' logs/*.log

logs/alu.log 1
logs/uart.log 1

FNR is the record number within the current file, so FNR == 1 marks the first record of each file. The logic: when a new file starts and it is not the very first record of the run, print the previous file's tally and reset; remember the new filename; count errors; and in END, flush the last file — because no new file ever starts after it.

6. Extraction, Not Just Counting

A triage that only counts tells you something is wrong. One that extracts tells you what. Chapter 4.5's match() and substr() pull a value out of free-form message text:

100 UVM_INFO Test started
410 UVM_ERROR Data mismatch at addr 0x1f40 after 12.75 us
505 UVM_ERROR Parity error after 3.10 us

awk '$2 == "UVM_ERROR" && match($0, /0x[0-9a-f]+/) { print FILENAME, $1, substr($0, RSTART, RLENGTH) }' mem.log

mem.log 410 0x1f40

One record — the second error carries no address, so match() returned 0 and the && short-circuited before substr() was reached. That is Chapter 4.2's short-circuit rule making the rule safe rather than merely fast: substr() is never called with the stale RSTART from a previous record.

Combining both degrees of tightness from Chapter 4.1 in one rule — exact field for the severity, loose match for the message:

awk '$2 == "UVM_ERROR" && $0 ~ /mismatch/ { print FILENAME, $1 }' mem.log

mem.log 410

7. What These Numbers Do Not Prove

This is the section the chapter exists for. The commands above work. Here is what their output does not license you to say — every point established earlier in the track, collected where it matters.

An error count is not a bug count. One root cause commonly prints an error on every subsequent transaction. errors=2 across two logs could be two independent bugs or one bug reported twice. Chapter 1.2 made this point; nothing in this chapter changes it.

Zero errors is not a passing run. A simulator that failed to compile, or died during elaboration, never reaches the point of printing a UVM error. Its log contains no error records and the run did not pass. verdict=CLEAN from section 4 would be wrong on such a log.

A missing log is invisible. logs/*.log expands to the files that exist. A test that crashed before writing anything contributes no records, no filename, and no error — so it silently does not appear in the output at all. This is the most dangerous item on the list, because the triage cannot see the thing it is missing.

A count of records is not a count of tests. Section 5 counts error records per file; a file is one test only if your flow guarantees one log per test.

The verdict ordering is a policy. Section 4 decided a fatal outranks an error. That is reasonable and it is a choice, and a different project might treat any warning as blocking.

8. A Complete Triage

Everything from the module, in one command, structured so the numbers carry their own context:

awk 'FNR == 1 { files++ } { total++ } $2 == "UVM_FATAL" { f++ } $2 == "UVM_ERROR" { e++ } $2 == "UVM_WARNING" { w++ } END { printf "%d files, %d records: %d fatal, %d error, %d warning records -> %s\n", files+0, total+0, f+0, e+0, w+0, (f+0 ? "FATAL" : (e+0 ? "FAIL" : "CLEAN")) }' logs/*.log

2 files, 7 records: 1 fatal, 2 error, 1 warning records -> FATAL

Read what that line claims. Two files were read and seven records seen — so if the regression launched five tests, the 2 files is itself the finding. The category counts are labelled records, not bugs. And the verdict is derived from the counts rather than asserted.

Setting an exit status so a calling script can act on it, using exit from Chapter 2.4:

awk 'FNR == 1 { files++ } { total++ } $2 == "UVM_FATAL" { f++ } $2 == "UVM_ERROR" { e++ } END { printf "%d files, %d records, %d fatal, %d error\n", files+0, total+0, f+0, e+0; exit (f+0 || e+0) ? 1 : 0 }' logs/*.log
echo "status: $?"

2 files, 7 records, 1 fatal, 2 error
status: 1

A non-zero status a nightly job can test, which Chapter 1.6 argued for and Chapter 2.4 supplied the tool for. And on a clean log:

printf '100 UVM_INFO Test started\n500 UVM_INFO Test finished\n' > clean.log
awk 'FNR == 1 { files++ } { total++ } $2 == "UVM_FATAL" { f++ } $2 == "UVM_ERROR" { e++ } END { printf "%d files, %d records, %d fatal, %d error\n", files+0, total+0, f+0, e+0; exit (f+0 || e+0) ? 1 : 0 }' clean.log
echo "status: $?"

1 files, 2 records, 0 fatal, 0 error
status: 0

1 files, 2 records is what makes that zero trustworthy — a zero with no denominator could have come from an empty file, and this one demonstrably read two records.

9. Common Mistakes

Using a whole-record severity match. Sections 2 and 3, and Chapter 4.1 at length. A message mentioning a severity gets counted as one.

Omitting END from the per-file idiom. Section 5's callout. The last file's count is silently dropped.

Calling an error count a bug count. Section 7.

Treating zero errors as a pass. Section 7. A tool that died prints none.

Forgetting that a missing log contributes nothing. Section 7. Count the files.

Reporting a count with no denominator. Chapter 4.6 section 5, and section 8 is the fix.

Reading the directory twice for two numbers. Section 4. One pass answers any number of independent questions.

Calling substr() without checking match() succeeded. Section 6. RSTART holds the previous record's value, so the output would be plausible and wrong.

Hand-rolling per-file counts when arrays exist. Section 5's callout. Module 6 and Chapter 13.1.

10. Exercises

Exercise 1 — Predict the output

100 UVM_INFO Test started
420 UVM_ERROR Data mismatch
500 UVM_INFO Test finished

100 UVM_INFO Test started
250 UVM_WARNING Retry
480 UVM_ERROR Addr mismatch
520 UVM_FATAL Bus hung

awk 'END { print NR, FNR }' logs/*.log

7 4

NR is 7 — the total across both files. FNR is 4, the record number within the last file, because FNR restarts at 1 for each file and is never reset afterwards. If you expected 7 7 or 7 1, that distinction is Chapter 7.4's subject and worth meeting now.

Exercise 2 — Modify a command

Print every warning record with its filename, anchored to the severity field.

awk '$2 == "UVM_WARNING" { print FILENAME, $1, $3 }' logs/*.log

logs/uart.log 250 Retry

One record, in one of the two files. The exact field test is right because severity is a closed vocabulary.

Exercise 3 — Trace the category counts

Predict the three counts, then check that they are consistent with the record total.

awk '$2 == "UVM_INFO" { i++ } $2 == "UVM_WARNING" { w++ } $2 == "UVM_ERROR" { e++ } $2 == "UVM_FATAL" { f++ } END { print i+0, w+0, e+0, f+0, "of", NR }' logs/*.log

3 1 2 1 of 7

Three info, one warning, two error, one fatal — and 3+1+2+1 is 7, which equals NR. That sum is the check: had it come to less than NR, some record carries a severity none of the four rules recognises, and the categories are not exhaustive. Chapter 4.6 section 9 made this point with a catch-all rule.

Exercise 4 — Debug a dropped file

An engineer's per-file count reports one fewer line than there are logs. Their command is below. Find the bug.

awk 'FNR == 1 && NR > 1 { print f, n+0; n = 0 } FNR == 1 { f = FILENAME } $2 == "UVM_ERROR" { n++ }' logs/*.log

logs/alu.log 1

One line for two files. The tally is printed when a new file begins, so the last file's count is never flushed — nothing starts after it. Section 5's END clause is the missing piece:

awk 'FNR == 1 && NR > 1 { print f, n+0; n = 0 } FNR == 1 { f = FILENAME } $2 == "UVM_ERROR" { n++ } END { print f, n+0 }' logs/*.log

logs/alu.log 1
logs/uart.log 1

Two lines for two files. The failure direction is what makes this nasty — the output looked like a valid report, just shorter.

Exercise 5 — Engineering application

Report the number of files read, the record total, and the error-record count, for a directory.

awk 'FNR == 1 { files++ } $2 == "UVM_ERROR" { e++ } END { print files+0, "files,", NR, "records,", e+0, "error records" }' logs/*.log

2 files, 7 records, 2 error records

FNR == 1 fires once per file, which is the cheapest file counter available. NR supplies the record total with no counter at all. And the label says error records, which is the honest noun — section 7's discipline in the output rather than only in the prose.

Exercise 6 — Challenge: make a missing log visible

The triage cannot see a test that produced no log. Write a command that takes the expected number of tests as a parameter and reports a discrepancy, then run it for an expectation of 2 and of 5.

awk -v expected=2 'FNR == 1 { files++ } $2 == "UVM_ERROR" { e++ } END { printf "%d of %d expected logs read, %d error records%s\n", files+0, expected, e+0, (files+0 < expected ? "  *** MISSING LOGS ***" : "") }' logs/*.log

2 of 2 expected logs read, 2 error records

awk -v expected=5 'FNR == 1 { files++ } $2 == "UVM_ERROR" { e++ } END { printf "%d of %d expected logs read, %d error records%s\n", files+0, expected, e+0, (files+0 < expected ? "  *** MISSING LOGS ***" : "") }' logs/*.log

2 of 5 expected logs read, 2 error records  *** MISSING LOGS ***

The second run is the one that matters. Nothing about the logs changed — the same two files, the same two error records. What changed is that the script was told what to expect, so it could notice that three tests produced nothing at all.

This is the only item in section 7 that a script can detect by itself, and it needs information from outside the files. The expectation has to come from whatever launched the regression, which is why Chapter 12.6's nightly job carries it and why -v (Chapter 8.2) is the mechanism.

The other caveats — an error count not being a bug count, a clean log not proving a pass — cannot be settled from inside the log at all. They are read by an engineer, and the script's job is to present the evidence in a form that makes the limits visible.

11. Summary

• FILENAME names the file currently being read, which is what makes multi-file output actionable. FNR is the record number within that file. Both are Chapter 7.4's subject.
• Anchor a severity test to its field. A whole-record match counts a message that mentions a severity.
• An anchored alternation on a field — $2 ~ /^UVM_(ERROR|FATAL)$/ — accepts a set of exact values without matching substrings.
• One pass answers any number of independent questions, because every rule is tried against every record.
• Per-file counts without arrays need a flush in END, or the last file is silently dropped. Arrays remove the problem entirely — Module 6.
• Check match() before substr(). RSTART holds the previous record's value, so an unguarded extraction is plausible and wrong.
• An error count is not a bug count, zero errors is not a pass, and a missing log is invisible. None of these is fixed by a better pattern.
• Report the denominator and label the noun. 2 error records in 7 records across 2 files is checkable; 2 errors is not.
• A missing log can only be detected against an expectation from outside the files.

That completes Module 4, and with it the whole of awk's selection machinery. You can decide which records matter by position, by value, by shape, by span, and by any combination — and you can extract a value from text that has no columns at all.

What every rule in this module has had in common is that it makes one decision per record and then forgets. The counters in this chapter hinted at the next step: a variable that survives from one record to the next is already a kind of memory, and once you have that, you need the rest of a language — somewhere to put a value, a way to branch, a way to loop. Module 5, Variables, Operators, and Control Flow, is where awk stops being a filter and becomes a small programming language.