diff --git a/ChangeLog b/ChangeLog index 9dd0b1529..f69fd5619 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,3 +1,7 @@ +17.12.6-beta.1 +-------------- + * Add goroutine labels to track what they are getting up to if we suspect a hang (#3292) + Version 17.12.5 --------------- * Add a stat for number of BUILD files currently parsing (#3290) diff --git a/VERSION b/VERSION index a93455c71..277c6aae6 100644 --- a/VERSION +++ b/VERSION @@ -1 +1 @@ -17.12.5 +17.12.6-beta.1 diff --git a/src/core/state.go b/src/core/state.go index da61ef2a2..f53861cf4 100644 --- a/src/core/state.go +++ b/src/core/state.go @@ -1,6 +1,7 @@ package core import ( + "bytes" "crypto/sha1" "crypto/sha256" "fmt" @@ -11,6 +12,7 @@ import ( iofs "io/fs" "iter" "path/filepath" + "runtime/pprof" "sort" "strings" "sync" @@ -645,6 +647,7 @@ func (state *BuildState) forwardResults() { } case <-t.C: go state.checkForCycles() + go dumpGoroutineInfo() // Still need to get a result! result = <-state.progress.internalResults } @@ -1534,3 +1537,10 @@ func (s BuildResultStatus) IsFailure() bool { func (s BuildResultStatus) IsActive() bool { return s == PackageParsing || s == TargetBuilding || s == TargetTesting } + +// dumpGoroutineInfo logs out the goroutine stacks when we believe we might have hung. +func dumpGoroutineInfo() { + var buf bytes.Buffer + pprof.Lookup("goroutine").WriteTo(&buf, 1) + log.Debug("Current stacks: %s", buf.String()) +} diff --git a/src/parse/asp/interpreter.go b/src/parse/asp/interpreter.go index 28cf985ef..de2b94eb0 100644 --- a/src/parse/asp/interpreter.go +++ b/src/parse/asp/interpreter.go @@ -1,11 +1,13 @@ package asp import ( + "context" "fmt" "iter" "path/filepath" "reflect" "runtime/debug" + "runtime/pprof" "strings" "sync" @@ -35,6 +37,7 @@ type interpreter struct { // It loads all the builtin rules at this point. func newInterpreter(state *core.BuildState, p *Parser) *interpreter { s := &scope{ + ctx: context.Background(), state: state, locals: map[string]pyObject{}, } @@ -166,6 +169,10 @@ func (i *interpreter) interpretAll(pkg *core.Package, forLabel, dependent *core. label: *forLabel, dependent: *dependent, } + old := s.ctx + s.ctx = pprof.WithLabels(s.ctx, pprof.Labels("parse", forLabel.String())) + pprof.SetGoroutineLabels(s.ctx) + defer pprof.SetGoroutineLabels(old) } if !mode.IsPreload() { @@ -206,6 +213,8 @@ func (i *interpreter) interpretStatements(s *scope, statements []*Statement) (re func (i *interpreter) Subinclude(pkgScope *scope, path string, label core.BuildLabel, preload bool) pyDict { key := filepath.Join(path, pkgScope.state.CurrentSubrepo) globals, err := i.subincludes.GetOrSet(key, func() (pyDict, error) { + pprof.SetGoroutineLabels(pprof.WithLabels(pkgScope.ctx, pprof.Labels("subinclude", path))) + defer pprof.SetGoroutineLabels(pkgScope.ctx) stmts, err := i.parseSubinclude(path) if err != nil { return nil, err @@ -282,6 +291,7 @@ type parseTarget struct { // A scope contains all the information about a lexical scope. type scope struct { + ctx context.Context //nolint:containedctx interpreter *interpreter filename string state *core.BuildState @@ -400,6 +410,7 @@ func (s *scope) NewPackagedScope(pkg *core.Package, mode core.ParseMode, hint in func (s *scope) newScope(pkg *core.Package, mode core.ParseMode, filename string, hint int) *scope { s2 := &scope{ + ctx: s.ctx, filename: filename, interpreter: s.interpreter, state: s.state,