Python Part II · Module 33 · Testing and Debugging Automation
Testing the Command-Line Contract
A flow script has two audiences. A human reads what it prints; another script reads its exit code, and only one of those is a contract — the wrapper in Chapter 32.3 branched on `$?` and never looked at the text. So the exit code is the part worth asserting, which the canonical annotation gets right. It also asserts the one value that cannot distinguish a script that found problems from a script that crashed, and fixing that turns out to require a test on something other than the code.
Advanced20 min readPythonPart IIAutomationTestingExit Codes
Part II · Module 33 · Chapter 33.8 · Testing the Command-Line Contract
1. Two Audiences, One Contract
AUDIENCES = [
("a human", "the printed text", "tolerates rewording", "no"),
("a wrapper script", "the exit code", "breaks on a changed code", "yes"),
("a consumer reading stdout", "the data on stdout", "breaks on stray text", "yes"),
("a log reader", "stderr", "tolerates anything", "no"),
]
print(f"{'audience':<30} {'reads':<22} {'on a change':<30} contract")
for who, reads, change, contract in AUDIENCES:
print(f"{who:<30} {reads:<22} {change:<30} {contract}")
print()
print("audiences whose expectations are a contract:", 2)
print("what 32.3's wrapper branched on :", "$? only")
print("what it never examined :", "the text")audience reads on a change contract
a human the printed text tolerates rewording no
a wrapper script the exit code breaks on a changed code yes
a consumer reading stdout the data on stdout breaks on stray text yes
a log reader stderr tolerates anything no
audiences whose expectations are a contract: 2
what 32.3's wrapper branched on : $? only
what it never examined : the textTwo of four audiences have a contract, and the canonical purpose names the first. Section 6 is about the second, which is the clause people forget: not only what code the tool returns but which stream it writes on.
2. The Annotation
cp = subprocess.run([sys.executable, "check_log.py", BAD_LOG])
assert cp.returncode == 1import subprocess
import sys
from pathlib import Path
Path("check_log.py").write_text(
'import sys\n'
'\n'
'def main(argv):\n'
' if len(argv) < 2:\n'
' print("usage: check_log.py LOG", file=sys.stderr)\n'
' return 2\n'
' text = open(argv[1], encoding="utf-8").read()\n'
' errors = sum(1 for l in text.splitlines()\n'
' if l.startswith("UVM_ERROR"))\n'
' print(f"{errors} errors")\n'
' return 1 if errors else 0\n'
'\n'
'if __name__ == "__main__":\n'
' sys.exit(main(sys.argv))\n', encoding="utf-8")
Path("bad.log").write_text("UVM_INFO started\nUVM_ERROR drv.sv(88): bad\n"
"TEST DONE\n", encoding="utf-8")
Path("good.log").write_text("UVM_INFO started\nTEST DONE\n", encoding="utf-8")
cp = subprocess.run([sys.executable, "check_log.py", "bad.log"],
stdout=subprocess.PIPE, text=True)
assert cp.returncode == 1
print("the annotation's assertion passed")
print("returncode:", cp.returncode)
print("stdout :", cp.stdout.strip())
print()
cp2 = subprocess.run([sys.executable, "check_log.py", "good.log"],
stdout=subprocess.PIPE, text=True)
print("a clean log gives:", cp2.returncode, cp2.stdout.strip())
print()
print("sys.executable is used because:", "`python` may not exist — 32.3 §3")the annotation's assertion passed
returncode: 1
stdout : 1 errors
a clean log gives: 0 0 errors
sys.executable is used because: `python` may not exist — 32.3 §3The annotation is correct in three ways worth noting. It runs the tool as a real subprocess, so the whole path through if __name__ and sys.exit is exercised. It uses sys.executable rather than "python", which Chapter 32.3 Section 3 showed is the only reliable spelling. And it asserts the exit code, which is the thing a wrapper reads.
Then there is what rc == 1 cannot tell you.
3. A Crash Also Exits 1
import subprocess
import sys
from pathlib import Path
Path("deliberate.py").write_text(
'import sys\nprint("2 errors found")\nsys.exit(1)\n', encoding="utf-8")
Path("crash.py").write_text(
'print("starting")\nraise KeyError("offset")\n', encoding="utf-8")
print(f"{'script':<26} {'rc':>3} {'stdout':<20} stderr lines")
for label, script in (("deliberate sys.exit(1)", "deliberate.py"),
("uncaught KeyError", "crash.py")):
r = subprocess.run([sys.executable, script], stdout=subprocess.PIPE,
stderr=subprocess.PIPE, text=True)
print(f"{label:<26} {r.returncode:>3} {r.stdout.strip()!r:<20} "
f"{len(r.stderr.strip().splitlines())}")script rc stdout stderr lines
deliberate sys.exit(1) 1 '2 errors found' 0
uncaught KeyError 1 'starting' 4Both return 1. Python's interpreter exits 1 when an exception reaches the top level, and 1 is also the conventional code for "I did my job and found problems" — so the two meanings collide on the one value a wrapper is most likely to test.
That makes the annotation's assertion weaker than it looks: assert cp.returncode == 1 passes whether the parser counted an error or died on line 40 with a KeyError. Chapter 30.1 Section 4 established that separating design failures from infrastructure failures is the most useful line in a report; this is the same distinction collapsing at the process boundary.
The discriminator is in the right-hand column:
import subprocess
import sys
from pathlib import Path
Path("deliberate.py").write_text(
'import sys\nprint("2 errors found")\nsys.exit(1)\n', encoding="utf-8")
Path("crash.py").write_text(
'print("starting")\nraise KeyError("offset")\n', encoding="utf-8")
def run_tool(script):
r = subprocess.run([sys.executable, script], stdout=subprocess.PIPE,
stderr=subprocess.PIPE, text=True)
return {"rc": r.returncode,
"stdout": r.stdout,
"stderr": r.stderr,
"crashed": "Traceback (most recent call last)" in r.stderr}
for label, script in (("deliberate", "deliberate.py"), ("crash", "crash.py")):
r = run_tool(script)
print(f"{label:<12} rc={r['rc']} crashed={r['crashed']}")
print()
print("the assertion the annotation needs alongside rc == 1:")
print(' assert "Traceback" not in cp.stderr')
print()
d = run_tool("deliberate.py")
c = run_tool("crash.py")
print("deliberate failure passes it:", "Traceback" not in d["stderr"])
print("the crash fails it :", "Traceback" not in c["stderr"])deliberate rc=1 crashed=False
crash rc=1 crashed=True
the assertion the annotation needs alongside rc == 1:
assert "Traceback" not in cp.stderr
deliberate failure passes it: True
the crash fails it : FalseOne extra assertion separates them. assert "Traceback" not in cp.stderr is crude and effective: a Python script that exits non-zero deliberately does not print a traceback, and one that crashed always does.
4. argparse Supplies the Third Code
import subprocess
import sys
from pathlib import Path
Path("tool.py").write_text(
'import argparse\n'
'import sys\n'
'\n'
'def main(argv=None):\n'
' p = argparse.ArgumentParser(prog="tool.py")\n'
' p.add_argument("log")\n'
' args = p.parse_args(argv)\n'
' text = open(args.log, encoding="utf-8").read()\n'
' errors = sum(1 for l in text.splitlines()\n'
' if l.startswith("UVM_ERROR"))\n'
' print(f"{errors} errors")\n'
' return 1 if errors else 0\n'
'\n'
'if __name__ == "__main__":\n'
' sys.exit(main())\n', encoding="utf-8")
Path("bad.log").write_text("UVM_ERROR x\n", encoding="utf-8")
Path("good.log").write_text("UVM_INFO ok\n", encoding="utf-8")
CASES = [
("a log with errors", ["bad.log"]),
("a clean log", ["good.log"]),
("no argument at all", []),
("an unknown option", ["--verbose", "good.log"]),
]
print(f"{'invocation':<24} {'rc':>3} {'stdout':<14} {'stderr':<8} meaning")
for label, args in CASES:
r = subprocess.run([sys.executable, "tool.py"] + args,
stdout=subprocess.PIPE, stderr=subprocess.PIPE,
text=True)
meaning = {0: "ok", 1: "found problems", 2: "used wrongly"}.get(
r.returncode, "?")
print(f"{label:<24} {r.returncode:>3} {r.stdout.strip()!r:<14} "
f"{len(r.stderr.strip().splitlines()):<8} {meaning}")invocation rc stdout stderr meaning
a log with errors 1 '1 errors' 0 found problems
a clean log 0 '0 errors' 0 ok
no argument at all 2 '' 2 used wrongly
an unknown option 2 '' 2 used wronglyThree codes without writing any of them. argparse exits 2 on a usage error and writes to stderr, which gives the contract its third value for free — and the shape matches what every Unix tool does, so a wrapper written against it needs no special knowledge.
Note the two usage rows print nothing on stdout. That is the property Section 6 is about, and it is argparse's doing rather than the author's.
5. Testing In-Process
A subprocess per test is correct and slow. The main(argv) -> int shape makes the same contract testable without one:
import contextlib
import io
import unittest
from pathlib import Path
Path("bad.log").write_text("UVM_ERROR x\n", encoding="utf-8")
Path("good.log").write_text("UVM_INFO ok\n", encoding="utf-8")
def quiet_stderr():
"""argparse prints usage on stderr; a test does not want to see it."""
return contextlib.redirect_stderr(io.StringIO())
def main(argv):
"""Returns the exit code rather than calling sys.exit."""
import argparse
p = argparse.ArgumentParser(prog="tool.py")
p.add_argument("log")
try:
args = p.parse_args(argv)
except SystemExit as exc:
return int(exc.code)
text = Path(args.log).read_text(encoding="utf-8")
errors = sum(1 for l in text.splitlines() if l.startswith("UVM_ERROR"))
print(f"{errors} errors")
return 1 if errors else 0
class ContractInProcess(unittest.TestCase):
def test_errors_give_one(self):
self.assertEqual(main(["bad.log"]), 1)
def test_clean_gives_zero(self):
self.assertEqual(main(["good.log"]), 0)
def test_usage_error_gives_two(self):
with quiet_stderr():
self.assertEqual(main([]), 2)
def run(case):
suite = unittest.TestLoader().loadTestsFromTestCase(case)
res = unittest.TextTestRunner(stream=io.StringIO(), verbosity=0).run(suite)
return {"run": res.testsRun, "failures": len(res.failures),
"ok": res.wasSuccessful()}
print("in-process suite:", run(ContractInProcess))
print()
print("the exit status is:", "a return value")
print("subprocesses launched:", 0)
print("the one line that keeps it a CLI:",
'if __name__ == "__main__": sys.exit(main(sys.argv[1:]))')0 errors
1 errors
in-process suite: {'run': 3, 'failures': 0, 'ok': True}
the exit status is: a return value
subprocesses launched: 0
the one line that keeps it a CLI: if __name__ == "__main__": sys.exit(main(sys.argv[1:]))Three contract assertions, no subprocesses. main returning an int is Chapter 33.2 Section 5's seam applied to the program's entry point: the decision about what to exit with becomes a value a test can compare, and the single sys.exit(main(...)) line is the only impure part.
The two stray errors lines above it are worth noticing rather than tidying away. main prints to stdout, and an in-process test shares the test runner's stdout — so the tool's output lands in the middle of the test report unless the test redirects it, which is what quiet_stderr does for the usage case and deliberately does not do here. A subprocess test never has this problem, because the child's streams are captured by definition. It is a small cost of testing in-process, and the fix is a redirect_stdout in each test rather than pretending it is not happening.
The trade is real and worth stating rather than hiding:
TRADES = [
("the shebang line", "no", "only a subprocess runs it"),
("which interpreter", "no", "in-process is always this one"),
("sys.argv parsing", "partly", "main(argv) takes a list you built"),
("the exit code mapping", "yes", "it is the return value"),
("stdout and stderr content", "yes", "redirect_stdout / redirect_stderr"),
("$? as a shell sees it", "no", "32.7's mod-256 happens at the boundary"),
]
print(f"{'what the contract includes':<28} {'in-process?':<12} note")
for what, ok, note in TRADES:
print(f"{what:<28} {ok:<12} {note}")
print()
print("clauses testable in-process:", 3)
print("clauses needing a subprocess:", 3)
print("so a CLI needs:", "both, and the subprocess tests can be few")what the contract includes in-process? note
the shebang line no only a subprocess runs it
which interpreter no in-process is always this one
sys.argv parsing partly main(argv) takes a list you built
the exit code mapping yes it is the return value
stdout and stderr content yes redirect_stdout / redirect_stderr
$? as a shell sees it no 32.7's mod-256 happens at the boundary
clauses testable in-process: 3
clauses needing a subprocess: 3
so a CLI needs: both, and the subprocess tests can be fewThree clauses each way, so the answer is both: many fast in-process tests for the code mapping and the output, and a handful of subprocess tests for the things only a real process exercises — including Chapter 32.7's modulo-256 truncation, which cannot be observed from inside.
6. Which Stream Is Part of the Contract
import subprocess
import sys
from pathlib import Path
Path("to_stdout.py").write_text(
'import sys\n'
'print("test,seed,status")\n'
'print("ERROR: filelist not found", flush=True)\n'
'sys.exit(1)\n', encoding="utf-8")
Path("to_stderr.py").write_text(
'import sys\n'
'print("test,seed,status")\n'
'print("ERROR: filelist not found", file=sys.stderr, flush=True)\n'
'sys.exit(1)\n', encoding="utf-8")
for label, script in (("error on stdout", "to_stdout.py"),
("error on stderr", "to_stderr.py")):
r = subprocess.run([sys.executable, script], stdout=subprocess.PIPE,
stderr=subprocess.PIPE, text=True)
print(f"--- {label}")
print(" rc :", r.returncode)
print(" stdout lines :", len(r.stdout.strip().splitlines()))
print(" stderr lines :", len(r.stderr.strip().splitlines()))
print(" stdout as CSV:",
[l for l in r.stdout.strip().splitlines()])--- error on stdout
rc : 1
stdout lines : 2
stderr lines : 0
stdout as CSV: ['test,seed,status', 'ERROR: filelist not found']
--- error on stderr
rc : 1
stdout lines : 1
stderr lines : 1
stdout as CSV: ['test,seed,status']The first script's stdout is a CSV with a prose line in it. A consumer doing tool.py > results.csv gets a file whose second row is an error message — and since the exit code is 1 in both cases, a wrapper that checks only $? would at least notice, while a pipeline that ignores the status silently writes a corrupt file.
So the contract has a clause about streams, and the test for it asserts an absence:
import subprocess
import sys
from pathlib import Path
Path("tool.py").write_text(
'import argparse\n'
'import sys\n'
'from pathlib import Path\n'
'\n'
'def main(argv=None):\n'
' p = argparse.ArgumentParser(prog="tool.py")\n'
' p.add_argument("log")\n'
' args = p.parse_args(argv)\n'
' path = Path(args.log)\n'
' if not path.is_file():\n'
' print(f"ERROR: no such log: {path}", file=sys.stderr)\n'
' return 3\n'
' text = path.read_text(encoding="utf-8")\n'
' errors = sum(1 for l in text.splitlines()\n'
' if l.startswith("UVM_ERROR"))\n'
' print("errors")\n'
' print(errors)\n'
' return 1 if errors else 0\n'
'\n'
'if __name__ == "__main__":\n'
' sys.exit(main())\n', encoding="utf-8")
Path("bad.log").write_text("UVM_ERROR x\n", encoding="utf-8")
CASES = [("a log with errors", ["bad.log"], 1),
("a missing log", ["nosuch.log"], 3),
("no argument", [], 2)]
print(f"{'case':<22} {'rc':>3} {'stdout lines':>13} {'stderr lines':>13} "
f"stdout clean")
for label, args, expected_rc in CASES:
r = subprocess.run([sys.executable, "tool.py"] + args,
stdout=subprocess.PIPE, stderr=subprocess.PIPE,
text=True)
out_lines = r.stdout.strip().splitlines()
data_only = all(not l.startswith("ERROR") for l in out_lines)
print(f"{label:<22} {r.returncode:>3} {len(out_lines):>13} "
f"{len(r.stderr.strip().splitlines()):>13} {data_only}")
assert r.returncode == expected_rc
print()
print("the clause:", "on any failure path, stdout carries data or nothing")
print("the assertion:", 'assert not [l for l in stdout if l.startswith("ERROR")]')case rc stdout lines stderr lines stdout clean
a log with errors 1 2 0 True
a missing log 3 0 1 True
no argument 2 0 2 True
the clause: on any failure path, stdout carries data or nothing
the assertion: assert not [l for l in stdout if l.startswith("ERROR")]Every failure path writes zero lines to stdout. The missing-log case returns 3 and says why on stderr; the usage case returns 2 and says why on stderr; only the successful-parse case writes to stdout, and what it writes is data.
That is the clause a pipeline depends on, and it is the one that is never written down.
7. The Contract, Written Down
CONTRACT = [
(0, "the log was read and had no errors", "stdout: the data", "stderr: empty"),
(1, "the log was read and had errors", "stdout: the data", "stderr: empty"),
(2, "the command line was wrong", "stdout: empty", "stderr: usage"),
(3, "an input was missing or unreadable", "stdout: empty", "stderr: why"),
]
print("check_log.py — command-line contract")
print()
print(f"{'exit':>5} {'meaning':<36} {'stdout':<20} stderr")
for code, meaning, out, err in CONTRACT:
print(f"{code:>5} {meaning:<36} {out:<20} {err}")
print()
print("not in the contract:", ["the wording of any message",
"the order of stderr lines",
"whether a count is printed before the rows"])
print()
print("codes used :", [c for c, *_ in CONTRACT])
print("code 1 collides with:", "the interpreter's own exit-on-exception — §3")
print("mitigation :", 'tests assert "Traceback" not in stderr')check_log.py — command-line contract
exit meaning stdout stderr
0 the log was read and had no errors stdout: the data stderr: empty
1 the log was read and had errors stdout: the data stderr: empty
2 the command line was wrong stdout: empty stderr: usage
3 an input was missing or unreadable stdout: empty stderr: why
not in the contract: ['the wording of any message', 'the order of stderr lines', 'whether a count is printed before the rows']
codes used : [0, 1, 2, 3]
code 1 collides with: the interpreter's own exit-on-exception — §3
mitigation : tests assert "Traceback" not in stderrFour codes, two stream rules, and an explicit list of what is not promised — which is the half that makes the rest usable. A contract that does not say the wording is unspecified invites a wrapper to grep for a message, and then improving an error message breaks a caller.
8. The Contract Suite, Assembled
import io
import subprocess
import sys
import unittest
from pathlib import Path
TOOL = "check_log.py"
Path(TOOL).write_text(
'import argparse\n'
'import sys\n'
'from pathlib import Path\n'
'\n'
'EXIT_OK, EXIT_FOUND, EXIT_USAGE, EXIT_INPUT = 0, 1, 2, 3\n'
'\n'
'def main(argv=None):\n'
' p = argparse.ArgumentParser(prog="check_log.py")\n'
' p.add_argument("log")\n'
' args = p.parse_args(argv)\n'
' path = Path(args.log)\n'
' if not path.is_file():\n'
' print(f"ERROR: no such log: {path}", file=sys.stderr)\n'
' return EXIT_INPUT\n'
' try:\n'
' text = path.read_text(encoding="utf-8")\n'
' except UnicodeDecodeError:\n'
' print(f"ERROR: not utf-8: {path}", file=sys.stderr)\n'
' return EXIT_INPUT\n'
' errors = sum(1 for l in text.splitlines()\n'
' if l.startswith("UVM_ERROR"))\n'
' print("errors")\n'
' print(errors)\n'
' return EXIT_FOUND if errors else EXIT_OK\n'
'\n'
'if __name__ == "__main__":\n'
' sys.exit(main())\n', encoding="utf-8")
Path("bad.log").write_text("UVM_INFO started\nUVM_ERROR drv.sv(88): bad\n",
encoding="utf-8")
Path("good.log").write_text("UVM_INFO started\nTEST DONE\n", encoding="utf-8")
Path("binary.log").write_bytes(b"\xff\xfe\x00 junk\n")
def invoke(args):
r = subprocess.run([sys.executable, TOOL] + args, stdout=subprocess.PIPE,
stderr=subprocess.PIPE, text=True)
return {"rc": r.returncode, "out": r.stdout, "err": r.stderr}
class CliContract(unittest.TestCase):
def test_clean_log_exits_zero(self):
self.assertEqual(invoke(["good.log"])["rc"], 0)
def test_log_with_errors_exits_one(self):
self.assertEqual(invoke(["bad.log"])["rc"], 1)
def test_missing_argument_exits_two(self):
self.assertEqual(invoke([])["rc"], 2)
def test_missing_log_exits_three(self):
self.assertEqual(invoke(["nosuch.log"])["rc"], 3)
def test_undecodable_log_exits_three(self):
self.assertEqual(invoke(["binary.log"])["rc"], 3)
# the crash discriminator — §3
def test_no_failure_path_prints_a_traceback(self):
for args in ([], ["nosuch.log"], ["binary.log"], ["bad.log"]):
with self.subTest(args=args):
self.assertNotIn("Traceback", invoke(args)["err"])
# the stream clause — §6
def test_failure_paths_write_nothing_to_stdout(self):
for args in ([], ["nosuch.log"], ["binary.log"]):
with self.subTest(args=args):
self.assertEqual(invoke(args)["out"], "")
def test_success_paths_write_data_to_stdout(self):
for args in (["good.log"], ["bad.log"]):
with self.subTest(args=args):
out = invoke(args)["out"].strip().splitlines()
self.assertEqual(out[0], "errors")
self.assertTrue(out[1].isdigit())
def test_errors_are_explained_on_stderr(self):
for args in (["nosuch.log"], ["binary.log"]):
with self.subTest(args=args):
self.assertIn("ERROR:", invoke(args)["err"])
# every code the contract names is reachable
def test_every_contract_code_is_reachable(self):
seen = {invoke(a)["rc"] for a in
(["good.log"], ["bad.log"], [], ["nosuch.log"])}
self.assertEqual(seen, {0, 1, 2, 3})
def run(case):
suite = unittest.TestLoader().loadTestsFromTestCase(case)
res = unittest.TextTestRunner(stream=io.StringIO(), verbosity=0).run(suite)
return {"run": res.testsRun, "failures": len(res.failures),
"errors": len(res.errors), "ok": res.wasSuccessful()}
print("cli contract suite:", run(CliContract))
print()
print("exit codes asserted :", 4)
print("stream clauses asserted :", 3)
print("crash discriminator :", 1)
print("codes proven reachable :", 4)cli contract suite: {'run': 10, 'failures': 0, 'errors': 0, 'ok': True}
exit codes asserted : 4
stream clauses asserted : 3
crash discriminator : 1
codes proven reachable : 4Ten tests covering four exit codes, three stream clauses and the crash discriminator.
The last test is the one most suites omit and it is the cheapest insurance here: test_every_contract_code_is_reachable asserts that the set of observed codes is exactly {0, 1, 2, 3}. A contract listing a code no input can produce is a promise about behaviour that does not exist — which is Chapter 29.5's unreachable-bin problem arriving in a CLI, and Chapter 33.9's subject in miniature.
9. Never Merge the Two Streams in a Test
Section 6's clause — nothing on stdout on a failure path — is only assertable if the two streams arrive separately. The convenient way to run a subprocess destroys exactly that:
import subprocess
import sys
from pathlib import Path
Path("tool.py").write_text(
'import sys\n'
'print("test,seed,status")\n'
'print("ERROR: filelist not found", file=sys.stderr)\n'
'sys.exit(1)\n', encoding="utf-8")
separate = subprocess.run([sys.executable, "tool.py"], stdout=subprocess.PIPE,
stderr=subprocess.PIPE, text=True)
merged = subprocess.run([sys.executable, "tool.py"], stdout=subprocess.PIPE,
stderr=subprocess.STDOUT, text=True)
print("separate pipes")
print(" stdout:", repr(separate.stdout))
print(" stderr:", repr(separate.stderr))
print("merged into stdout")
print(" stdout:", repr(merged.stdout))
print(" stderr:", repr(merged.stderr))
print()
print("can assert 'no ERROR on stdout', separate:",
"ERROR" not in separate.stdout)
print("can assert it when merged :",
"ERROR" not in merged.stdout)separate pipes
stdout: 'test,seed,status\n'
stderr: 'ERROR: filelist not found\n'
merged into stdout
stdout: 'ERROR: filelist not found\ntest,seed,status\n'
stderr: None
can assert 'no ERROR on stdout', separate: True
can assert it when merged : FalseMerging makes the Section 6 assertion impossible, and it does something else worth noticing: in the merged capture the stderr line comes first, although the program printed the stdout line first.
That ordering is not a bug and not reliable either. print to stdout is
block-buffered when stdout is a pipe, while stderr is unbuffered — so the
error message is flushed immediately and the CSV header waits in a buffer until
the process exits. The interleaving you see in a merged capture reflects
buffering, not program order.
import subprocess
import sys
from pathlib import Path
Path("tool.py").write_text(
'import sys\n'
'print("one")\n'
'print("two", file=sys.stderr)\n'
'print("three")\n', encoding="utf-8")
for label, flags in (("default buffering", []), ("-u (unbuffered)", ["-u"])):
r = subprocess.run([sys.executable] + flags + ["tool.py"],
stdout=subprocess.PIPE, stderr=subprocess.STDOUT,
text=True)
print(f" {label:<20} merged order: {r.stdout.split()}")
print()
print("program order :", ["one", "two", "three"])
print("merged order depends on :", "buffering, not the source")
print("so asserting on the merge:", "tests the buffering")
print("the flag that fixes it :", "-u, or PYTHONUNBUFFERED=1") default buffering merged order: ['two', 'one', 'three']
-u (unbuffered) merged order: ['one', 'two', 'three']
program order : ['one', 'two', 'three']
merged order depends on : buffering, not the source
so asserting on the merge: tests the buffering
the flag that fixes it : -u, or PYTHONUNBUFFERED=1The same program, two different orders. A test asserting on a merged capture is asserting on the interpreter's buffering policy, which changes when the output is a terminal rather than a pipe — so such a test passes by hand and fails in CI, or the reverse.
That is the second reason to keep the streams apart, and it generalises past testing:
RULES = [
("a test", "separate pipes", "the stream is part of the contract — §6"),
("a test", "separate pipes", "merged order reflects buffering, not source"),
("a run log for a human", "merged", "one chronological file is what you want"),
("a data-producing run", "separate", "stdout is the data — §1"),
("a wrapper reading rc", "either", "the code is unaffected"),
]
print(f"{'context':<24} {'streams':<16} why")
for ctx, how, why in RULES:
print(f"{ctx:<24} {how:<16} {why}")
print()
print("contexts where merging is right:", 1)
print("and even there :", "pass -u, or the order is a lie")context streams why
a test separate pipes the stream is part of the contract — §6
a test separate pipes merged order reflects buffering, not source
a run log for a human merged one chronological file is what you want
a data-producing run separate stdout is the data — §1
a wrapper reading rc either the code is unaffected
contexts where merging is right: 1
and even there : pass -u, or the order is a lieExactly one context wants the streams merged, and it is the one Chapter
33.13 keeps in the run directory: a human reading a run log afterwards wants a
single chronological file, not two that have to be interleaved by hand. Even
there the chronology is only trustworthy with -u, which is why
[sys.executable, "-u", script] appears in every subprocess invocation in this
module.
10. Predict, Run, Observe
import subprocess
import sys
from pathlib import Path
Path("d.py").write_text("import sys\nsys.exit(1)\n", encoding="utf-8")
Path("c.py").write_text("raise KeyError('x')\n", encoding="utf-8")
Path("u.py").write_text(
"import argparse\np=argparse.ArgumentParser()\np.add_argument('x')\n"
"p.parse_args()\n", encoding="utf-8")
def rc_and_err(script, args=()):
r = subprocess.run([sys.executable, script] + list(args),
stdout=subprocess.DEVNULL, stderr=subprocess.PIPE,
text=True)
return r.returncode, "Traceback" in r.stderr
# A
print("A:", rc_and_err("d.py"))
# B
print("B:", rc_and_err("c.py"))
# C
print("C:", rc_and_err("u.py"))
# D
print("D:", rc_and_err("u.py", ["value"]))The verified output:
A: (1, False)
B: (1, True)
C: (2, False)
D: (0, False)A — a deliberate failure: code 1, no traceback.
B — a crash: the same code 1, with a traceback. The pair is the whole of Section 3 — the first element cannot tell A from B, and the second one can.
C — argparse's usage error gives 2, and False. parse_args raises SystemExit, which the interpreter treats as a request to exit rather than as an error, so no traceback is printed even though the program stopped early on stderr. That is what makes the Section 3 discriminator usable: it stays False on every deliberate exit, whoever raised it.
D — the success path: 0 and nothing on stderr.
11. Exercises
Exercise 1 — four audiences. For one of your scripts, say who reads what and which expectations are a contract.
Exercise 2 — what the wrapper reads. Check what your own run.sh branches on.
Exercise 3 — run it as a subprocess. Write the annotation's two lines for one of your tools.
Exercise 4 — sys.executable. Confirm your tests do not say "python".
Exercise 5 — crash versus deliberate. Make one of your tools crash and compare its exit code with its failure code.
Exercise 6 — the collision. Explain in two sentences why 1 cannot distinguish them.
Exercise 7 — the stderr assertion. Add assertNotIn("Traceback", ...) to one contract test.
Exercise 8 — reserve a code. Decide whether your flow uses 1 for found-problems or for crashed, and write it down.
Exercise 9 — argparse's 2. Confirm your tool exits 2 on a usage error.
Exercise 10 — three for free. List the codes your tool returns without you writing them.
Exercise 11 — main returning int. Convert one script's entry point and say what becomes testable.
Exercise 12 — the one line. Write the if __name__ line that keeps it a CLI.
Exercise 13 — three clauses each way. Decide which of your contract clauses need a subprocess.
Exercise 14 — the mod-256 clause. Explain why Chapter 32.7's truncation cannot be observed in-process.
Exercise 15 — error on stdout. Find a tool in your flow that prints an error to stdout.
Exercise 16 — the corrupt CSV. Construct the tool.py > results.csv case and look at the file.
Exercise 17 — assert an absence. Add the stdout-is-empty-on-failure assertion.
Exercise 18 — data or nothing. State the stream clause for your own tool.
Exercise 19 — write the contract. Produce the Section 7 table for one of your scripts.
Exercise 20 — what is not promised. List three things about your tool's output that callers must not depend on.
Exercise 21 — a wrapper grepping a message. Find one, and say what breaks when the message improves.
Exercise 22 — every code reachable. Add the test asserting the observed code set equals the contract's.
Exercise 23 — an unreachable code. Find a documented code no input produces, and decide whether to remove it or reach it.
Exercise 24 — ten tests. Build the Section 8 suite for one of your own tools.
Exercise 25 — merge it. Re-run one of your CLI tests with stderr=subprocess.STDOUT and say which assertion you lose.
Exercise 26 — the order surprise. Reproduce the case where the stderr line appears first.
Exercise 27 — why. Explain the buffering difference between stdout and stderr on a pipe.
Exercise 28 — by hand and in CI. Describe how a merged-capture assertion can pass locally and fail in CI.
Exercise 29 — add -u. Confirm the ordering becomes program order.
Exercise 30 — one context. Name the single place merging is right, and say what it is for.
Exercise 31 — the run log. Check whether your flow's run log is captured with -u.
12. Summary
- Two of four audiences have a contract — the wrapper reading the exit code and the consumer reading stdout — and the canonical purpose names the first.
- The annotation is right in three ways: a real subprocess,
sys.executablerather than"python", and an assertion on the code rather than the text. - A deliberate
sys.exit(1)and an uncaught exception both return 1, soassert rc == 1passes on a crash. - The discriminator is stderr.
assert "Traceback" not in cp.stderris crude and separates them completely. - The interpreter's
1is not under your control, so either accept the collision and test stderr, or reserve different codes — and write the choice down. argparsesupplies a third code for free: 2 on a usage error, with the message on stderr and nothing on stdout.main(argv) -> intmakes the exit status a return value, so three contract clauses are testable with no subprocess at all.- Three clauses need a real process — the shebang, the interpreter choice, and the modulo-256 truncation of Chapter 32.7 — so a CLI wants both kinds of test.
- Which stream is part of the contract. A tool printing its error to stdout corrupts
tool.py > results.csv, and the test asserts an absence: nothing on stdout on any failure path. - Write down what is not promised — message wording, line order — or a wrapper will grep for a message and improving it will break a caller.
- Assert that every documented code is reachable. A contract listing a code no input produces is Chapter 29.5's unreachable bin in a CLI.
- Never merge the streams in a test.
stderr=subprocess.STDOUTmakes the Section 6 assertion — nothing on stdout on a failure path — impossible to write. - A merged capture's order reflects buffering, not program order: stdout is block-buffered on a pipe and stderr is not, so the error line can appear first.
- The same program produced two different merged orders, with and without
-u— so asserting on a merge tests the buffering policy. - Exactly one context wants them merged: a run log a human reads afterwards. Capture it with
-u, or the chronology is a lie.
The next chapter asks the question that makes every test in this module credible: delete a check and see whether the suite notices.
Where this fits
Part of the Python curriculum.
