mipsevm,cmd: implement processing logs with metadata usage

.gitignore

@@ -8,3 +8,4 @@ venv
 example/bin
 contracts/out
 state.json
+*.json

cmd/json.go

@@ -2,12 +2,16 @@ package cmd
 
 import (
 	"encoding/json"
+	"errors"
 	"fmt"
 	"io"
 	"os"
 )
 
 func loadJSON[X any](inputPath string) (*X, error) {
+	if inputPath == "" {
+		return nil, errors.New("no path specified")
+	}
 	f, err := os.OpenFile(inputPath, os.O_RDONLY, 0)
 	if err != nil {
 		return nil, fmt.Errorf("failed to open file %q: %w", inputPath, err)

cmd/load_elf.go

@@ -28,6 +28,12 @@ var (
 		Value:    "state.json",
 		Required: false,
 	}
+	LoadELFMetaFlag = &cli.PathFlag{
+		Name:     "meta",
+		Usage:    "Write metadata file, for symbol lookup during program execution. None if empty.",
+		Value:    "meta.json",
+		Required: false,
+	}
 )
 
 func LoadELF(ctx *cli.Context) error {
@@ -36,6 +42,9 @@ func LoadELF(ctx *cli.Context) error {
 	if err != nil {
 		return fmt.Errorf("failed to open ELF file %q: %w", elfPath, err)
 	}
+	if elfProgram.Machine != elf.EM_MIPS {
+		return fmt.Errorf("ELF is not big-endian MIPS R3000, but got %q", elfProgram.Machine.String())
+	}
 	state, err := mipsevm.LoadELF(elfProgram)
 	if err != nil {
 		return fmt.Errorf("failed to load ELF data into VM state: %w", err)
@@ -53,6 +62,13 @@ func LoadELF(ctx *cli.Context) error {
 			return fmt.Errorf("failed to apply patch %s: %w", typ, err)
 		}
 	}
+	meta, err := mipsevm.MakeMetadata(elfProgram)
+	if err != nil {
+		return fmt.Errorf("failed to compute program metadata: %w", err)
+	}
+	if err := writeJSON[*mipsevm.Metadata](ctx.Path(LoadELFMetaFlag.Name), meta, false); err != nil {
+		return fmt.Errorf("failed to output metadata: %w", err)
+	}
 	return writeJSON[*mipsevm.State](ctx.Path(LoadELFOutFlag.Name), state, true)
 }
 
@@ -65,5 +81,6 @@ var LoadELFCommand = &cli.Command{
 		LoadELFPathFlag,
 		LoadELFPatchFlag,
 		LoadELFOutFlag,
+		LoadELFMetaFlag,
 	},
 }

cmd/run.go

@@ -62,6 +62,12 @@ var (
 		Value:    new(StepMatcherFlag),
 		Required: false,
 	}
+	RunMetaFlag = &cli.PathFlag{
+		Name:     "meta",
+		Usage:    "path to metadata file for symbol lookup for enhanced debugging info durign execution.",
+		Value:    "meta.json",
+		Required: false,
+	}
 )
 
 type Proof struct {
@@ -207,6 +213,18 @@ func Run(ctx *cli.Context) error {
 	proofAt := ctx.Generic(RunProofAtFlag.Name).(*StepMatcherFlag).Matcher()
 	snapshotAt := ctx.Generic(RunSnapshotAtFlag.Name).(*StepMatcherFlag).Matcher()
 
+	var meta *mipsevm.Metadata
+	if metaPath := ctx.Path(RunMetaFlag.Name); metaPath == "" {
+		l.Info("no metadata file specified, defaulting to empty metadata")
+		meta = &mipsevm.Metadata{Symbols: nil} // provide empty metadata by default
+	} else {
+		if m, err := loadJSON[mipsevm.Metadata](metaPath); err != nil {
+			return fmt.Errorf("failed to load metadata: %w", err)
+		} else {
+			meta = m
+		}
+	}
+
 	//us, err := mipsevm.NewUnicornState(mu, state, po, outLog, errLog)
 	//if err != nil {
 	//	return fmt.Errorf("failed to setup instrumented VM state: %w", err)
@@ -229,6 +247,17 @@ func Run(ctx *cli.Context) error {
 		//	l.Info("", "insn", state.Memory.GetMemory(state.PC), "pc", state.PC, "symbol", sy.Name)
 		//	// print name
 		//}
+		if meta.LookupSymbol(state.PC) == "runtime.notesleep" {
+			return fmt.Errorf("got stuck in Go sleep at step %d", step)
+		}
+		if step%100 == 0 || step > 14_478_400 {
+			l.Info("processing",
+				"step", step,
+				"pc", mipsevm.HexU32(state.PC),
+				"insn", mipsevm.HexU32(state.Memory.GetMemory(state.PC)),
+				"name", meta.LookupSymbol(state.PC),
+			)
+		}
 
 		if stopAt(state) {
 			break
@@ -289,5 +318,6 @@ var RunCommand = &cli.Command{
 		RunSnapshotAtFlag,
 		RunSnapshotFmtFlag,
 		RunStopAtFlag,
+		RunMetaFlag,
 	},
 }

mipsevm/metadata.go

+package mipsevm
+
+import (
+	"debug/elf"
+	"fmt"
+	"sort"
+)
+
+type Symbol struct {
+	Name  string `json:"name"`
+	Start uint32 `json:"start"`
+	Size  uint32 `json:"size"`
+}
+
+type Metadata struct {
+	Symbols []Symbol `json:"symbols"`
+}
+
+func MakeMetadata(elfProgram *elf.File) (*Metadata, error) {
+	syms, err := elfProgram.Symbols()
+	if err != nil {
+		return nil, fmt.Errorf("failed to load symbols table: %w", err)
+	}
+	// Make sure the table is sorted, Go outputs mostly sorted data, except some internal functions
+	sort.Slice(syms, func(i, j int) bool {
+		return syms[i].Value < syms[j].Value
+	})
+	out := &Metadata{Symbols: make([]Symbol, len(syms))}
+	for i, s := range syms {
+		out.Symbols[i] = Symbol{Name: s.Name, Start: uint32(s.Value), Size: uint32(s.Size)}
+	}
+	return out, nil
+}
+
+func (m *Metadata) LookupSymbol(addr uint32) string {
+	if len(m.Symbols) == 0 {
+		return "!unknown"
+	}
+	// find first symbol with higher start. Or n if no such symbol exists
+	i := sort.Search(len(m.Symbols), func(i int) bool {
+		return m.Symbols[i].Start > addr
+	})
+	if i == 0 {
+		return "!start"
+	}
+	out := &m.Symbols[i-1]
+	if out.Start+out.Size < addr { // addr may be pointing to a gap between symbols
+		return "!gap"
+	}
+	return out.Name
+}
+
+// HexU32 to lazy-format integer attributes for logging
+type HexU32 uint32
+
+func (v HexU32) String() string {
+	return fmt.Sprintf("%08x", uint32(v))
+}
+
+func (v HexU32) MarshalText() ([]byte, error) {
+	return []byte(v.String()), nil
+}