Chapter 14: Disassembly, debugging, and runtime errors

This chapter:

Grow the disassembler from a Chapter 10 sanity check into a genuinely useful tool: resolved jump targets, and a line-number column that doesn't repeat itself.
Compress the chunk's line table to run-length encoding.
Give the VM a real call-stack trace on runtime error, mapped back to Muspel source lines.
Build a minimal single-step debugger, entirely out of tools already in hand.
Grow musc its seventh and eighth subcommands: debug, and the graceful errors run and bench already had underneath them.

Where we left off: musc run executes every example correctly through a real VM. What it doesn't do yet is help you understand why one doesn't, or watch one execute step by step.

14.1 A disassembler worth reading

Chapter 10's disassembler proved the bytecode format was sound. It's less pleasant to actually use: every jump printed its raw signed offset, leaving the reader to redo patch_jump's own arithmetic by hand (exactly what Chapter 11's worked example asked of you), and every instruction repeated its source line even across a long run that never left that line at all. Both are fixed the same way real disassemblers fix them: resolve what you can at print time, rather than making the reader re-derive it.

case 2:
	hi := c.code[offset + 1]
	lo := c.code[offset + 2]
	raw_offset := i16(u16(hi) << 8 | u16(lo))
	target := offset + width + int(raw_offset)
	fmt.printfln("%04d %s %-14s %6d -> %04d", offset, line, op_name(op), raw_offset, target)

target is exactly the arithmetic Chapter 11 asked you to do by hand, offset + width + raw_offset, done once here so every later listing shows the answer directly.

format_line handles the repeated-line problem: print the actual number only when it's different from the previous instruction's line, a bare | otherwise, the same convention clox's own disassembler uses:

format_line :: proc(c: ^Chunk, offset: int) -> string {
	line := chunk_line_at(c, offset)
	if offset > 0 && chunk_line_at(c, offset - 1) == line {
		return "   |"
	}
	return fmt.tprintf("%4d", line)
}

examples/if_demo.mus (Chapter 11's own worked example) shows both upgrades together:

./run.sh compile examples/if_demo.mus

== <script> ==
0000 0003 CONSTANT       0000 '5'
0002    | DEFINE_GLOBAL  0001
0004 0004 GET_GLOBAL     0002
0006    | CONSTANT       0003 '10'
0008    | LESS
0009    | JUMP_IF_FALSE  000011 -> 0023
0012    | POP
0013 0005 GET_GLOBAL     0004
0015    | CONSTANT       0005 '1'
0017    | CALL           0001
0019    | POP
0020 0004 JUMP           000008 -> 0031
0023    | POP
0024 0007 GET_GLOBAL     0006
0026    | CONSTANT       0007 '2'
0028    | CALL           0001
0030    | POP
0031 0000 NIL
0032    | RETURN

Compare this against Chapter 11's own listing for the identical file: same bytes, same offsets, same raw operand values, but JUMP_IF_FALSE 000011 -> 0023 now hands you the target Chapter 11 made you compute from 9 + 2 + 11, and the line column only speaks up when the source line actually changes. Nothing about the bytecode changed; only how much work reading it takes did.

Get_Field/Set_Field/Get_Global/Set_Global/Define_Global all get the same resolved treatment Constant already had: their operand is a constant-pool index too, so the disassembler resolves it back to the name it names, rather than leaving the reader to cross-reference the constant pool by hand:

case .Constant, .Get_Global, .Set_Global, .Define_Global, .Get_Field, .Set_Field:
	value := c.constants[operand]
	fmt.printfln("%04d %s %-14s %4d '%s'", offset, line, op_name(op), operand, const_value_to_string(value))
case .Make_Struct:
	layout := c.constants[operand].(^Struct_Layout)
	fmt.printfln("%04d %s %-14s %4d '%s' fields=%v", offset, line, op_name(op), operand, layout.type_name, layout.field_names)

./run.sh compile examples/structs_enums.mus

0004    | MAKE_STRUCT    0000 'Vec2' fields=["x", "y"]
...
0018    | GET_FIELD      0009 'pos'
0020    | GET_FIELD      0010 'x'

MAKE_STRUCT's line names the struct type and its full field list, not just a bare index, because a Struct_Layout constant (Chapter 10) carries both and there's no reason to make the reader chase the constant pool a second time to see what a struct actually looked like at the point it was built.

14.2 A line table that doesn't cost one entry per byte

Chunk.lines was, until now, one int per byte of compiled code, correct but wasteful: a whole compiled expression, an entire loop body, routinely shares one source line across a dozen bytes. Line_Run compresses this to one entry per change of line:

Line_Run :: struct {
	start_offset: int,
	line:         int,
}

chunk_write :: proc(c: ^Chunk, byte: u8, line: int) {
	if len(c.lines) == 0 || c.lines[len(c.lines) - 1].line != line {
		append(&c.lines, Line_Run{start_offset = len(c.code), line = line})
	}
	append(&c.code, byte)
}

Reading it back is a backward scan for the last run starting at or before a given offset:

chunk_line_at :: proc(c: ^Chunk, offset: int) -> int {
	for i := len(c.lines) - 1; i >= 0; i -= 1 {
		if c.lines[i].start_offset <= offset {
			return c.lines[i].line
		}
	}
	return 0
}

This is the table both the disassembler's format_line and section 14.3's stack trace read from; neither needed to change how they ask for a line, only where the answer comes from.

14.3 A real call-stack trace

Calling a non-function, or dividing by zero, are two ways a correctly-compiled program can still fail at run time, in ways Chapter 7's static resolution pass has no way to catch ahead of time (resolution only arity-checks calls to known, named functions, never what a variable happens to hold at run time). examples/call_error.mus calls a number:

var x = 5
print(x())

./run.sh run examples/call_error.mus

runtime error: '5' is not callable
  at <script> (line 5)

examples/div_zero.mus fails two calls deep, giving the trace something worth tracing:

func divide(a, b) {
    return a / b
}
print(divide(10, 0))

./run.sh run examples/div_zero.mus

runtime error: division by zero
  at divide (line 4)
  at <script> (line 6)

Both errors are raised the same way, one small proc that walks vm.frames innermost first:

runtime_error :: proc(vm: ^VM, format: string, args: ..any) {
	fmt.eprintf("runtime error: ")
	fmt.eprintfln(format, ..args)
	for i := len(vm.frames) - 1; i >= 0; i -= 1 {
		f := vm.frames[i]
		line := chunk_line_at(f.chunk, f.ip - 1)
		fmt.eprintfln("  at %s (line %d)", f.name, line)
	}
	os.exit(1)
}

f.ip - 1, not f.ip, is the detail worth not skipping past. By the time any case in vm_step calls runtime_error, read_u8/read_i16 have already advanced ip past every byte of the instruction that's currently failing (decode-then-execute, same as every other opcode). ip - 1 always lands back inside that instruction's own byte range, regardless of whether it had zero, one, or two operand bytes, and every byte belonging to one instruction is always on the same source line (Chapter 11's compiler emits them that way), so which byte within it ip - 1 happens to land on never matters. Frame.name, added this chapter purely for this and section 14.4, carries "<script>" for the outermost frame and a function's own name for every call beneath it, so the trace reads exactly like any language's own stack trace: innermost call first, working back out to where the whole thing started.

Design decision: divide's stack trace, but not 1 + "two"'s. This chapter fixes exactly two failure modes gracefully: calling a non-callable value, and dividing by zero. A type mismatch in Add/Sub/etc. (adding a number to a string the wrong way round, say) still panics Odin's own type assertion, ungracefully, exactly as it always has. That's a real, deliberate scope cut, not an oversight: comprehensive runtime type-checking on every opcode is Chapter 18's job (instruction budgets and stack-depth limits alongside it), where a failing script tears down that one instance and every other script, and the host, keeps running. This chapter's two cases exist because the debugger (section 14.4) and this stack trace share one mechanism, and dividing by zero was the shortest honest way to prove it works on a real, easily triggered failure, not because the list of possible runtime errors stops at two.

Neither improvement reaches Chapter 8's tree-walker: --walk still returns nil for call_error.mus and +Inf for div_zero.mus, silently, no error at all. That's consistent with the tree-walker's own established scope (section 8.3 already deferred graceful runtime errors to "later"), not a new gap this chapter opens.

14.4 A minimal single-step debugger

Everything a step debugger needs already exists: vm_step (Chapter 13) executes exactly one instruction and reports whether the program's still running; disassemble_instruction (section 14.1) prints any instruction, including one that hasn't run yet. vm_debug_run is just those two, alternating, with a value-stack printout and one line of input in between:

vm_debug_run :: proc(vm: ^VM) {
	running := true
	auto_run := false
	for running {
		if !auto_run {
			frame := vm.frames[len(vm.frames) - 1]
			fmt.printf("[%s] ", frame.name)
			disassemble_instruction(frame.chunk, frame.ip)
			debug_print_stack(vm)

			fmt.print("> ")
			if !bufio.scanner_scan(&scanner) do return
			switch bufio.scanner_text(&scanner) {
			case "q": return
			case "c": auto_run = true
			}
		}
		running = vm_step(vm)
	}
}

Enter alone steps once; c stops asking and runs the rest silently (no debugger prints, just whatever the script itself prints); q gives up. musc debug examples/hello.mus, stepped by hand:

Muspel step debugger: Enter to step, 'c' to run to completion, 'q' to quit.
[<script>] 0000 0002 CONSTANT       0000 'hello, muspel'
  stack:
> [<script>] 0002    | DEFINE_GLOBAL  0001
  stack: [hello, muspel]
> [<script>] 0004 0003 GET_GLOBAL     0002
  stack:
> [<script>] 0006    | GET_GLOBAL     0003
  stack: [<native fn>]
> [<script>] 0008    | CALL           0001
  stack: [<native fn>] [hello, muspel]
> hello, muspel
[<script>] 0010    | POP
  stack: [nil]

Watch the fourth step: GET_GLOBAL pushes <native fn>, the print builtin sitting under that name in vm.globals, exactly as ordinary a Value to this debugger as hello, muspel sitting right below it. Stepping into CALL runs print itself (its own side effect, hello, muspel, appears between two debugger prompts, not as part of either), then leaves its nil return value on the stack for the trailing Stmt_Expr's own Pop to discard, the exact mechanic Chapter 11's compiler committed to.

Run it against examples/fib.mus and step into the first recursive call: the value stack itself becomes a visible call stack, <fn fib> and each pending argument stacking up one frame at a time, then unwinding as each Return fires, the same picture section 13.2 described in prose, now watchable one instruction at a time.

Checkpoint

musc compile shows resolved jump targets and a non-repeating line column for every example; musc run produces a readable, line-accurate stack trace for both call_error.mus and div_zero.mus; musc debug can step through a real program instruction by instruction, showing the value stack growing and shrinking exactly as Chapter 13 described.

Exercises

Step musc debug through examples/if_demo.mus by hand and confirm the value stack at the JUMP_IF_FALSE instruction holds exactly one value, the condition, matching section 10.4's claim that this instruction peeks rather than pops.
Trigger a runtime error three calls deep (write a small chain of functions, each calling the next, with the innermost one dividing by zero) and confirm the stack trace lists all three frames, innermost first, each with the correct line.
Section 14.3's Design decision names exactly two graceful runtime errors. Trigger a type mismatch this chapter does not handle gracefully (1 + true, say) and read the resulting Odin-level panic. Compare it against call_error.mus's clean trace: what information does the panic have that the graceful error doesn't, and vice versa?
Extend vm_debug_run with your own command, a p <name> that prints one global's current value by name without stepping, is a reasonably small addition given vm.globals is already sitting on the VM you have a pointer to.