From b4f9a25503bbfc0a18927a0e2d5777295e29e8cc Mon Sep 17 00:00:00 2001 From: aarzilli Date: Thu, 16 Mar 2023 15:50:56 +0100 Subject: [PATCH] logflags,proc: flag to log stacktrace execution Add a log flag to write logs about what the stacktracer does. --- Documentation/usage/dlv_log.md | 1 + cmd/dlv/cmds/commands.go | 1 + pkg/logflags/logflags.go | 12 ++++++ pkg/proc/stack.go | 74 ++++++++++++++++++++++++++++++++++ 4 files changed, 88 insertions(+) diff --git a/Documentation/usage/dlv_log.md b/Documentation/usage/dlv_log.md index 39f92e158b..7dc6ed2c48 100644 --- a/Documentation/usage/dlv_log.md +++ b/Documentation/usage/dlv_log.md @@ -19,6 +19,7 @@ names selected from this list: dap Log all DAP messages fncall Log function call protocol minidump Log minidump loading + stack Log stacktracer Additionally --log-dest can be used to specify where the logs should be written. diff --git a/cmd/dlv/cmds/commands.go b/cmd/dlv/cmds/commands.go index 38221c9707..4791755107 100644 --- a/cmd/dlv/cmds/commands.go +++ b/cmd/dlv/cmds/commands.go @@ -412,6 +412,7 @@ names selected from this list: dap Log all DAP messages fncall Log function call protocol minidump Log minidump loading + stack Log stacktracer Additionally --log-dest can be used to specify where the logs should be written. diff --git a/pkg/logflags/logflags.go b/pkg/logflags/logflags.go index 233e9bb920..acf4cb5a7a 100644 --- a/pkg/logflags/logflags.go +++ b/pkg/logflags/logflags.go @@ -26,6 +26,7 @@ var rpc = false var dap = false var fnCall = false var minidump = false +var stack = false var logOut io.WriteCloser @@ -131,6 +132,15 @@ func MinidumpLogger() Logger { return makeLogger(minidump, Fields{"layer": "core", "kind": "minidump"}) } +// Stack returns true if the stacktracer should be logged. +func Stack() bool { + return stack +} + +func StackLogger() Logger { + return makeLogger(stack, Fields{"layer": "core", "kind": "stack"}) +} + // WriteDAPListeningMessage writes the "DAP server listening" message in dap mode. func WriteDAPListeningMessage(addr net.Addr) { writeListeningMessage("DAP", addr) @@ -215,6 +225,8 @@ func Setup(logFlag bool, logstr, logDest string) error { fnCall = true case "minidump": minidump = true + case "stack": + stack = true default: fmt.Fprintf(os.Stderr, "Warning: unknown log output value %q, run 'dlv help log' for usage.\n", logcmd) } diff --git a/pkg/proc/stack.go b/pkg/proc/stack.go index d4791df812..f519f33772 100644 --- a/pkg/proc/stack.go +++ b/pkg/proc/stack.go @@ -6,10 +6,12 @@ import ( "fmt" "go/constant" "reflect" + "strings" "github.com/go-delve/delve/pkg/dwarf/frame" "github.com/go-delve/delve/pkg/dwarf/op" "github.com/go-delve/delve/pkg/dwarf/reader" + "github.com/go-delve/delve/pkg/logflags" ) // This code is partly adapted from runtime.gentraceback in @@ -208,11 +210,36 @@ func (it *stackIterator) Next() bool { return false } + if logflags.Stack() { + logger := logflags.StackLogger() + w := &strings.Builder{} + fmt.Fprintf(w, "current pc = %#x CFA = %#x FrameBase = %#x ", it.pc, it.regs.CFA, it.regs.FrameBase) + for i := 0; i < it.regs.CurrentSize(); i++ { + reg := it.regs.Reg(uint64(i)) + if reg == nil { + continue + } + name, _, _ := it.bi.Arch.DwarfRegisterToString(i, reg) + fmt.Fprintf(w, " %s = %#x", name, reg.Uint64Val) + } + logger.Debugf("%s", w.String()) + } + callFrameRegs, ret, retaddr := it.advanceRegs() it.frame = it.newStackframe(ret, retaddr) + if logflags.Stack() { + logger := logflags.StackLogger() + fnname := "?" + if it.frame.Call.Fn != nil { + fnname = it.frame.Call.Fn.Name + } + logger.Debugf("new frame %#x %s:%d at %s", it.frame.Call.PC, it.frame.Call.File, it.frame.Call.Line, fnname) + } + if it.opts&StacktraceSimple == 0 { if it.bi.Arch.switchStack(it, &callFrameRegs) { + logflags.StackLogger().Debugf("stack switched") return true } } @@ -398,11 +425,18 @@ func (it *stackIterator) advanceRegs() (callFrameRegs op.DwarfRegisters, ret uin framectx = it.bi.Arch.fixFrameUnwindContext(fde.EstablishFrame(it.pc), it.pc, it.bi) } + logger := logflags.StackLogger() + + logger.Debugf("advanceRegs at %#x", it.pc) + cfareg, err := it.executeFrameRegRule(0, framectx.CFA, 0) if cfareg == nil { it.err = fmt.Errorf("CFA becomes undefined at PC %#x: %v", it.pc, err) return op.DwarfRegisters{}, 0, 0 } + if logflags.Stack() { + logger.Debugf("\tCFA rule %s -> %#x", ruleString(&framectx.CFA, it.bi.Arch.RegnumToString), cfareg.Uint64Val) + } it.regs.CFA = int64(cfareg.Uint64Val) callimage := it.bi.PCToImage(it.pc) @@ -426,7 +460,16 @@ func (it *stackIterator) advanceRegs() (callFrameRegs op.DwarfRegisters, ret uin callFrameRegs.AddReg(callFrameRegs.SPRegNum, cfareg) for i, regRule := range framectx.Regs { + if logflags.Stack() { + logger.Debugf("\t%s rule %s ", it.bi.Arch.RegnumToString(i), ruleString(®Rule, it.bi.Arch.RegnumToString)) + + } reg, err := it.executeFrameRegRule(i, regRule, it.regs.CFA) + if reg != nil { + logger.Debugf("\t\t-> %#x", reg.Uint64Val) + } else { + logger.Debugf("\t\t-> nothing (%v)", err) + } callFrameRegs.AddReg(i, reg) if i == framectx.RetAddrReg { if reg == nil { @@ -701,3 +744,34 @@ func (d *Defer) DeferredFunc(p *Target) (file string, line int, fn *Function) { file, line = bi.EntryLineForFunc(fn) return file, line, fn } + +func ruleString(rule *frame.DWRule, regnumToString func(uint64) string) string { + switch rule.Rule { + case frame.RuleUndefined: + return "undefined" + case frame.RuleSameVal: + return "sameval" + case frame.RuleOffset: + return fmt.Sprintf("[cfa+%d]", rule.Offset) + case frame.RuleValOffset: + return fmt.Sprintf("cfa+%d", rule.Offset) + case frame.RuleRegister: + return fmt.Sprintf("R(%d)", rule.Reg) + case frame.RuleExpression: + w := &strings.Builder{} + op.PrettyPrint(w, rule.Expression, regnumToString) + return fmt.Sprintf("[expr(%s)]", w.String()) + case frame.RuleValExpression: + w := &strings.Builder{} + op.PrettyPrint(w, rule.Expression, regnumToString) + return fmt.Sprintf("expr(%s)", w.String()) + case frame.RuleArchitectural: + return "architectural" + case frame.RuleCFA: + return fmt.Sprintf("R(%d)+%d", rule.Reg, rule.Offset) + case frame.RuleFramePointer: + return fmt.Sprintf("[R(%d)] framepointer", rule.Reg) + default: + return fmt.Sprintf("unknown_rule(%d)", rule.Rule) + } +}