awk With Python

Part III · Module 12 · Chapter 12.5 · awk With Python

1. Why This Matters

awk's strengths are narrow and real: it streams a file once, it splits records into fields without being told how, and a useful extraction is often one line. Its weaknesses are equally clear — no data structures beyond associative arrays, no libraries, no plotting, and arithmetic that Chapter 11.1 showed needs care.

Python is the opposite on every point, and it is slower at the streaming part. So the natural flow is awk at the front and Python behind it, and the design question is what crosses between them.

2. The Division of Labour

The line to draw is about what the result is. If the answer is a handful of numbers per file, awk is the right tool and Python should not reimplement the scan. If the answer needs those numbers joined against a test list, compared with last night's, or rendered, Python is the right tool and awk should not be growing an END block to do it.

3. The Call That Works

Every example in this chapter reads sim.log, the synthetic UVM log published in Chapter 12.1 section 2. Create it from there first, or the Python wrappers below will report awk: can't open file sim.log with a return code of 2 — which is, as it happens, the first thing section 5 is about.

import subprocess

# argv LIST, not a shell string: nothing is re-parsed by a shell.
r = subprocess.run(
    ["awk", "/^UVM_ERROR (\\.|\\/|@)/ { n++ } END { print n+0 }", "sim.log"],
    capture_output=True, text=True)
print("  returncode =", r.returncode, " stdout =", repr(r.stdout), " stderr =", repr(r.stderr))

python3 extract.py

  returncode = 0  stdout = '2\n'  stderr = ''

Two errors, which is the count Chapter 12.1 section 5 established as correct for this log. capture_output=True, text=True gives strings rather than bytes, and the list form means the program text reaches awk exactly as written — no shell, no quoting to get wrong.

4. subprocess Does Not Raise

import subprocess

r = subprocess.run(["awk", "END { print n+0 }", "no-such.log"], capture_output=True, text=True)
print("  returncode =", r.returncode, " stdout =", repr(r.stdout))
print("  int(r.stdout or 0) =", int(r.stdout or 0))

try:
    subprocess.run(["awk", "END { print 1 }", "no-such.log"],
                   capture_output=True, text=True, check=True)
    print("  check=True: no exception")
except subprocess.CalledProcessError as e:
    print("  check=True: CalledProcessError returncode =", e.returncode)

python3 missing.py 2>/dev/null

  returncode = 2  stdout = ''
  int(r.stdout or 0) = 0
  check=True: CalledProcessError returncode = 2

5. shell=True Rewrites the Program

import subprocess

for label, sev in [("benign ", "UVM_ERROR"),
                   ("hostile", 'X" ; echo INJECTED-COMMAND-RAN ; true "')]:
    cmd = """awk '$1 == "%s" { n++ } END { print n+0 }' sim.log""" % sev
    r = subprocess.run(cmd, shell=True, capture_output=True, text=True)
    print("  %s rc=%d stdout=%r" % (label, r.returncode, r.stdout[:60]))

python3 inject.py

  benign  rc=0 stdout='3\n'
  hostile rc=0 stdout='UVM_INFO @ 0: reporter [RNTST] Running test alu_smoke_test..'

The hostile value returns the log's first line instead of a count, and the status is 0. The benign value returns 3 rather than 2 because $1 == "UVM_ERROR" also matches the report summary line — Chapter 9.3's finding, unchanged.

What the shell actually built:

sev = 'X" ; echo INJECTED-COMMAND-RAN ; true "'
cmd = """awk '$1 == "%s" { n++ } END { print n+0 }' sim.log""" % sev
print("  the shell receives:")
print("   ", cmd)
print("  so the awk PROGRAM is:")
print("   ", cmd.split("'")[1])

python3 show.py

  the shell receives:
    awk '$1 == "X" ; echo INJECTED-COMMAND-RAN ; true "" { n++ } END { print n+0 }' sim.log
  so the awk PROGRAM is:
    $1 == "X" ; echo INJECTED-COMMAND-RAN ; true "" { n++ } END { print n+0 }

Note that the injected ; is inside the single quotes, so the shell did not run a second command — it handed awk a different program. The program has three rules where there was one, and the second is what prints everything:

awk 'BEGIN { x = echo INJECTED-COMMAND-RAN; printf "  value=[%s]  true? %s\n", x, (x ? "YES" : "no") }'

  value=[0]  true? YES

awk 'BEGIN { printf "  INJECTED-COMMAND-RAN (three unset vars, two minus signs) = [%s]\n", INJECTED-COMMAND-RAN
             printf "  echo (unset) concatenated with that = [%s]\n", echo (INJECTED-COMMAND-RAN)
             printf "  non-empty string is TRUE in a pattern: %s\n", ((echo (INJECTED-COMMAND-RAN)) ? "YES" : "no") }'

  INJECTED-COMMAND-RAN (three unset vars, two minus signs) = [0]
  echo (unset) concatenated with that = [0]
  non-empty string is TRUE in a pattern: YES

printf 'a\nb\n' | awk 'echo INJECTED-COMMAND-RAN { print "  matched: " $0 }'

  matched: a
  matched: b

The hyphens are subtraction. INJECTED-COMMAND-RAN is three unset variables combined with two minus signs, which is 0 - 0 - 0 — the number 0. Concatenating the unset echo in front of it gives the string "0", and a non-empty string used as a pattern is true for every record.

That is Module 5's rule arriving where it does damage: a string constant "0" is true while a field containing 0 is false. Here the pattern is a computed string, so it is true, so the rule prints every line.

6. -v Passes It as Data

import subprocess

for label, sev in [("benign ", "UVM_ERROR"),
                   ("hostile", 'X" ; echo INJECTED-COMMAND-RAN ; true "')]:
    r = subprocess.run(["awk", "-v", "s=" + sev, '$1 == s { n++ } END { print n+0 }', "sim.log"],
                       capture_output=True, text=True)
    print("  %s rc=%d stdout=%r" % (label, r.returncode, r.stdout))

python3 safe.py

  benign  rc=0 stdout='3\n'
  hostile rc=0 stdout='0\n'

The hostile value now counts zero records, which is the correct answer — no field equals that string. The program text never changed, so there was nothing to exploit.

-v has the one limitation Chapter 8.4 measured: it processes escape sequences, so a value containing a backslash arrives altered. ENVIRON["name"], with the value placed in the child's environment via subprocess.run(..., env=...), is the backslash-safe route.

7. Where to Stop Using awk

The division from section 2, stated as a rule: awk until the result stops being per-file.

The temptation is to keep adding to the END block, and the signal that it has gone too far is Chapter 11.8's: when the output needs a denominator and an aggregation name beside it, the logic has outgrown a one-pass filter.

8. Common Mistakes

shell=True with a spliced value. It rewrites the awk program — section 5.

Assuming shell=False is sufficient. The value is still program text unless it goes through -v.

Not checking returncode. subprocess.run returns normally on a non-zero status — section 4.

int(r.stdout or 0). An unreadable log becomes the integer zero.

Discarding r.stderr. It holds awk's diagnostic and nothing else does.

-v with a backslash in the value. Escapes are processed; use the environment.

Reimplementing the scan in Python. awk's one pass is the part it is good at.

Growing the END block into a report. When it needs denominators, it belongs in Python.

9. Exercises

Exercise 1 — One extraction, checked

import subprocess, sys

r = subprocess.run(["awk", "/^UVM_ERROR (\\.|\\/|@)/ { n++ } END { print n+0 }", "sim.log"],
                   capture_output=True, text=True)
if r.returncode != 0:
    sys.exit("awk failed (%d): %s" % (r.returncode, r.stderr.strip()))
print("  errors =", int(r.stdout))

python3 ex1.py

  errors = 2

Exercise 2 — A severity passed as data

import subprocess

for sev in ["UVM_INFO", "UVM_ERROR", "UVM_FATAL"]:
    r = subprocess.run(["awk", "-v", "s=" + sev,
                        '$1 == s && /(\\.|\\/|@)/ { n++ } END { print n+0 }', "sim.log"],
                       capture_output=True, text=True)
    print("  %-10s %s" % (sev, r.stdout.strip()))

python3 ex2.py

  UVM_INFO   4
  UVM_ERROR  2
  UVM_FATAL  0

The /(\.|\/|@)/ clause excludes the report summary lines, which is why UVM_ERROR reads 2 rather than 3.

Exercise 3 — Debug a dashboard that reports zero for a missing log

import subprocess

for log in ["sim.log", "no-such.log"]:
    r = subprocess.run(["awk", "/^UVM_ERROR (\\.|\\/|@)/ { n++ } END { print n+0 }", log],
                       capture_output=True, text=True)
    naive = int(r.stdout or 0)
    print("  %-12s rc=%d stdout=%r  int(... or 0)=%d" % (log, r.returncode, r.stdout, naive))

python3 ex3.py 2>/dev/null

  sim.log      rc=0 stdout='2\n'  int(... or 0)=2
  no-such.log  rc=2 stdout=''  int(... or 0)=0

The second row is the bug: rc=2 says awk failed and int(... or 0) reports zero errors. The status is right there and unused.

Exercise 4 — Debug a count that returned the log

import subprocess

sev = 'X" ; echo INJECTED-COMMAND-RAN ; true "'
cmd = """awk '$1 == "%s" { n++ } END { print n+0 }' sim.log""" % sev
r = subprocess.run(cmd, shell=True, capture_output=True, text=True)
print("  rc=%d  lines returned=%d  first line=%r" % (r.returncode, len(r.stdout.splitlines()), r.stdout.splitlines()[0][:40]))

python3 ex4.py

  rc=0  lines returned=12  first line='UVM_INFO @ 0: reporter [RNTST] Running t'

Twelve lines where one number was expected, and rc=0. The value closed awk's string literal and the remainder became two extra rules.

Exercise 5 — Engineering application

A reduction that calls awk per log, checks every status, and does the aggregation in Python.

import subprocess, sys, pathlib

PROG = ('/^UVM_ERROR (\\.|\\/|@)/ { e++ } /^UVM_ERROR :/ { s = $3 } '
        'END { printf "%d %s\\n", e + 0, (s == "" ? "-" : s) }')

def reduce_one(path):
    """Return (errors, declared) or raise RuntimeError. The program is a
    constant and the path is a separate argv element -- nothing is spliced."""
    r = subprocess.run(["awk", PROG, str(path)], capture_output=True, text=True)
    if r.returncode != 0:
        raise RuntimeError("awk exit %d on %s: %s" % (r.returncode, path, r.stderr.strip()))
    parts = r.stdout.split()
    if len(parts) != 2:
        raise RuntimeError("unexpected output from awk on %s: %r" % (path, r.stdout))
    return int(parts[0]), parts[1]

logs = ["sim.log", "no-such.log"]
total, rows, broken = 0, [], []
for lg in logs:
    try:
        errs, declared = reduce_one(lg)
    except RuntimeError as exc:
        broken.append((lg, str(exc)))
        continue
    agree = (declared == "-") or (int(declared) == errs)
    rows.append((lg, errs, declared, agree))
    total += errs

for lg, errs, declared, agree in rows:
    print("  %-12s %d error(s), log declares %s -> %s" % (lg, errs, declared, "agree" if agree else "DISAGREE"))
for lg, why in broken:
    print("  %-12s UNREADABLE: %s" % (lg, why.split(":")[0]))
print("# %d log(s) reduced, %d unreadable, %d error(s) total" % (len(rows), len(broken), total))
sys.exit(2 if broken else (1 if total else 0))

python3 reduce.py
echo "status: $?"

  sim.log      2 error(s), log declares 2 -> agree
  no-such.log  UNREADABLE: awk exit 2 on no-such.log
# 1 log(s) reduced, 1 unreadable, 2 error(s) total
status: 2

Four things the boundary now carries correctly: the program is a constant, the path is an argv element, a non-zero status raises rather than yielding an empty string, and the shape of awk's output is validated before int() touches it.

Status 2 because a log was unreadable, which Chapter 12.1 section 8 argued is a different event from a test failing — and the aggregation, the cross-check against the log's own summary and the exit policy are all in Python, where they are a dict and two comparisons.

Exercise 6 — Challenge: show that removing the shell is not enough

Section 5's fix was -v. Show that shell=False alone, with the value still spliced into the program, is just as exploitable.

import subprocess

sev = 'X" ; echo INJECTED-COMMAND-RAN ; true "'
prog = '$1 == "%s" { n++ } END { print n+0 }' % sev
r = subprocess.run(["awk", prog, "sim.log"], capture_output=True, text=True)
print("  shell=False, value spliced: rc=%d  lines=%d" % (r.returncode, len(r.stdout.splitlines())))

r = subprocess.run(["awk", "-v", "s=" + sev, '$1 == s { n++ } END { print n+0 }', "sim.log"],
                   capture_output=True, text=True)
print("  shell=False, value via -v : rc=%d  lines=%d  stdout=%r" % (r.returncode, len(r.stdout.splitlines()), r.stdout))

python3 ex6.py

  shell=False, value spliced: rc=0  lines=12
  shell=False, value via -v : rc=0  lines=1  stdout='0\n'

Twelve lines with no shell involved. The list form prevented the shell from parsing anything, and the value still rewrote the awk program, because the splice happened in Python before subprocess was called.

So the two mitigations are independent and both are needed:

• shell=False stops the shell from re-parsing the command. Necessary for filenames, arguments and anything containing shell metacharacters.
• -v stops the value from becoming awk program text. Necessary for any value that reaches the program.

A great deal of advice stops at the first one. This measurement is the reason to go on to the second — and the general statement is the one Chapter 8.4 reached and this chapter confirms past a process boundary: a value interpolated into any program's source is that program's source, whichever language it is.

10. Summary

• awk for the per-file reduction, Python for everything after it — section 7's table.
• Pass an argv list, with the program as a constant and the path as its own element.
• subprocess.run does not raise on a non-zero status. Check returncode or pass check=True.
• int(r.stdout or 0) turns an unreadable log into zero errors — the or 0 defeats the very case it looks like it handles.
• Read r.stderr. It holds awk's diagnostic and capture_output hides it.
• shell=True with a spliced value rewrites the program — 12 lines returned, rc=0.
• The injection needed no shell. A double quote inside the value closed awk's string literal.
• shell=False is not enough; the spliced value is still program text — Exercise 6.
• -v passes it as data and the hostile value correctly counts zero.
• The injected pattern was true because the hyphens are subtraction: 0 - 0 - 0 concatenated to the string "0", and a non-empty string is a true pattern — Module 5's constant-versus-field rule.

Chapter 12.6 — Nightly Regression Automation closes Module 12 and Part III by assembling all of it into the job that runs at 2 a.m.: walk the run directory, reduce every log, write one metrics row, and leave an exit status that says something true about a run nobody watched.