When the Log Is Missing, Empty or Truncated

Part I · Module 15 · Chapter 15.10 · When the Log Is Missing, Empty or Truncated

1. The Question Behind the Question

"Did smoke_test pass?" looks like a yes-or-no question about a log file. It is not, because before you can answer it you must answer a prior one: is there a log, and is it a whole one?

The states, and what each one means about the job:

Only the last row is a test result. The other four are infrastructure failures, and a flow that cannot tell them apart cannot be trusted.

2. Why the Naive Parser Reports Success

Chronologic VCS simulator copyright 1991-2024
UVM_INFO @ 0: reporter [RNTST] Running test smoke_test...
UVM_INFO @ 1200: uvm_test_top.env.agt [SEQ] starting sequence
UVM_INFO @ 2400: uvm_test_top.env.agt [SEQ] item 1 don

def verdict(path):
    errors = 0
    with open(path) as f:
        for line in f:
            if "UVM_ERROR" in line or "UVM_FATAL" in line:
                errors += 1
    return "FAIL" if errors else "PASS"


print("verdict:", verdict("truncated.log"))

verdict: PASS

The log stops mid-word — item 1 don — because the process was killed while writing. The parser found no errors, and no errors became PASS.

Nothing here is a bug in the ordinary sense. Every line was read correctly. The flaw is the inference: absence of evidence of failure is not evidence of success, and on a truncated log it is evidence of nothing at all.

3. The Two Cheap States

The canonical check, and it is two lines:

if not path.exists():
    return "NO_LOG"
if path.stat().st_size == 0:
    return "EMPTY_LOG"

Executed, with the Chapter 15.8 Section 4 gating:

from pathlib import Path

Path("ran.log").write_text("Compile start\nSimulation complete\n")
Path("died.log").write_text("")


def pre_check(name):
    p = Path(name)
    if not p.exists():
        return "NO_LOG"
    if not p.is_file():
        return "NOT_A_FILE"
    if p.stat().st_size == 0:
        return "EMPTY_LOG"
    return "HAS_CONTENT"


for name in ["ran.log", "died.log", "never.log"]:
    print(f"{name:<12} {pre_check(name)}")

ran.log      HAS_CONTENT
died.log     EMPTY_LOG
never.log    NO_LOG

Both checks are cheap — neither reads a byte of content — and both are certain. An empty file is empty; there is no ambiguity to resolve.

The is_file() line is there because exists() is true for a directory (Chapter 15.8 Section 3), and stat().st_size on one is machine-dependent.

4. Truncation Is Not Visible to the Filesystem

Here is the difficulty. Compare a complete log and a truncated one by every property the filesystem offers:

Compile start
UVM_INFO running
Simulation complete

Compile start
UVM_INFO runn

from pathlib import Path

for name in ["complete.log", "cut.log"]:
    p = Path(name)
    print(f"{name:<14} exists={p.exists()} is_file={p.is_file()} "
          f"size={p.stat().st_size} nonzero={p.stat().st_size > 0}")

complete.log   exists=True is_file=True size=51 nonzero=True
cut.log        exists=True is_file=True size=28 nonzero=True

Identical on every count that matters. Both exist, both are files, both are non-empty. Size differs, but you cannot know what size this log should have been — that depends on the test.

A truncated file is, as Chapter 15.1 Section 6 put it, valid text that simply stops. Nothing in the filesystem knows the difference between a file that ended and a file that was interrupted.

5. The End Marker Is the Only Evidence

The one thing that distinguishes them is a line the tool promises to write last:

Compile start
UVM_INFO running
Simulation complete

Compile start
UVM_INFO runn

END_MARKER = "Simulation complete"


def finished(path):
    last = ""
    with open(path) as f:
        for line in f:
            last = line
    return END_MARKER in last


for name in ["complete.log", "cut.log"]:
    print(f"{name:<14} finished={finished(name)}")

complete.log   finished=True
cut.log        finished=False

The loop keeps only the most recent line — bounded, as Chapter 15.7 Section 5 requires — and the test is whether the file's last line is the marker.

Checking the last line rather than anywhere in the file matters:

Simulation complete was expected but
UVM_INFO still runn

END_MARKER = "Simulation complete"


def finished_anywhere(path):
    with open(path) as f:
        return END_MARKER in f.read()


def finished_lastline(path):
    last = ""
    with open(path) as f:
        for line in f:
            last = line
    return END_MARKER in last


print("anywhere :", finished_anywhere("sneaky.log"))
print("last line:", finished_lastline("sneaky.log"))

anywhere : True
last line: False

A log that mentions the marker in passing is not a finished log. The last-line version is also the streaming-safe one: f.read() on a 20 GB log is Chapter 15.7's forbidden move.

6. The Fourth State

A log can be complete and still not answer the question:

Chronologic VCS simulator copyright 1991-2024
UVM_INFO @ 0: reporter [RNTST] Running test smoke_test...
UVM_INFO @ 400: uvm_test_top [ENV] build phase done
Simulation complete

END_MARKER = "Simulation complete"


def classify(path):
    verdict = None
    last = ""
    with open(path) as f:
        for line in f:
            last = line
            if "TEST FAILED" in line or "UVM_FATAL" in line:
                verdict = "FAIL"
            elif "TEST PASSED" in line and verdict is None:
                verdict = "PASS"
    if END_MARKER not in last:
        return "TRUNCATED"
    if verdict is None:
        return "NO_VERDICT"
    return verdict


print("classify:", classify("noverdict.log"))

classify: NO_VERDICT

The run finished cleanly and never said whether the test passed. That happens when the test is killed politely, when a UVM phase never completes, or when the test name was wrong and nothing ran.

It is kept separate from TRUNCATED because the remedies differ: a truncated log usually means rerun, while NO_VERDICT on a complete log means something is wrong with the test or the harness and rerunning will reproduce it. A flow that merges them learns to ignore both.

7. Order the Checks by Cost and Certainty

The checks must run in a specific order, and the reason is mechanical rather than stylistic:

from pathlib import Path


def classify_wrong(name):
    p = Path(name)
    if p.stat().st_size == 0:        # asks before checking it is there
        return "EMPTY_LOG"
    if not p.exists():
        return "NO_LOG"
    return "HAS_CONTENT"


try:
    print(classify_wrong("never.log"))
except FileNotFoundError as e:
    print("raised:", type(e).__name__, "--", e.strerror)

raised: FileNotFoundError -- No such file or directory

stat() raises on a missing path (Chapter 15.8 Section 4), so the existence check must come first. The general rule:

Cheapest and most certain first. Each check may assume every earlier one passed.

In order: does it exist → is it a file → is it non-empty → does it end properly → what does it say. Each step is a precondition for the next, which is why the classifier reads as a chain of early returns.

8. The One Handler That Earns Its Place

Chapter 15.8 Section 6 showed that a check can pass and the open still fail — another process can delete the file in between. In a classifier that runs against thousands of logs on a shared farm, that is not hypothetical:

from pathlib import Path

END_MARKER = "Simulation complete"


def classify(name):
    """Return (state, reason). state is a verdict or an infrastructure failure."""
    p = Path(name)

    if not p.exists():
        return ("NO_LOG", "the tool produced no log at all")
    if not p.is_file():
        return ("NOT_A_FILE", f"{p.name} exists but is not a file")
    if p.stat().st_size == 0:
        return ("EMPTY_LOG", "the tool started and wrote nothing")

    verdict = None
    last = ""
    try:
        with open(p, encoding="utf-8", errors="replace") as f:
            for line in f:
                last = line
                if "TEST FAILED" in line or "UVM_FATAL" in line:
                    verdict = "FAIL"
                elif "TEST PASSED" in line and verdict is None:
                    verdict = "PASS"
    except OSError as e:
        return ("UNREADABLE", f"{type(e).__name__} while reading {p.name}")

    if END_MARKER not in last:
        return ("TRUNCATED", "no end marker -- the run was interrupted")
    if verdict is None:
        return ("NO_VERDICT", "the run finished without a pass or fail line")
    return (verdict, "a real result")


Path("pass.log").write_text(
    "Running test smoke_test\nUVM_INFO [FINISH] *** TEST PASSED ***\nSimulation complete\n")
Path("fail.log").write_text(
    "Running test cdc_test\nUVM_ERROR drv.sv(88) bad handshake\n"
    "UVM_INFO [FINISH] *** TEST FAILED ***\nSimulation complete\n")
Path("cut.log").write_text("Running test burst_test\nUVM_INFO item 1 don")
Path("empty.log").write_text("")
Path("quiet.log").write_text("Running test reset_test\nSimulation complete\n")

for name in ["pass.log", "fail.log", "cut.log", "empty.log", "quiet.log", "never.log"]:
    state, reason = classify(name)
    print(f"{name:<11} {state:<11} {reason}")

pass.log    PASS        a real result
fail.log    FAIL        a real result
cut.log     TRUNCATED   no end marker -- the run was interrupted
empty.log   EMPTY_LOG   the tool started and wrote nothing
quiet.log   NO_VERDICT  the run finished without a pass or fail line
never.log   NO_LOG      the tool produced no log at all

Six inputs, six distinct answers, none of them a lie.

The except OSError is the handler the canonical purpose calls "the first try/except that matters", and it passes Chapter 14.4's test: it has a real action — return a distinct state — and it does not pretend the file was read. OSError is the right breadth because it covers FileNotFoundError, PermissionError and the rest of the family (Chapter 14.5 Section 5), all of which mean the same thing here: we could not read it, and that is not a test result.

Note also errors="replace" (Chapter 15.3 Section 6). A vendor banner with an odd byte must not turn a FAIL into a crash.

9. Return a State, Not a Boolean

classify returns a pair rather than True/False, and that shape matters. A boolean forces every caller to collapse six outcomes into two, and the collapse is where information dies:

RESULTS = [
    ("smoke", "PASS"), ("cdc", "FAIL"), ("burst", "TRUNCATED"),
    ("reset", "EMPTY_LOG"), ("arb", "NO_LOG"), ("perf", "NO_VERDICT"),
]

counts = {}
for _, state in RESULTS:
    counts[state] = counts.get(state, 0) + 1

real = counts.get("PASS", 0) + counts.get("FAIL", 0)
infra = len(RESULTS) - real

print("tests submitted    :", len(RESULTS))
print("real results       :", real)
print("infrastructure     :", infra)
for state in sorted(counts):
    print(f"  {state:<11} {counts[state]}")
print()
print("naive pass rate    :", f"{counts.get('PASS', 0)}/{len(RESULTS)}")
print("honest pass rate   :", f"{counts.get('PASS', 0)}/{real}", "of results that exist")

tests submitted    : 6
real results       : 2
infrastructure     : 4
  EMPTY_LOG   1
  FAIL        1
  NO_LOG      1
  NO_VERDICT  1
  PASS        1
  TRUNCATED   1

naive pass rate    : 1/6
honest pass rate   : 1/2 of results that exist

Two different numbers from one set of runs, and both are honest about something different. 1/6 understates the design's quality by blaming it for four infrastructure failures. 1/2 describes the design and says so. What you must never report is 1/1 — a pass rate computed over only the logs that happened to parse.

Module 17 Chapter 17.7 turns these states into exit codes and policy. This chapter is the mechanism.

10. Predict, Run, Observe

Running test p
UVM_INFO [FINISH] *** TEST PASSED ***

END_MARKER = "Simulation complete"


def classify(path):
    verdict = None
    last = ""
    with open(path) as f:
        for line in f:
            last = line
            if "TEST PASSED" in line:
                verdict = "PASS"
    if END_MARKER not in last:
        return "TRUNCATED"
    return verdict or "NO_VERDICT"


print("A:", classify("p.log"))
with open("p.log") as f:
    print("B:", repr(f.read()[-12:]))

A: TRUNCATED
B: ' PASSED ***\n'

A is TRUNCATED, not PASS — and this is the case that decides whether the classifier is worth having. The log says the test passed. It even ends with a newline, so it does not look cut off. But the tool's end marker is absent, so the run did not finish.

That is the right answer. A test that reports TEST PASSED and is then killed during cleanup may have left no coverage database, no waveform and no results file. Trusting the verdict line alone would report a success the flow cannot reproduce.

B shows why it is not obvious: the last line is complete and well-formed. Truncation does not have to happen mid-word, and a check that looks for a dangling partial line would miss this entirely.

The order of the two checks is what produces this. TRUNCATED is tested before the verdict is returned, so completeness outranks content — which is the whole argument of Section 7.

11. Exercises

Exercise 1 — the naive parser. Run Section 2's verdict on a truncated log and confirm it says PASS. Write the one-sentence explanation you would give a colleague.

Exercise 2 — two cheap states. Implement pre_check and test it against a real file, an empty file and a missing name.

Exercise 3 — indistinguishable. Tabulate exists, is_file and st_size for a complete and a truncated log. Say which column, if any, could classify them.

Exercise 4 — the marker. Find the real end-of-run marker for a simulator you have access to, and say how you confirmed it is always last.

Exercise 5 — anywhere versus last line. Build a log that mentions the end marker in the middle. Show the two checks disagreeing and say which is right.

Exercise 6 — the fourth state. Produce a complete log with no verdict. Say what you would do about it that differs from a truncated one.

Exercise 7 — wrong order. Put the stat() check before the exists() check and record the traceback. State the rule in your own words.

Exercise 8 — two pass rates. For a regression of 200 jobs where 30 produced no usable log, compute both pass rates. Say which you would put in a report and what you would say about the other.

12. Summary

• Before "did it pass" comes "is there a whole log" — and four of the six possible answers are infrastructure failures, not test results.
• NO_LOG and EMPTY_LOG are cheap and certain: one exists() and one st_size, reading nothing.
• Gate stat() behind is_file(), because exists() is true for a directory and a directory's size is machine-dependent.
• Truncation is invisible to the filesystem — a cut log exists, is a file, and is non-empty, exactly like a complete one.
• An end marker the tool promises to write is the only evidence, and it must be checked on the last line, not anywhere in the file.
• Confirm the real marker empirically for every tool you parse.
• NO_VERDICT is a separate state from TRUNCATED because the remedies differ: rerun versus investigate.
• Order the checks cheapest and most certain first; each may assume the earlier ones passed, and stat() raises if you get it wrong.
• One except OSError around the read earns its place — the file can vanish between the check and the open.
• Return a state and a reason, not a boolean, so the caller can tell a result from a failure.
• A pass rate computed only over logs that parsed is the one number you must never publish.

That closes Module 15. You can open a file, read it at any size, write one safely, ask what is there, change it carefully, and — most importantly — tell the difference between a result and the absence of one. The next module turns the loose variables these parsers return into objects that carry their own meaning.