extern/zrepl
1
0
Fork 0
mirror of https://github.com/zrepl/zrepl.git synced 2024-12-31 19:39:28 +01:00
Code Issues Actions Packages Projects Releases Wiki Activity

package trace: track activeChildTasks in a set if debugEnabled=true

Browse Source 
refs #358
This commit is contained in:
Christian Schwarz 2020-08-23 20:11:40 +02:00
parent d5ce578929
commit e500d9ee26
1 changed files with 37 additions and 8 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

45
daemon/logging/trace/trace.go
View File

@ -93,9 +93,11 @@ package trace
import (
"context"
"fmt"
runtimedebug "runtime/debug"
"strings"
"time"
"github.com/kr/pretty"
"github.com/pkg/errors"
"github.com/prometheus/client_golang/prometheus"
"github.com/zrepl/zrepl/util/chainlock"
@ -120,15 +122,19 @@ func RegisterMetrics(r prometheus.Registerer) {
}
type traceNode struct {
id string
annotation string
parentTask *traceNode
// NOTE: members with prefix debug are only valid if the package variable debugEnabled is true.
id string
annotation string
parentTask *traceNode
debugCreationStack string // debug: stack trace of when the traceNode was created
mtx chainlock.L
activeChildTasks int32 // only for task nodes, insignificant for span nodes
parentSpan *traceNode
activeChildSpan *traceNode // nil if task or span doesn't have an active child span
activeChildTasks int32 // only for task nodes, insignificant for span nodes
debugActiveChildTasks map[*traceNode]bool // debug: set of active child tasks
parentSpan *traceNode
activeChildSpan *traceNode // nil if task or span doesn't have an active child span
startedAt time.Time
endedAt time.Time
@ -137,6 +143,14 @@ type traceNode struct {
func (s *traceNode) StartedAt() time.Time { return s.startedAt }
func (s *traceNode) EndedAt() time.Time { return s.endedAt }
// caller must hold mtx
func (s *traceNode) debugString() string {
if !debugEnabled {
return "<debugEnabled=false>"
}
return pretty.Sprint(s)
}
// Returned from WithTask or WithSpan.
// Must be called once the task or span ends.
// See package-level docs for nesting rules.
@ -196,8 +210,16 @@ func WithTask(ctx context.Context, taskName string) (context.Context, DoneFunc)
endedAt: time.Time{},
}
if debugEnabled {
this.debugCreationStack = string(runtimedebug.Stack())
this.debugActiveChildTasks = map[*traceNode]bool{}
}
if parentTask != nil {
this.parentTask.activeChildTasks++
if debugEnabled {
this.parentTask.debugActiveChildTasks[this] = true
}
parentTask.mtx.Unlock()
}
@ -218,7 +240,7 @@ func WithTask(ctx context.Context, taskName string) (context.Context, DoneFunc)
defer this.mtx.Lock().Unlock()
if this.activeChildTasks != 0 {
panic(errors.Wrapf(ErrTaskStillHasActiveChildTasks, "end task: %v active child tasks", this.activeChildTasks))
panic(errors.WithMessagef(ErrTaskStillHasActiveChildTasks, "end task: %v active child tasks\n: %s", this.activeChildTasks, this.debugString()))
}
// support idempotent task ends
@ -229,8 +251,11 @@ func WithTask(ctx context.Context, taskName string) (context.Context, DoneFunc)
if this.parentTask != nil {
this.parentTask.activeChildTasks--
if debugEnabled {
delete(this.parentTask.debugActiveChildTasks, this)
}
if this.parentTask.activeChildTasks < 0 {
panic("impl error: parent task with negative activeChildTasks count")
panic(fmt.Sprintf("impl error: parent task with negative activeChildTasks count: %s", this.debugString()))
}
}
return false
@ -279,6 +304,10 @@ func WithSpan(ctx context.Context, annotation string) (context.Context, DoneFunc
endedAt: time.Time{},
}
if debugEnabled {
this.debugCreationStack = string(runtimedebug.Stack())
}
parentSpan.mtx.HoldWhile(func() {
if parentSpan.activeChildSpan != nil {
panic(ErrAlreadyActiveChildSpan)