Trace optimizations (#695)

* proc: Added trace benchmark

Results:

BenchmarkTrace-4   	    5000	  36195899 ns/op

* proc/linux: faster single step implementation.

BenchmarkTrace-4   	    5000	   2093271 ns/op

* proc: Cache function debug_info entries to speed up variable lookup.

BenchmarkTrace-4   	    5000	   1864846 ns/op

* proc/variables: Optimize FunctionArguments by prefetching frame

BenchmarkTrace-4   	    5000	   1815795 ns/op

* proc/variables: optimized parseG

BenchmarkTrace-4   	   10000	    712767 ns/op
This commit is contained in:
Alessandro Arzilli 2017-02-07 22:08:11 +01:00 committed by Derek Parker
parent 8724b3fce7
commit 098457e59e
9 changed files with 227 additions and 57 deletions

18
_fixtures/traceperf.go Normal file

@ -0,0 +1,18 @@
package main
func PerfCheck(i, a, b, c int) {
x := a - b - c
_ = x
}
func main() {
a := 1
b := 1
c := 1
for i := 0; true; i++ {
a = a * 2
b = -b + i
c = i * b
PerfCheck(i, a, b, c)
}
}

@ -4,8 +4,8 @@ import (
"errors"
"fmt"
"golang.org/x/debug/dwarf"
"github.com/derekparker/delve/dwarf/op"
"golang.org/x/debug/dwarf"
)
type Reader struct {

@ -61,12 +61,18 @@ type Process struct {
ptraceChan chan func()
ptraceDoneChan chan interface{}
types map[string]dwarf.Offset
functions []functionDebugInfo
loadModuleDataOnce sync.Once
moduleData []moduleData
nameOfRuntimeType map[uintptr]nameOfRuntimeTypeEntry
}
type functionDebugInfo struct {
lowpc, highpc uint64
offset dwarf.Offset
}
var NotExecutableErr = errors.New("not an executable file")
// New returns an initialized Process struct. Before returning,
@ -173,7 +179,7 @@ func (dbp *Process) LoadInformation(path string) error {
go dbp.parseDebugFrame(exe, &wg)
go dbp.obtainGoSymbols(exe, &wg)
go dbp.parseDebugLineInfo(exe, &wg)
go dbp.loadTypeMap(&wg)
go dbp.loadDebugInfoMaps(&wg)
wg.Wait()
return nil
@ -536,13 +542,16 @@ func (dbp *Process) StepOut() error {
var deferpc uint64 = 0
if filepath.Ext(topframe.Current.File) == ".go" {
if dbp.SelectedGoroutine != nil && dbp.SelectedGoroutine.DeferPC != 0 {
_, _, deferfn := dbp.goSymTable.PCToLine(dbp.SelectedGoroutine.DeferPC)
deferpc, err = dbp.FirstPCAfterPrologue(deferfn, false)
if err != nil {
return err
if dbp.SelectedGoroutine != nil {
deferPCEntry := dbp.SelectedGoroutine.DeferPC()
if deferPCEntry != 0 {
_, _, deferfn := dbp.goSymTable.PCToLine(deferPCEntry)
deferpc, err = dbp.FirstPCAfterPrologue(deferfn, false)
if err != nil {
return err
}
pcs = append(pcs, deferpc)
}
pcs = append(pcs, deferpc)
}
}

@ -402,6 +402,13 @@ func status(pid int, comm string) rune {
return state
}
// waitFast is like wait but does not handle process-exit correctly
func (dbp *Process) waitFast(pid int) (int, *sys.WaitStatus, error) {
var s sys.WaitStatus
wpid, err := sys.Wait4(pid, &s, sys.WALL, nil)
return wpid, &s, err
}
func (dbp *Process) wait(pid, options int) (int, *sys.WaitStatus, error) {
var s sys.WaitStatus
if (pid != dbp.Pid) || (options != 0) {

@ -2385,3 +2385,20 @@ func TestIssue664(t *testing.T) {
}
})
}
// Benchmarks (*Processs).Continue + (*Scope).FunctionArguments
func BenchmarkTrace(b *testing.B) {
withTestProcess("traceperf", b, func(p *Process, fixture protest.Fixture) {
_, err := setFunctionBreakpoint(p, "main.PerfCheck")
assertNoError(err, b, "setFunctionBreakpoint()")
b.ResetTimer()
for i := 0; i < b.N; i++ {
assertNoError(p.Continue(), b, "Continue()")
s, err := p.CurrentThread.Scope()
assertNoError(err, b, "Scope()")
_, err = s.FunctionArguments(LoadConfig{false, 0, 64, 0, 3})
assertNoError(err, b, "FunctionArguments()")
}
b.StopTimer()
})
}

@ -215,12 +215,15 @@ func (dbp *Process) next(stepInto bool) error {
// Set breakpoint on the most recently deferred function (if any)
var deferpc uint64 = 0
if dbp.SelectedGoroutine != nil && dbp.SelectedGoroutine.DeferPC != 0 {
_, _, deferfn := dbp.goSymTable.PCToLine(dbp.SelectedGoroutine.DeferPC)
var err error
deferpc, err = dbp.FirstPCAfterPrologue(deferfn, false)
if err != nil {
return err
if dbp.SelectedGoroutine != nil {
deferPCEntry := dbp.SelectedGoroutine.DeferPC()
if deferPCEntry != 0 {
_, _, deferfn := dbp.goSymTable.PCToLine(deferPCEntry)
var err error
deferpc, err = dbp.FirstPCAfterPrologue(deferfn, false)
if err != nil {
return err
}
}
}
if deferpc != 0 && deferpc != topframe.Current.PC {

@ -49,7 +49,7 @@ func (t *Thread) singleStep() (err error) {
if err != nil {
return err
}
wpid, status, err := t.dbp.wait(t.ID, 0)
wpid, status, err := t.dbp.waitFast(t.ID)
if err != nil {
return err
}

@ -8,6 +8,7 @@ import (
"go/constant"
"go/token"
"reflect"
"sort"
"strconv"
"strings"
"sync"
@ -118,22 +119,61 @@ func (dbp *Process) loadPackageMap() error {
return nil
}
func (dbp *Process) loadTypeMap(wg *sync.WaitGroup) {
type sortFunctionsDebugInfoByLowpc []functionDebugInfo
func (v sortFunctionsDebugInfoByLowpc) Len() int { return len(v) }
func (v sortFunctionsDebugInfoByLowpc) Less(i, j int) bool { return v[i].lowpc < v[j].lowpc }
func (v sortFunctionsDebugInfoByLowpc) Swap(i, j int) {
temp := v[i]
v[i] = v[j]
v[j] = temp
}
func (dbp *Process) loadDebugInfoMaps(wg *sync.WaitGroup) {
defer wg.Done()
dbp.types = make(map[string]dwarf.Offset)
dbp.functions = []functionDebugInfo{}
reader := dbp.DwarfReader()
for entry, err := reader.NextType(); entry != nil; entry, err = reader.NextType() {
for entry, err := reader.Next(); entry != nil; entry, err = reader.Next() {
if err != nil {
break
}
name, ok := entry.Val(dwarf.AttrName).(string)
if !ok {
continue
}
if _, exists := dbp.types[name]; !exists {
dbp.types[name] = entry.Offset
switch entry.Tag {
case dwarf.TagArrayType, dwarf.TagBaseType, dwarf.TagClassType, dwarf.TagStructType, dwarf.TagUnionType, dwarf.TagConstType, dwarf.TagVolatileType, dwarf.TagRestrictType, dwarf.TagEnumerationType, dwarf.TagPointerType, dwarf.TagSubroutineType, dwarf.TagTypedef, dwarf.TagUnspecifiedType:
name, ok := entry.Val(dwarf.AttrName).(string)
if !ok {
continue
}
if _, exists := dbp.types[name]; !exists {
dbp.types[name] = entry.Offset
}
case dwarf.TagSubprogram:
lowpc, ok := entry.Val(dwarf.AttrLowpc).(uint64)
if !ok {
continue
}
highpc, ok := entry.Val(dwarf.AttrHighpc).(uint64)
if !ok {
continue
}
dbp.functions = append(dbp.functions, functionDebugInfo{lowpc, highpc, entry.Offset})
}
}
sort.Sort(sortFunctionsDebugInfoByLowpc(dbp.functions))
}
func (dbp *Process) findFunctionDebugInfo(pc uint64) (dwarf.Offset, error) {
i := sort.Search(len(dbp.functions), func(i int) bool {
fn := dbp.functions[i]
return pc <= fn.lowpc || (fn.lowpc <= pc && pc < fn.highpc)
})
if i != len(dbp.functions) {
fn := dbp.functions[i]
if fn.lowpc <= pc && pc < fn.highpc {
return fn.offset, nil
}
}
return 0, errors.New("unable to find function context")
}
func (dbp *Process) expandPackagesInType(expr ast.Expr) {
@ -187,10 +227,10 @@ func nameOfRuntimeType(_type *Variable) (typename string, kind int64, err error)
var tflag int64
if tflagField := _type.toFieldNamed("tflag"); tflagField != nil && tflagField.Value != nil {
if tflagField := _type.loadFieldNamed("tflag"); tflagField != nil && tflagField.Value != nil {
tflag, _ = constant.Int64Val(tflagField.Value)
}
if kindField := _type.toFieldNamed("kind"); kindField != nil && kindField.Value != nil {
if kindField := _type.loadFieldNamed("kind"); kindField != nil && kindField.Value != nil {
kind, _ = constant.Int64Val(kindField.Value)
}
@ -227,7 +267,7 @@ func nameOfRuntimeType(_type *Variable) (typename string, kind int64, err error)
// to a runtime.slicetype).
func nameOfNamedRuntimeType(_type *Variable, kind, tflag int64) (typename string, err error) {
var strOff int64
if strField := _type.toFieldNamed("str"); strField != nil && strField.Value != nil {
if strField := _type.loadFieldNamed("str"); strField != nil && strField.Value != nil {
strOff, _ = constant.Int64Val(strField.Value)
} else {
return "", errors.New("could not find str field")
@ -261,7 +301,7 @@ func nameOfNamedRuntimeType(_type *Variable, kind, tflag int64) (typename string
}
if ut := uncommon(_type, tflag); ut != nil {
if pkgPathField := ut.toFieldNamed("pkgpath"); pkgPathField != nil && pkgPathField.Value != nil {
if pkgPathField := ut.loadFieldNamed("pkgpath"); pkgPathField != nil && pkgPathField.Value != nil {
pkgPathOff, _ := constant.Int64Val(pkgPathField.Value)
pkgPath, _, _, err := _type.dbp.resolveNameOff(_type.Addr, uintptr(pkgPathOff))
if err != nil {
@ -284,7 +324,7 @@ func nameOfUnnamedRuntimeType(_type *Variable, kind, tflag int64) (string, error
switch reflect.Kind(kind & kindMask) {
case reflect.Array:
var len int64
if lenField := _type.toFieldNamed("len"); lenField != nil && lenField.Value != nil {
if lenField := _type.loadFieldNamed("len"); lenField != nil && lenField.Value != nil {
len, _ = constant.Int64Val(lenField.Value)
}
elemname, err := fieldToType(_type, "elem")
@ -348,10 +388,10 @@ func nameOfFuncRuntimeType(_type *Variable, tflag int64, anonymous bool) (string
}
var inCount, outCount int64
if inCountField := _type.toFieldNamed("inCount"); inCountField != nil && inCountField.Value != nil {
if inCountField := _type.loadFieldNamed("inCount"); inCountField != nil && inCountField.Value != nil {
inCount, _ = constant.Int64Val(inCountField.Value)
}
if outCountField := _type.toFieldNamed("outCount"); outCountField != nil && outCountField.Value != nil {
if outCountField := _type.loadFieldNamed("outCount"); outCountField != nil && outCountField.Value != nil {
outCount, _ = constant.Int64Val(outCountField.Value)
// only the lowest 15 bits of outCount are used, rest are flags
outCount = outCount & (1<<15 - 1)
@ -449,7 +489,7 @@ func nameOfInterfaceRuntimeType(_type *Variable, kind, tflag int64) (string, err
return "", err
}
var tflag int64
if tflagField := typ.toFieldNamed("tflag"); tflagField != nil && tflagField.Value != nil {
if tflagField := typ.loadFieldNamed("tflag"); tflagField != nil && tflagField.Value != nil {
tflag, _ = constant.Int64Val(tflagField.Value)
}
methodtype, err = nameOfFuncRuntimeType(typ, tflag, false)

@ -126,13 +126,11 @@ type G struct {
// Information on goroutine location
CurrentLoc Location
// PC of entry to top-most deferred function.
DeferPC uint64
// Thread that this goroutine is currently allocated to
thread *Thread
dbp *Process
variable *Variable
dbp *Process
}
// EvalScope is the scope for variable evaluation. Contains the thread,
@ -380,24 +378,23 @@ func (gvar *Variable) parseG() (*G, error) {
}
return nil, NoGError{tid: id}
}
gvar.loadValue(loadFullValue)
for {
if _, isptr := gvar.RealType.(*dwarf.PtrType); !isptr {
break
}
gvar = gvar.maybeDereference()
}
gvar.loadValue(LoadConfig{false, 1, 64, 0, -1})
if gvar.Unreadable != nil {
return nil, gvar.Unreadable
}
schedVar := gvar.toFieldNamed("sched")
pc, _ := constant.Int64Val(schedVar.toFieldNamed("pc").Value)
sp, _ := constant.Int64Val(schedVar.toFieldNamed("sp").Value)
id, _ := constant.Int64Val(gvar.toFieldNamed("goid").Value)
gopc, _ := constant.Int64Val(gvar.toFieldNamed("gopc").Value)
waitReason := constant.StringVal(gvar.toFieldNamed("waitreason").Value)
d := gvar.toFieldNamed("_defer")
deferPC := int64(0)
fnvar := d.toFieldNamed("fn")
if fnvar != nil {
fnvalvar := fnvar.toFieldNamed("fn")
deferPC, _ = constant.Int64Val(fnvalvar.Value)
}
status, _ := constant.Int64Val(gvar.toFieldNamed("atomicstatus").Value)
schedVar := gvar.fieldVariable("sched")
pc, _ := constant.Int64Val(schedVar.fieldVariable("pc").Value)
sp, _ := constant.Int64Val(schedVar.fieldVariable("sp").Value)
id, _ := constant.Int64Val(gvar.fieldVariable("goid").Value)
gopc, _ := constant.Int64Val(gvar.fieldVariable("gopc").Value)
waitReason := constant.StringVal(gvar.fieldVariable("waitreason").Value)
status, _ := constant.Int64Val(gvar.fieldVariable("atomicstatus").Value)
f, l, fn := gvar.dbp.goSymTable.PCToLine(uint64(pc))
g := &G{
ID: int(id),
@ -405,15 +402,15 @@ func (gvar *Variable) parseG() (*G, error) {
PC: uint64(pc),
SP: uint64(sp),
WaitReason: waitReason,
DeferPC: uint64(deferPC),
Status: uint64(status),
CurrentLoc: Location{PC: uint64(pc), File: f, Line: l, Fn: fn},
variable: gvar,
dbp: gvar.dbp,
}
return g, nil
}
func (v *Variable) toFieldNamed(name string) *Variable {
func (v *Variable) loadFieldNamed(name string) *Variable {
v, err := v.structMember(name)
if err != nil {
return nil
@ -425,6 +422,40 @@ func (v *Variable) toFieldNamed(name string) *Variable {
return v
}
func (v *Variable) fieldVariable(name string) *Variable {
for i := range v.Children {
if child := &v.Children[i]; child.Name == name {
return child
}
}
return nil
}
// PC of entry to top-most deferred function.
func (g *G) DeferPC() uint64 {
if g.variable.Unreadable != nil {
return 0
}
d := g.variable.fieldVariable("_defer").maybeDereference()
if d.Addr == 0 {
return 0
}
d.loadValue(LoadConfig{false, 1, 64, 0, -1})
if d.Unreadable != nil {
return 0
}
fnvar := d.fieldVariable("fn").maybeDereference()
if fnvar.Addr == 0 {
return 0
}
fnvar.loadValue(LoadConfig{false, 1, 64, 0, -1})
if fnvar.Unreadable != nil {
return 0
}
deferPC, _ := constant.Int64Val(fnvar.fieldVariable("fn").Value)
return uint64(deferPC)
}
// From $GOROOT/src/runtime/traceback.go:597
// isExportedRuntime reports whether name is an exported runtime function.
// It is only for runtime functions, so ASCII A-Z is fine.
@ -513,22 +544,25 @@ func (scope *EvalScope) extractVariableFromEntry(entry *dwarf.Entry, cfg LoadCon
if err != nil {
return nil, err
}
v.loadValue(cfg)
return v, nil
}
func (scope *EvalScope) extractVarInfo(varName string) (*Variable, error) {
reader := scope.DwarfReader()
_, err := reader.SeekToFunction(scope.PC)
off, err := scope.Thread.dbp.findFunctionDebugInfo(scope.PC)
if err != nil {
return nil, err
}
reader.Seek(off)
reader.Next()
for entry, err := reader.NextScopeVariable(); entry != nil; entry, err = reader.NextScopeVariable() {
if err != nil {
return nil, err
}
if entry.Tag == 0 {
break
}
n, ok := entry.Val(dwarf.AttrName).(string)
if !ok {
@ -577,6 +611,7 @@ func (scope *EvalScope) PackageVariables(cfg LoadConfig) ([]*Variable, error) {
if err != nil {
continue
}
val.loadValue(cfg)
vars = append(vars, val)
}
@ -1564,17 +1599,21 @@ func (v *Variable) loadInterface(recurseLevel int, loadData bool, cfg LoadConfig
// Fetches all variables of a specific type in the current function scope
func (scope *EvalScope) variablesByTag(tag dwarf.Tag, cfg LoadConfig) ([]*Variable, error) {
reader := scope.DwarfReader()
_, err := reader.SeekToFunction(scope.PC)
off, err := scope.Thread.dbp.findFunctionDebugInfo(scope.PC)
if err != nil {
return nil, err
}
reader.Seek(off)
reader.Next()
var vars []*Variable
for entry, err := reader.NextScopeVariable(); entry != nil; entry, err = reader.NextScopeVariable() {
if err != nil {
return nil, err
}
if entry.Tag == 0 {
break
}
if entry.Tag == tag {
val, err := scope.extractVariableFromEntry(entry, cfg)
@ -1586,6 +1625,43 @@ func (scope *EvalScope) variablesByTag(tag dwarf.Tag, cfg LoadConfig) ([]*Variab
vars = append(vars, val)
}
}
if len(vars) <= 0 {
return vars, nil
}
// prefetch the whole chunk of memory relative to these variables
minaddr := vars[0].Addr
var maxaddr uintptr
var size int64
for _, v := range vars {
if v.Addr < minaddr {
minaddr = v.Addr
}
size += v.DwarfType.Size()
if end := v.Addr + uintptr(v.DwarfType.Size()); end > maxaddr {
maxaddr = end
}
}
// check that we aren't trying to cache too much memory: we shouldn't
// exceed the real size of the variables by more than the number of
// variables times the size of an architecture pointer (to allow for memory
// alignment).
if int64(maxaddr-minaddr)-size <= int64(len(vars))*int64(scope.PtrSize()) {
mem := cacheMemory(vars[0].mem, minaddr, int(maxaddr-minaddr))
for _, v := range vars {
v.mem = mem
}
}
for _, v := range vars {
v.loadValue(cfg)
}
return vars, nil
}