yaegi
yaegi copied to clipboard
traefik
proposal: add interp.FilterStack() method to get interpreter stacktrace
Related to the following tickets:
detailed call information on panic https://github.com/traefik/yaegi/issues/531 Capture call stack https://github.com/traefik/yaegi/issues/1040
Interpreter-level stack traces are now available using the new debug interface #1188 #1225 (using, I think, a much saner approach than I am about to propose)
However, it could still be useful to instead convert a runtime stack trace showing the full code path through both interpreted and binary code, without using the debug interface. For example:
// sample.go
package main
import (
"github.com/traefik/yaegi/interp"
"github.com/traefik/yaegi/stdlib"
"reflect"
"fmt"
"os"
)
// Binary method to show that we can move between binary and interpreted frames
func Passthrough(f func()) {
f()
}
type Debug struct {
interp *interp.Interpreter
}
// Function we call from interpreted code to capture stack trace
func (d Debug) PrintStack(msg string) {
filteredStack := d.interp.FilteredStack()
fmt.Fprintf(os.Stderr, "%s\n%s\n", msg, string(filteredStack))
}
func main() {
i := interp.New(interp.Options{})
i.Use(stdlib.Symbols)
customSymbols := map[string]map[string]reflect.Value{}
customSymbols["sample/sample"] = map[string]reflect.Value{
"Passthrough": reflect.ValueOf(Passthrough),
"PrintStack": reflect.ValueOf(Debug{i}.PrintStack),
}
i.Use(customSymbols)
defer func() {
r := recover()
if r != nil {
p := i.GetOldestPanicForErr(r)
if p != nil {
fmt.Fprintln(os.Stderr, p)
} else {
fmt.Fprintln(os.Stderr, r)
}
}
}()
_, err := i.EvalPath("helper.go")
if err != nil {
panic(err)
}
v, err := i.Eval("helper.foo")
if err != nil {
panic(err)
}
foo := v.Interface().(func())
foo()
}
// helper.go
package helper
import "sample"
type someStruct struct {
funcField func()
}
func (s *someStruct) someMethod() {
s.funcField()
}
func foo() {
z := func() {
bar()
}
sample.Passthrough((&someStruct{z}).someMethod)
}
func bar() {
sample.PrintStack("Something went terribly wrong!")
//panic("Something went terribly wrong!")
}
Run with go run sample.go
The normal runtime interpreter stacktrace is not ideal:
goroutine 1 [running]:
runtime/debug.Stack(0xc0002870e0, 0x10, 0x10)
/usr/local/go/src/runtime/debug/stack.go:24 +0x9f
main.Debug.PrintStack(0xc0003a8000, 0xc0004a0041, 0x1e)
/go/src/samplepanic/sample.go:22 +0x34
reflect.Value.call(0xdb12a0, 0xc000286270, 0x13, 0xee44e4, 0x4, 0xc00029e780, 0x1, 0x1, 0xc0004a00c0, 0xc000288bb0, ...)
/usr/local/go/src/reflect/value.go:476 +0x8e7
reflect.Value.Call(0xdb12a0, 0xc000286270, 0x13, 0xc00029e780, 0x1, 0x1, 0xee1880, 0xc0001ac701, 0xc00029e780)
/usr/local/go/src/reflect/value.go:337 +0xb9
github.com/traefik/yaegi/interp.callBin.func1(0xc0004a6fc0, 0xdb12a0, 0xc000286270, 0x13, 0xc00029e780, 0x1, 0x1, 0x710000c00048b5f0, 0x6, 0xc000099520)
/go/src/yaegi/interp/run.go:1484 +0x67
github.com/traefik/yaegi/interp.callBin.func10(0xc0003aa4d0, 0xc000284370)
/go/src/yaegi/interp/run.go:1661 +0x1c3
github.com/traefik/yaegi/interp.runCfg(0xc0004a57a0, 0xc0004a70e0, 0xc0003aa4d0, 0xc0004a67e0, 0xc0004a57a0)
/go/src/yaegi/interp/run.go:201 +0xbe
github.com/traefik/yaegi/interp.call.func9(0xc0003aa420, 0x417c3b)
/go/src/yaegi/interp/run.go:1431 +0xe7f
github.com/traefik/yaegi/interp.runCfg(0xc0004a7b00, 0xc0004a57a0, 0xc0003aa420, 0xc0004a7b00, 0xc0004a7b00)
/go/src/yaegi/interp/run.go:201 +0xbe
github.com/traefik/yaegi/interp.genFunctionWrapper.func2.1(0x1561e30, 0x0, 0x0, 0x1561e30, 0x400, 0x7f57962cff18)
/go/src/yaegi/interp/run.go:1030 +0x55a
reflect.Value.call(0xda9f80, 0xc000282390, 0x193, 0xee44e4, 0x4, 0x1561e30, 0x0, 0x0, 0x8, 0xe3a760, ...)
/usr/local/go/src/reflect/value.go:476 +0x8e7
reflect.Value.Call(0xda9f80, 0xc000282390, 0x193, 0x1561e30, 0x0, 0x0, 0xee1880, 0xc0001ad101, 0x1561e30)
/usr/local/go/src/reflect/value.go:337 +0xb9
github.com/traefik/yaegi/interp.callBin.func1(0xc0004a4240, 0xda9f80, 0xc000282390, 0x193, 0x1561e30, 0x0, 0x0, 0x0, 0xda9f80, 0xc000282390)
/go/src/yaegi/interp/run.go:1484 +0x67
github.com/traefik/yaegi/interp.callBin.func10(0xc0003aa370, 0xc000284280)
/go/src/yaegi/interp/run.go:1661 +0x1c3
github.com/traefik/yaegi/interp.runCfg(0xc0004a6000, 0xc0004a4360, 0xc0003aa370, 0xc0003b3560, 0xc0004a6000)
/go/src/yaegi/interp/run.go:201 +0xbe
github.com/traefik/yaegi/interp.genFunctionWrapper.func2.1(0x1561e30, 0x0, 0x0, 0x1561e30, 0x7f576f510438, 0x3a0)
/go/src/yaegi/interp/run.go:1030 +0x55a
main.Passthrough(0xc00048bce0)
/go/src/samplepanic/sample.go:13 +0x25
reflect.Value.call(0xdb0aa0, 0xf29628, 0x13, 0xee44e4, 0x4, 0xc00029e750, 0x1, 0x1, 0xda9f80, 0xc0001ad8d8, ...)
/usr/local/go/src/reflect/value.go:476 +0x8e7
reflect.Value.Call(0xdb0aa0, 0xf29628, 0x13, 0xc00029e750, 0x1, 0x1, 0xda9f80, 0xc0003b3560, 0x0)
/usr/local/go/src/reflect/value.go:337 +0xb9
github.com/traefik/yaegi/interp.callBin.func1(0xc0004a5b00, 0xdb0aa0, 0xf29628, 0x13, 0xc00029e750, 0x1, 0x1, 0x120, 0x120, 0x7f57962cff18)
/go/src/yaegi/interp/run.go:1484 +0x67
github.com/traefik/yaegi/interp.callBin.func10(0xc0003aa160, 0xc0002842d0)
/go/src/yaegi/interp/run.go:1661 +0x1c3
github.com/traefik/yaegi/interp.runCfg(0xc0004a46c0, 0xc0004a4fc0, 0xc0003aa160, 0xc0004a46c0, 0xc0004a46c0)
/go/src/yaegi/interp/run.go:201 +0xbe
github.com/traefik/yaegi/interp.genFunctionWrapper.func2.1(0x1561e30, 0x0, 0x0, 0x1561e30, 0xc00028aa40, 0xda9f80)
/go/src/yaegi/interp/run.go:1030 +0x55a
main.main()
/go/src/samplepanic/sample.go:60 +0x49c
With the proposed FilterStack method, you can get a stacktrace that looks like this instead:
Something went terribly wrong!
goroutine 1 [running]:
main.Debug.PrintStack(0xc0003d4480, 0xc000600101, 0x1e)
/go/src/sampledebug/sample.go:22 +0x45
helper.bar()
helper.go:21:2
helper.foo.func1()
helper.go:15:3
helper.(*someStruct).someMethod()
helper.go:10:2
main.Passthrough(0xc000616a50)
/go/src/sampledebug/sample.go:13 +0x25
helper.foo()
helper.go:17:2
main.main()
/go/src/sampledebug/sample.go:60 +0x495
You can follow the call path through both binary frames and interpreted frames. Yaegi runtime frames are filtered out and replaced by the interpreted code, making it easier to see what happened. This example now shows calling a debug function deliberately, but you can capture a panic in the same way.
How it works: by placing a handle value in the parameters to several strategic calls in the runtime we can then later parse a runtime stacktrace, look for the magic values in function parameters, and reconstruct the calling nodes.
Aside from being totally insane, this approach has several other disadvantages:
(1) I'm not sure if we can be confident that the runtime stack trace can always be parsed in this way (it might change, and might vary by platform and runtime version)
(2) Interpreter behavior and stack trace parsing code are now tightly coupled, perhaps forcing you go to back and fix the stack trace parsing with every little change to the interpreter.
(3) I don't know what effects this has on performance.
Also, FuncName() turned out to be much more complicated than I expected. I'm convinced there must be a simpler way to do this - perhaps with some help at parse time. I haven't extensively tested correctness either.
I've also modified runCfg so that it captures a filtered stack trace on every panic, which can then be retrieved by calling i.GetOldestPanicForErr(err), which returns an interp.Panic object. In this branch, yaegi now prints the filtered stacktrace rather than the normal runtime stacktrace by default, which you can try out by running it on anything that panics. The runtime stacktrace is still available programmatically as i.GetOldestPanicForErr(err).Stack.
We want to capture the oldest panic, before runCfg unwinds everything and we lose important context. However, at that point, we don't yet know whether it will be recovered or not. We store the panic in the Interpreter struct. This will cause incorrect behavior if the panic is recovered and GetOldestPanicForErr is never called, and then later the exact same error happens again but is not recovered. In that case we will return the wrong (old) stacktrace.
All in all, using the new debug functionality to achieve something like this would probably work out better in the long run, but because this might be useful to someone I figured I'd put it up for discussion.
