cannon: Add traceback debugger (#10669)

* cannon: Add traceback debugger

* review comments

* fix go lint

cannon/cmd/run.go

@@ -99,6 +99,10 @@ var (
 		Name:  "pprof.cpu",
 		Usage: "enable pprof cpu profiling",
 	}
+	RunDebugFlag = &cli.BoolFlag{
+		Name:  "debug",
+		Usage: "enable debug mode, which includes stack traces and other debug info in the output. Requires --meta.",
+	}
 
 	OutFilePerm = os.FileMode(0o755)
 )
@@ -336,6 +340,15 @@ func Run(ctx *cli.Context) error {
 	}
 
 	us := mipsevm.NewInstrumentedState(state, po, outLog, errLog)
+	debugProgram := ctx.Bool(RunDebugFlag.Name)
+	if debugProgram {
+		if metaPath := ctx.Path(RunMetaFlag.Name); metaPath == "" {
+			return fmt.Errorf("cannot enable debug mode without a metadata file")
+		}
+		if err := us.InitDebug(meta); err != nil {
+			return fmt.Errorf("failed to initialize debug mode: %w", err)
+		}
+	}
 	proofFmt := ctx.String(RunProofFmtFlag.Name)
 	snapshotFmt := ctx.String(RunSnapshotFmtFlag.Name)
 
@@ -442,6 +455,9 @@ func Run(ctx *cli.Context) error {
 		}
 	}
 	l.Info("Execution stopped", "exited", state.Exited, "code", state.ExitCode)
+	if debugProgram {
+		us.Traceback()
+	}
 
 	if err := jsonutil.WriteJSON(ctx.Path(RunOutputFlag.Name), state, OutFilePerm); err != nil {
 		return fmt.Errorf("failed to write state output: %w", err)
@@ -468,5 +484,6 @@ var RunCommand = &cli.Command{
 		RunMetaFlag,
 		RunInfoAtFlag,
 		RunPProfCPU,
+		RunDebugFlag,
 	},
 }

cannon/mipsevm/instrumented.go

@@ -1,6 +1,7 @@
 package mipsevm
 
 import (
+	"errors"
 	"io"
 )
 
@@ -9,6 +10,12 @@ type PreimageOracle interface {
 	GetPreimage(k [32]byte) []byte
 }
 
+type Debug struct {
+	stack  []uint32
+	caller []uint32
+	meta   *Metadata
+}
+
 type InstrumentedState struct {
 	state *State
 
@@ -27,6 +34,9 @@ type InstrumentedState struct {
 	lastPreimageKey [32]byte
 	// offset we last read from, or max uint32 if nothing is read this step
 	lastPreimageOffset uint32
+
+	debug        Debug
+	debugEnabled bool
 }
 
 const (
@@ -53,6 +63,15 @@ func NewInstrumentedState(state *State, po PreimageOracle, stdOut, stdErr io.Wri
 	}
 }
 
+func (m *InstrumentedState) InitDebug(meta *Metadata) error {
+	if meta == nil {
+		return errors.New("metadata is nil")
+	}
+	m.debugEnabled = true
+	m.debug.meta = meta
+	return nil
+}
+
 func (m *InstrumentedState) Step(proof bool) (wit *StepWitness, err error) {
 	m.memProofEnabled = proof
 	m.lastMemAccess = ^uint32(0)

cannon/mipsevm/mips.go

@@ -179,6 +179,49 @@ func (m *InstrumentedState) handleSyscall() error {
 	return nil
 }
 
+func (m *InstrumentedState) pushStack(target uint32) {
+	if !m.debugEnabled {
+		return
+	}
+	m.debug.stack = append(m.debug.stack, target)
+	m.debug.caller = append(m.debug.caller, m.state.PC)
+}
+
+func (m *InstrumentedState) popStack() {
+	if !m.debugEnabled {
+		return
+	}
+	if len(m.debug.stack) != 0 {
+		fn := m.debug.meta.LookupSymbol(m.state.PC)
+		topFn := m.debug.meta.LookupSymbol(m.debug.stack[len(m.debug.stack)-1])
+		if fn != topFn {
+			// most likely the function was inlined. Snap back to the last return.
+			i := len(m.debug.stack) - 1
+			for ; i >= 0; i-- {
+				if m.debug.meta.LookupSymbol(m.debug.stack[i]) == fn {
+					m.debug.stack = m.debug.stack[:i]
+					m.debug.caller = m.debug.caller[:i]
+					break
+				}
+			}
+		} else {
+			m.debug.stack = m.debug.stack[:len(m.debug.stack)-1]
+			m.debug.caller = m.debug.caller[:len(m.debug.caller)-1]
+		}
+	} else {
+		fmt.Printf("ERROR: stack underflow at pc=%x. step=%d\n", m.state.PC, m.state.Step)
+	}
+}
+
+func (m *InstrumentedState) Traceback() {
+	fmt.Printf("traceback at pc=%x. step=%d\n", m.state.PC, m.state.Step)
+	for i := len(m.debug.stack) - 1; i >= 0; i-- {
+		s := m.debug.stack[i]
+		idx := len(m.debug.stack) - i - 1
+		fmt.Printf("\t%d %x in %s caller=%08x\n", idx, s, m.debug.meta.LookupSymbol(s), m.debug.caller[i])
+	}
+}
+
 func (m *InstrumentedState) handleBranch(opcode uint32, insn uint32, rtReg uint32, rs uint32) error {
 	if m.state.NextPC != m.state.PC+4 {
 		panic("branch in delay slot")
@@ -291,6 +334,7 @@ func (m *InstrumentedState) mipsStep() error {
 		}
 		// Take top 4 bits of the next PC (its 256 MB region), and concatenate with the 26-bit offset
 		target := (m.state.NextPC & 0xF0000000) | ((insn & 0x03FFFFFF) << 2)
+		m.pushStack(target)
 		return m.handleJump(linkReg, target)
 	}
 
@@ -356,6 +400,7 @@ func (m *InstrumentedState) mipsStep() error {
 			if fun == 9 {
 				linkReg = rdReg
 			}
+			m.popStack()
 			return m.handleJump(linkReg, rs)
 		}