From ae381e74a506b13138e82dc01883f230255f14ff Mon Sep 17 00:00:00 2001 From: Ayke van Laethem Date: Tue, 25 Apr 2023 01:27:39 +0200 Subject: [PATCH] main: print source location when a panic happens in -monitor The previous commit started printing the instruction address for runtime panics. This commit starts using this address to print the source location. Here is an example where this feature is very useful. There is a heap allocation in the Bluetooth package, but we don't know where exactly. Printing the instruction address of the panic is already useful, but what is even more useful is looking up this address in the DWARF debug information that's part of the binary: $ tinygo flash -target=circuitplay-bluefruit -monitor ./examples/heartrate Connected to /dev/ttyACM0. Press Ctrl-C to exit. tick 00:00.810 tick 00:01.587 tick 00:02.387 tick 00:03.244 panic: runtime error at 0x00027c4d: alloc in interrupt [tinygo: panic at /home/ayke/src/tinygo/bluetooth/adapter_sd.go:74:4] To be clear, this path isn't stored on the microcontroller. It's stored as part of the build, and `-monitor` just looks up the path from the panic message. Possible enhancements: - Print such an address for regular panics as well. I'm not sure that's so useful, as it's usually a lot easier to look up panics just by their message. - Use runtimePanicAt (instead of runtimePanic) in other locations, if that proves to be beneficial. - Print the TinyGo-generated output in some other color, to distinguish it from the regular console output. - Print more details when panicking (registers, stack values), and print an actual backtrace. --- main.go | 4 +- monitor.go | 139 +++++++++++++++++++++++++++++++++++++-- monitor_test.go | 66 +++++++++++++++++++ testdata/trivialpanic.go | 7 ++ 4 files changed, 209 insertions(+), 7 deletions(-) create mode 100644 monitor_test.go create mode 100644 testdata/trivialpanic.go diff --git a/main.go b/main.go index 3b3b1a30..a2c5611b 100644 --- a/main.go +++ b/main.go @@ -532,7 +532,7 @@ func Flash(pkgName, port string, options *compileopts.Options) error { return fmt.Errorf("unknown flash method: %s", flashMethod) } if options.Monitor { - return Monitor("", options) + return Monitor(result.Executable, "", options) } return nil } @@ -1720,7 +1720,7 @@ func main() { os.Exit(1) } case "monitor": - err := Monitor(*port, options) + err := Monitor("", *port, options) handleCompilerError(err) case "targets": dir := filepath.Join(goenv.Get("TINYGOROOT"), "targets") diff --git a/monitor.go b/monitor.go index 74f5c219..9bef531f 100644 --- a/monitor.go +++ b/monitor.go @@ -1,9 +1,18 @@ package main import ( + "debug/dwarf" + "debug/elf" + "debug/macho" + "debug/pe" + "errors" "fmt" + "go/token" + "io" "os" "os/signal" + "regexp" + "strconv" "time" "github.com/mattn/go-tty" @@ -13,7 +22,7 @@ import ( ) // Monitor connects to the given port and reads/writes the serial port. -func Monitor(port string, options *compileopts.Options) error { +func Monitor(executable, port string, options *compileopts.Options) error { config, err := builder.NewConfig(options) if err != nil { return err @@ -74,17 +83,31 @@ func Monitor(port string, options *compileopts.Options) error { go func() { buf := make([]byte, 100*1024) + var line []byte for { n, err := p.Read(buf) if err != nil { errCh <- fmt.Errorf("read error: %w", err) return } - - if n == 0 { - continue + start := 0 + for i, c := range buf[:n] { + if c == '\n' { + os.Stdout.Write(buf[start : i+1]) + start = i + 1 + address := extractPanicAddress(line) + if address != 0 { + loc, err := addressToLine(executable, address) + if err == nil && loc.IsValid() { + fmt.Printf("[tinygo: panic at %s]\n", loc.String()) + } + } + line = line[:0] + } else { + line = append(line, c) + } } - fmt.Printf("%v", string(buf[:n])) + os.Stdout.Write(buf[start:n]) } }() @@ -104,3 +127,109 @@ func Monitor(port string, options *compileopts.Options) error { return <-errCh } + +var addressMatch = regexp.MustCompile(`^panic: runtime error at 0x([0-9a-f]+): `) + +// Extract the address from the "panic: runtime error at" message. +func extractPanicAddress(line []byte) uint64 { + matches := addressMatch.FindSubmatch(line) + if matches != nil { + address, err := strconv.ParseUint(string(matches[1]), 16, 64) + if err == nil { + return address + } + } + return 0 +} + +// Convert an address in the binary to a source address location. +func addressToLine(executable string, address uint64) (token.Position, error) { + data, err := readDWARF(executable) + if err != nil { + return token.Position{}, err + } + r := data.Reader() + + for { + e, err := r.Next() + if err != nil { + return token.Position{}, err + } + if e == nil { + break + } + switch e.Tag { + case dwarf.TagCompileUnit: + r.SkipChildren() + lr, err := data.LineReader(e) + if err != nil { + return token.Position{}, err + } + var lineEntry = dwarf.LineEntry{ + EndSequence: true, + } + for { + // Read the next .debug_line entry. + prevLineEntry := lineEntry + err := lr.Next(&lineEntry) + if err != nil { + if err == io.EOF { + break + } + return token.Position{}, err + } + + if prevLineEntry.EndSequence && lineEntry.Address == 0 { + // Tombstone value. This symbol has been removed, for + // example by the --gc-sections linker flag. It is still + // here in the debug information because the linker can't + // just remove this reference. + // Read until the next EndSequence so that this sequence is + // skipped. + // For more details, see (among others): + // https://reviews.llvm.org/D84825 + for { + err := lr.Next(&lineEntry) + if err != nil { + return token.Position{}, err + } + if lineEntry.EndSequence { + break + } + } + } + + if !prevLineEntry.EndSequence { + // The chunk describes the code from prevLineEntry to + // lineEntry. + if prevLineEntry.Address <= address && lineEntry.Address > address { + return token.Position{ + Filename: prevLineEntry.File.Name, + Line: prevLineEntry.Line, + Column: prevLineEntry.Column, + }, nil + } + } + } + } + } + + return token.Position{}, nil // location not found +} + +// Read the DWARF debug information from a given file (in various formats). +func readDWARF(executable string) (*dwarf.Data, error) { + f, err := os.Open(executable) + if err != nil { + return nil, err + } + if file, err := elf.NewFile(f); err == nil { + return file.DWARF() + } else if file, err := macho.NewFile(f); err == nil { + return file.DWARF() + } else if file, err := pe.NewFile(f); err == nil { + return file.DWARF() + } else { + return nil, errors.New("unknown binary format") + } +} diff --git a/monitor_test.go b/monitor_test.go new file mode 100644 index 00000000..18c22374 --- /dev/null +++ b/monitor_test.go @@ -0,0 +1,66 @@ +package main + +import ( + "bytes" + "os/exec" + "path/filepath" + "runtime" + "testing" + "time" + + "github.com/tinygo-org/tinygo/builder" + "github.com/tinygo-org/tinygo/compileopts" +) + +func TestTraceback(t *testing.T) { + if runtime.GOOS != "linux" { + // We care about testing the ELF format, which is only used on Linux + // (not on MacOS or Windows). + t.Skip("Test only works on Linux") + } + + // Build a small binary that only panics. + tmpdir := t.TempDir() + config, err := builder.NewConfig(&compileopts.Options{ + GOOS: runtime.GOOS, + GOARCH: runtime.GOARCH, + Opt: "z", + InterpTimeout: time.Minute, + Debug: true, + }) + if err != nil { + t.Fatal(err) + } + result, err := builder.Build("testdata/trivialpanic.go", ".elf", tmpdir, config) + if err != nil { + t.Fatal(err) + } + + // Run this binary, and capture the output. + buf := &bytes.Buffer{} + cmd := exec.Command(result.Binary) + cmd.Stdout = buf + cmd.Stderr = buf + cmd.Run() // this will return an error because of the panic, ignore it + + // Extract the "runtime error at" address. + line := bytes.TrimSpace(buf.Bytes()) + address := extractPanicAddress(line) + if address == 0 { + t.Fatalf("could not extract panic address from %#v", string(line)) + } + + // Look up the source location for this address. + location, err := addressToLine(result.Executable, address) + if err != nil { + t.Fatal("could not read source location:", err) + } + + // Verify that the source location is as expected. + if filepath.Base(location.Filename) != "trivialpanic.go" { + t.Errorf("expected path to end with trivialpanic.go, got %#v", location.Filename) + } + if location.Line != 6 { + t.Errorf("expected panic location to be line 6, got line %d", location.Line) + } +} diff --git a/testdata/trivialpanic.go b/testdata/trivialpanic.go new file mode 100644 index 00000000..d56970cb --- /dev/null +++ b/testdata/trivialpanic.go @@ -0,0 +1,7 @@ +package main + +var n *int + +func main() { + println(*n) // this will panic +}