Runtime Debugging, Profiling and Observability

When a program in an interpreted or VM-based language misbehaves, you can look at every layer: the tokens, the tree, the bytecode, each executed instruction, the stack and variables, the time spent in each function and the memory each part allocates.

Learning Objectives

Debug interpreted and VM-based programs: breakpoints, stepping, AST and token inspection, parser traces, disassembly, instruction tracing, locals/globals/stack inspection, call stacks and exception traces.

Profile: runtime logs, sampling versus instrumentation and its overhead, allocation profiling, GC logs and pause analysis, heap snapshots, CPU profiles, flame graphs, JIT and deoptimisation logs, start-up and warm-up measurement, benchmark methodology and statistics.

Test runtimes: differential testing, fuzzing lexers and parsers, property-based testing, verifier tests, crash reproduction, semantic regression tests, debugging optimised code and native/managed boundaries.

Plain-Language Explanation

When a program in an interpreted or VM-based language misbehaves, you can look at every layer: the tokens, the tree, the bytecode, each executed instruction, the stack and variables, the time spent in each function and the memory each part allocates. For the runtime itself, the strongest tools are comparing two implementations on the same programs and throwing random inputs at the parser to see if anything breaks.

Precise Technical Explanation

Debuggers map a source line to bytecode offsets (line tables) and stop when execution reaches them — by patching the instruction, checking a breakpoint table in the dispatch loop, or using a monitoring hook (sys.monitoring, JVMTI, the V8 inspector protocol).

Stepping through interpreted execution Step-over/into/out use frame depth and line changes; the course's tracers step per AST node or per instruction.

Print or visualise trees (ast.dump, the AST explorer) to confirm precedence and desugaring.

Token streams and parser traces Dump tokens with positions; log which grammar rule consumes each token when a parse goes wrong.

dis, javap -c, ILSpy, --print-bytecode, MiniLang's disassembler.

VM instruction tracing Log each executed instruction with the stack — MiniLang's vmtrace; production VMs have tracing builds or flags (-XX:+TraceBytecodes in debug HotSpot builds).

Inspecting locals, globals, and operand stacks Debugger variable panes, frame.f_locals, MiniLang's VM visualizer.

Call stacks and stack traces Frames with names and lines; async stack traces stitch logical call chains across await.

Traces with causes and contexts (Module 13); "break on throw" in debuggers.

GC, class-loading, compilation and deoptimisation logs (-Xlog, --trace-*, DOTNET_ variables).

Profilers and sampling Sampling profilers interrupt periodically and record stacks (py-spy, async-profiler, perf, Chrome's profiler): low overhead, statistical.

Deterministic profilers hook every call (cProfile, sys.setprofile): exact counts but distorted timings, especially for small functions.

Records allocation sites and sizes (tracemalloc, JFR allocation events, Chrome allocation sampling).

GC logs and pause analysis Pause durations and frequency, heap before/after (Module 14's real log), compared with latency percentiles.

Object graphs with retained sizes and retainer paths, compared over time to find leaks.

Per-function self and total time; call trees.

Stack samples aggregated into stacked bars whose width is time — the fastest way to read a profile.

JIT compilation logs Which methods compiled, at which tier, how long it took (Module 16's real logs).

Why optimised code was abandoned (--trace-deopt, -XX:+TraceDeoptimization in debug builds).

Startup and cold-start profiling -X importtime, class-loading logs, --cpu-prof from process start, wall-clock from launch to first response.

Warm-up and steady-state benchmarks Separate them explicitly; JIT runtimes need warm-up iterations before measuring steady state.

Benchmark methodology and statistical caution Repeat, report medians and spread (or confidence intervals), control CPU frequency and background load, use the same inputs, and check results are used so work is not eliminated.

Differential testing across implementations Run the same programs on two implementations (two back ends, two versions, two engines) and compare outputs — any difference is a bug in one of them. This course runs every MiniLang program on both back ends.

Fuzz testing lexers and parsers Random or mutated inputs; the property is "never crash, never hang, always produce tokens/AST or diagnostics". Coverage-guided fuzzers (libFuzzer, AFL++, Atheris, Jazzer) find deep bugs.

Generate structured inputs (valid programs) and check properties: both back ends agree; pretty-printing then re-parsing yields the same AST; compiled bytecode always verifies.

Bytecode verifier tests Malformed inputs for every rule (Module 8's examples), plus mutation of valid bytecode.

Runtime crash reproduction Minimise the failing input (delta debugging), record the version and flags, capture core dumps or hs_err logs.

Regression tests for language semantics Every fixed bug becomes a test (program + expected output or error).

Debugging optimized code Variables may be optimised out and frames inlined; reproduce with optimisation disabled, or rely on deoptimisation metadata the runtime keeps for debuggers.

Debugging native/managed boundary errors Crashes in native code called from managed code: enable checked modes (-Xcheck:jni, faulthandler, mixed-mode debugging), validate arguments at the boundary.

Useful example commands (tool availability varies) These commands do not work identically on every platform; each lesson that ran them states the tools and versions used.

# Python / CPython
python -m dis  # Check your Python version's supported module interface; use dis.dis() in a script when needed.

# Java
javac HelloRuntime.java
javap -c HelloRuntime

# .NET
dotnet --info
dotnet build

# WebAssembly
# Use the validator, disassembler, and runtime tools appropriate to the selected WASM toolchain.

Why It Matters in Real Systems

Most runtime bugs and performance problems are found by these tools, not by reading code; differential testing and fuzzing are how language implementations stay correct.

Key Terms

Periodically records stacks Hooks on every event Aggregated stack samples as stacked bars

Comparing implementations on the same inputs Testing with random or mutated inputs

Shrinking a failing input to a minimal one

Syntax or Instruction Format

No dedicated source syntax; this is a runtime or architecture concept. The course's tools: tokenize, parse/printAst, disassembleText, verify, interpret(..., { trace }), runVm(..., { trace }).

Complete Example

A property-based differential tester and a parser fuzzer for MiniLang (Node.js 24, the course's MiniLang module; seeded pseudo-random generator, so the run is reproducible):

Profiling CPython: deterministic profiling with cProfile, allocation sites with tracemalloc, and a careful timeit (CPython 3.13.1; times are one real run):

import { interpret, runSource, compile, verify, parse, tokenize } from "file:///D:/Projects/EngineerHub/src/cs/tracks/runtimes/minilang/minilang.ts";

let seed = 20251;
const rand = (n) => { seed = (seed * 1103515245 + 12345) % 2147483648; return seed % n; };
const pick = (xs) => xs[rand(xs.length)];

function expr(depth) {
  if (depth === 0 || rand(3) === 0) return pick(["a", "b", "c", String(rand(10)), "nil", "true", '"s"']);
  const kind = rand(5);
  if (kind === 0) return `-${expr(depth - 1)}`;
  if (kind === 1) return `(${expr(depth - 1)} ${pick(["and", "or"])} ${expr(depth - 1)})`;
  if (kind === 2) return `f(${expr(depth - 1)})`;
  return `(${expr(depth - 1)} ${pick(["+", "-", "*", "/", "<", "==", "!="])} ${expr(depth - 1)})`;
}
function program() {
  const lines = ["let a = 3;", "let b = 4;", "let c = 0;", "fun f(x) { if (x == nil) return 1; return x; }"];
  for (let i = 0; i < 4; i++) lines.push(pick([`print(${expr(3)});`, `c = ${expr(2)};`, `if (${expr(2)}) print(c); else print(a);`]));
  return lines.join("\n");
}

let agree = 0, errors = 0, outputs = 0;
for (let i = 0; i < 500; i++) {
  const src = program();
  const t = interpret(src), v = runSource(src);
  const tt = 
…
differential test: 500/500 random programs gave identical output and errors on both back ends
  (403 ended in a runtime error, 548 lines printed; every compiled program verified)
fuzzing: 2000 random token soups — 253 parsed cleanly, 1747 produced diagnostics, 0 crashes or hangs
import cProfile, pstats, io, timeit, tracemalloc


def slow_concat(n):
    s = ""
    for i in range(n):
        s += str(i)
    return s


def fast_join(n):
    return "".join(str(i) for i in range(n))


def work():
    for _ in range(20):
        slow_concat(2000)
        fast_join(2000)


profiler = cProfile.Profile()
profiler.runcall(work)
out = io.StringIO()
pstats.Stats(profiler, stream=out).sort_stats("cumulative").print_stats("slow_concat|fast_join")
print("\n".join(line for line in out.getvalue().splitlines() if "slow_concat" in line or "fast_join" in line or "ncalls" in line))

tracemalloc.start()
data = [list(range(100)) for _ in range(1000)]
snapshot = tracemalloc.take_snapshot()
top = snapshot.statistics("lineno")[0]
print("largest allocation site:", f"line {top.traceback[0].lineno},", f"{top.size // 1024} KiB in {top.count} blocks")
tracemalloc.stop()

for name in ("slow_concat", "fast_join"):
    runs = timeit.repeat(f"{name}(2000)", globals=globals(), number=200, repeat=5)
    best = min(runs) / 200 * 1e6
    print(f"{name:<12} best of 5 × 200 runs: {best:7.1f} µs per call (spread {max(runs) / min(runs):.2f}×)")
List reduced from 6 to 2 due to restriction <'slow_concat|fast_join'>
   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
       20    0.000    0.000    0.017    0.001 m23_profile.py:11(fast_join)
       20    0.011    0.001    0.011    0.001 m23_profile.py:4(slow_concat)
largest allocation site: line 28, 844 KiB in 2001 blocks
slow_concat  best of 5 × 200 runs:   386.9 µs per call (spread 1.34×)
fast_join    best of 5 × 200 runs:   233.2 µs per call (spread 1.02×)

Line-by-Line Explanation

Differential test: random but valid programs (closures over a function, short-circuit operators, arithmetic on mixed types) run on both back ends; outputs *and* error messages (with traces) must be identical, and every compiled program must pass the verifier. A seeded generator makes failures reproducible.

Fuzzer: random token soups and random ASCII characters exercise the lexer's and parser's error paths; the property is only that they terminate with tokens, an AST or diagnostics.

cProfile: call counts and cumulative times per function. Notice that it reports fast_join as *slower* than slow_concat, while timeit shows the opposite: the deterministic profiler adds overhead to every call, including every step of fast_join's generator expression, so it distorts small, call-heavy code — exactly the instrumentation-overhead caveat above. tracemalloc: the list comprehension line is the biggest allocation site. timeit.repeat: best-of-N with the spread shown — never a single timing.

Expected Output

The differential and fuzzing counts are deterministic (seeded); profile times vary.

Step-by-Step Runtime Behavior

For each random program: parse → tree-walk → compile → verify → VM → compare. Any mismatch would print the program and stop — the minimal reproducer for a bug report.

Common Misconceptions

"A profiler shows where time is spent, exactly." Sampling is statistical and instrumentation distorts.

"Fuzzing needs a big framework." A seeded random generator and a property already find bugs (this course's harness found a stack-trace difference between the back ends during development).

"If tests pass on one implementation, the language is correct." Differential testing compares implementations against each other.

Common Bugs and Failure Modes

Profiling debug builds, benchmarking with the profiler attached, non-reproducible fuzz failures (no seed), comparing outputs that legitimately differ (addresses, timings) in differential tests.

Corrected or Safer Patterns

Profile release builds under realistic load, separate profiling from benchmarking, seed and log random inputs, normalise nondeterministic output before comparing.

Debugging and Inspection Techniques

All of the above; plus delta debugging to shrink failing programs automatically.

Performance Considerations

Use sampling profilers in production (low overhead), instrumentation only in tests; flame graphs for CPU, allocation profiles for GC pressure.

Security Considerations

Fuzzing is the main defence against parser crashes on hostile input; profiles and heap snapshots can contain secrets — handle them as sensitive data.

Portability and Version Caveats

Profiler APIs and output formats are tool-specific; CPython 3.12 added sys.monitoring; JVM unified logging tags change between versions.

Real-World Use Cases

CSmith-style compiler fuzzing, OSS-Fuzz for language runtimes, JIT differential testing against interpreters, production flame graphs for latency regressions.

Best Practices

Make every tool reproducible (seeds, versions, flags), compare implementations, turn every bug into a regression test.

Exercises

E1 · Beginner. Why is timeit.repeat with the minimum (and spread) better than one timeit call?

Answer: Background noise only makes runs slower; the minimum approximates the undisturbed cost, and the spread shows how noisy the measurement was.

E2 · Intermediate. Name two outputs that must be normalised before differential-testing two Python versions.

Answer: Object addresses in reprs (0x…), hash-based ordering when hash randomisation is on, timings, and version strings in tracebacks.

E3 · Advanced challenge. Extend the differential tester to shrink a failing program.

Answer: Repeatedly try deleting statements and replacing sub-expressions by literals; keep a change if the mismatch persists; stop when no single deletion or replacement keeps it failing (delta debugging).

Quiz

? What does differential testing detect?
+ Behaviour differences between two implementations on the same input. :: Any difference is a bug in at least one.
- Performance differences only. :: Mainly correctness.
- Memory leaks. :: That needs heap tools.
- Syntax errors in the test. :: No.

? Why do sampling profilers have low overhead?
+ They record stacks only periodically instead of hooking every call. :: Statistical results.
- They run on a different computer. :: No.
- They disable the JIT. :: No.
- They only profile the main thread. :: Many sample all threads.

? Which are good benchmarking practices? (select all that apply)
+ Report spread, not just one number :: Measurements are noisy.
+ Warm up JIT runtimes before measuring steady state :: Otherwise you measure compilation.
- Benchmark with a deterministic profiler attached :: It distorts timings.
+ Use the results of the measured work :: Prevents dead-code elimination.

Summary and Key Takeaways

Inspect every layer (tokens, AST, bytecode, instructions, stacks), profile with the right tool (sampling for production, instrumentation for counts, allocation and heap tools for memory), measure carefully, and keep runtimes correct with differential testing, fuzzing and regression tests.

Further Reading

Brendan Gregg, *Systems Performance*, 2nd ed., profiling and flame graphs chapters.

McKeeman, "Differential Testing for Software" (1998); Yang et al., "Finding and Understanding Bugs in C Compilers" (Csmith, PLDI 2011).

Python documentation: "The Python Profilers", tracemalloc, timeit.