1package telemetry23import (4 "context"5 "encoding/hex"6 "log/slog"7 "time"8)910// Spans nest. Every span has a trace id, a span id and, unless it is a11// root, its parent's span id; a child shares its parent's trace id. No12// context.Context goes through the engine for it: whoever owns a thread13// of work (one UI program, one import) keeps a Trace, the spans it has14// open, and what starts through the Trace nests under the innermost.15// Work handed to another goroutine (a background tea.Cmd) takes a Parent16// instead, an explicit handle on the span to nest under. There is no17// goroutine-global "current span": 012 serve runs many programs in one18// process, and their commands run on other goroutines.1920// Parent identifies a span that others can nest under, from any21// goroutine. The zero Parent is none: spans under it are roots, each in22// a trace of its own.23type Parent struct {24 trace traceID25 span spanID26}2728// spanIDs are a span's trace and span ids, and its parent's span id29// (zero for a root).30type spanIDs struct {31 trace traceID32 span spanID33 parent spanID34}3536// child makes the ids of a new span under p.37func (p Parent) child() spanIDs {38 ids := spanIDs{trace: p.trace, parent: p.span}39 for ids.trace.IsZero() {40 randomBytes(ids.trace[:])41 }42 for ids.span.IsZero() {43 randomBytes(ids.span[:])44 }45 return ids46}4748// Span times one operation. The zero Span, returned while off, does49// nothing. With OTLP on it is sent as a span, and the log record of the50// same event carries its trace, span and parent ids.51type Span struct {52 name string53 start time.Time54 // attrs holds up to four attributes given to Start, in the Span55 // itself: keeping the variadic slice would move it to the heap at56 // every call site, telemetry on or off.57 attrs [4]slog.Attr58 n int59 ids spanIDs60 tr *Trace // the Trace it is open in, if it was started through one61}6263// Start begins timing an operation named like "recalc" or "import", with64// up to four attributes known at the start, as a root span.65func Start(name string, attrs ...slog.Attr) Span {66 if !on.Load() {67 return Span{}68 }69 return newSpan(Parent{}, name, attrs)70}7172// Start begins a span under p, like the package's Start.73func (p Parent) Start(name string, attrs ...slog.Attr) Span {74 if !on.Load() {75 return Span{}76 }77 return newSpan(p, name, attrs)78}7980func newSpan(p Parent, name string, attrs []slog.Attr) Span {81 s := Span{name: name, start: time.Now(), ids: p.child()}82 s.n = copy(s.attrs[:], attrs)83 return s84}8586// Parent is the handle for nesting spans under s; zero for the zero Span.87func (s Span) Parent() Parent { return Parent{s.ids.trace, s.ids.span} }8889// End logs the operation with its duration in milliseconds and any90// attributes learned along the way, such as rows read. A span started91// through a Trace is no longer open in it.92func (s Span) End(attrs ...slog.Attr) {93 if s.name == "" {94 return95 }96 s.tr.close(s.ids.span)97 if !on.Load() {98 return99 }100 emit(slog.LevelInfo, s.name, time.Since(s.start), append(s.attrs[:s.n:s.n], attrs...), s.ids)101}102103// Fail ends the span with an error, logged at Warn with its message.104func (s Span) Fail(err error, attrs ...slog.Attr) {105 if err == nil {106 s.End(attrs...)107 return108 }109 if s.name == "" {110 return111 }112 s.tr.close(s.ids.span)113 if !on.Load() {114 return115 }116 attrs = append(append(s.attrs[:s.n:s.n], attrs...), slog.String("error", err.Error()))117 emit(slog.LevelWarn, s.name, time.Since(s.start), attrs, s.ids)118}119120// Event logs a finished operation that took d, as a root span.121func Event(name string, d time.Duration, attrs ...slog.Attr) {122 if !on.Load() {123 return124 }125 emit(slog.LevelInfo, name, d, attrs, Parent{}.child())126}127128// Event logs a finished operation that took d, as a span under p.129func (p Parent) Event(name string, d time.Duration, attrs ...slog.Attr) {130 if !on.Load() {131 return132 }133 emit(slog.LevelInfo, name, d, attrs, p.child())134}135136// Trace is the spans open in one thread of work, innermost last: one UI137// program's, or one import's. Spans started through it nest under the138// innermost open span, and stay open in it until they end. It belongs139// to one goroutine at a time, like the Model or workbook that keeps it.140// A nil *Trace works too, with nothing open.141type Trace struct {142 open []Parent143 begun []Span // spans started by Begin, for End144}145146// NewTrace returns a Trace with base open, if it isn't zero, beneath147// everything started through it.148func NewTrace(base Parent) *Trace {149 t := &Trace{}150 if base != (Parent{}) {151 t.open = append(t.open, base)152 }153 return t154}155156// Parent is the innermost span open, zero if none is: the handle to give157// work done on another goroutine.158func (t *Trace) Parent() Parent {159 if t == nil || len(t.open) == 0 {160 return Parent{}161 }162 return t.open[len(t.open)-1]163}164165// Start begins a span under the innermost open one; it is the innermost166// itself until it ends.167func (t *Trace) Start(name string, attrs ...slog.Attr) Span {168 if !on.Load() {169 return Span{}170 }171 s := newSpan(t.Parent(), name, attrs)172 if t != nil {173 s.tr = t174 t.open = append(t.open, s.Parent())175 }176 return s177}178179// Event logs a finished operation that took d, under the innermost open180// span.181func (t *Trace) Event(name string, d time.Duration, attrs ...slog.Attr) {182 if !on.Load() {183 return184 }185 emit(slog.LevelInfo, name, d, attrs, t.Parent().child())186}187188// Begin starts a span like Start and keeps it for End, for code that189// has nowhere to keep a Span, such as the engine's hooks (see cmd/012).190// On a nil Trace it does nothing.191func (t *Trace) Begin(name string) {192 if t == nil || !on.Load() {193 return194 }195 t.begun = append(t.begun, t.Start(name))196}197198// End ends the span last begun by Begin, reporting whether there was one.199func (t *Trace) End(attrs ...slog.Attr) bool {200 if t == nil || len(t.begun) == 0 {201 return false202 }203 s := t.begun[len(t.begun)-1]204 t.begun = t.begun[:len(t.begun)-1]205 s.End(attrs...)206 return true207}208209// Enter makes p the innermost open span, until Leave with the depth it210// returns: for a span that lives across several updates (a macro run, a211// session) to hold what each of them starts.212func (t *Trace) Enter(p Parent) int {213 if t == nil {214 return 0215 }216 n := len(t.open)217 if p != (Parent{}) {218 t.open = append(t.open, p)219 }220 return n221}222223// Leave closes what was opened since the Enter that returned depth.224func (t *Trace) Leave(depth int) {225 if t != nil && depth < len(t.open) {226 t.open = t.open[:depth]227 }228}229230// close closes span and anything opened after it that is still open (a231// span ended out of order, or not at all).232func (t *Trace) close(span spanID) {233 if t == nil {234 return235 }236 for i := len(t.open) - 1; i >= 0; i-- {237 if t.open[i].span == span {238 t.open = t.open[:i]239 return240 }241 }242}243244// parentKey carries a Parent in a context.Context, where one already245// goes by, as into an import.246type parentKey struct{}247248// WithParent returns ctx carrying p, for ParentFrom.249func WithParent(ctx context.Context, p Parent) context.Context {250 if p == (Parent{}) {251 return ctx252 }253 return context.WithValue(ctx, parentKey{}, p)254}255256// ParentFrom is the Parent ctx carries, zero if none.257func ParentFrom(ctx context.Context) Parent {258 p, _ := ctx.Value(parentKey{}).(Parent)259 return p260}261262// idAttrs appends a span's ids to attrs as trace_id, span_id and, below263// a root, parent_id, so the JSON log holds the same tree as the traces.264// The three are cut from one string, one allocation.265func idAttrs(attrs []slog.Attr, ids spanIDs) []slog.Attr {266 var b [64]byte267 hex.Encode(b[:32], ids.trace[:])268 hex.Encode(b[32:48], ids.span[:])269 n := 48270 if !ids.parent.IsZero() {271 hex.Encode(b[48:], ids.parent[:])272 n = 64273 }274 s := string(b[:n])275 attrs = append(attrs, slog.String("trace_id", s[:32]), slog.String("span_id", s[32:48]))276 if n == 64 {277 attrs = append(attrs, slog.String("parent_id", s[48:]))278 }279 return attrs280}