1package profiling 2 3import ( 4 "context" 5 "fmt" 6 "sync" 7 "time" 8 9 "github.com/keybase/client/go/logger" 10 "github.com/keybase/clockwork" 11) 12 13type TimeTracer interface { 14 Stage(format string, args ...interface{}) 15 Finish() 16} 17 18type TimeTracerImpl struct { 19 sync.Mutex 20 ctx context.Context 21 log logger.Logger 22 clock clockwork.Clock 23 label string 24 stage string 25 staged bool // whether any stages were used 26 start time.Time // when the tracer started 27 prev time.Time // when the active stage started 28} 29 30func NewTimeTracer(ctx context.Context, log logger.Logger, clock clockwork.Clock, label string) TimeTracer { 31 now := clock.Now() 32 log.CDebugf(ctx, "+ %s", label) 33 return &TimeTracerImpl{ 34 ctx: ctx, 35 log: log, 36 clock: clock, 37 label: label, 38 stage: "init", 39 staged: false, 40 start: now, 41 prev: now, 42 } 43} 44 45func (t *TimeTracerImpl) finishStage() { 46 t.log.CDebugf(t.ctx, "| %s:%s [time=%s]", t.label, t.stage, t.clock.Since(t.prev)) 47} 48 49func (t *TimeTracerImpl) Stage(format string, args ...interface{}) { 50 t.Lock() 51 defer t.Unlock() 52 t.finishStage() 53 t.stage = fmt.Sprintf(format, args...) 54 t.prev = t.clock.Now() 55 t.staged = true 56} 57 58func (t *TimeTracerImpl) Finish() { 59 t.Lock() 60 defer t.Unlock() 61 if t.staged { 62 t.finishStage() 63 } 64 t.log.CDebugf(t.ctx, "- %s [time=%s]", t.label, t.clock.Since(t.start)) 65} 66 67type SilentTimeTracer struct{} 68 69func NewSilentTimeTracer() *SilentTimeTracer { 70 return &SilentTimeTracer{} 71} 72 73func (t *SilentTimeTracer) Stage(format string, args ...interface{}) {} 74 75func (t *SilentTimeTracer) Finish() {} 76