Skip to content
Observability

Observability

Observability

Three layers, each answering a different question:

LayerQuestionPackage
ObserversHow is the conversation behaving?observers/
MetricsHow is the system performing, in aggregate?telemetry/metrics
TracingWhat happened on this turn?telemetry/tracing

Observers

Observers watch frames without modifying them. They are the cheapest way to get conversation-level signal.

task := pipeline.NewWorker(pipe, pipeline.WorkerConfig{
    Observers: []pipeline.Observer{
        observers.NewTurnTracking(observers.TurnTrackingConfig{
            OnTurnEnded: func(turn int, d time.Duration, interrupted bool) {
                slog.Info("turn", "n", turn, "dur", d, "interrupted", interrupted)
            },
        }),
        observers.NewUserBotLatency(observers.LatencyConfig{
            OnLatency: func(d time.Duration) {
                slog.Info("response latency", "d", d)
            },
        }),
    },
})
ObserverMeasures
NewTurnTrackingTurn count, duration, and whether each was interrupted.
NewUserBotLatencyUser stopped speaking → bot started. The number users feel, with a per-service breakdown of where it went.
NewStartupTimingWhat each processor cost to start, and how long the transport took to connect.
NewDebugLogFrames and their contents, for working out what a pipeline is doing.
NewLLMLogWhat a model was asked, what it generated, and the tools it called.
NewTranscriptionLogWhat a transcriber heard, interim results included.
NewMetricsLogEach measurement the pipeline reports, as it is reported.

TurnTracking has a TurnEndTimeout (default 2.5s) so a brief gap between bot utterances (an HTTP TTS boundary, a tool call) does not split one turn into two.

Where the response latency went

UserBotLatency reports more than the headline figure. Alongside every latency it reports a LatencyBreakdown, and it reports separately on the first thing the bot says after a client connects, which is the greeting rather than a reply:

observers.NewUserBotLatency(observers.LatencyConfig{
    OnFirstBotSpeechLatency: func(d time.Duration) {
        slog.Info("greeting latency", "d", d)
    },
    OnBreakdown: func(b observers.LatencyBreakdown) {
        for _, line := range b.ChronologicalEvents() {
            slog.Info("latency", "event", line)
        }
    },
})

The breakdown accounts for the user turn (the silence window, the transcriber finalizing, any end-of-turn analyzer), each service’s time to first byte, the sentence aggregation before synthesis, and any tool calls the reply made. It is built from the MetricsFrames the services emit, so it is empty of measurements unless EnableMetrics is set below.

What startup cost

A processor does its startup work while handling the StartFrame: connecting, authenticating, loading a model. StartupTiming times that per processor and reports once the pipeline is up.

observers.NewStartupTiming(observers.StartupTimingConfig{
    OnStartupTimingReport: func(r observers.StartupTimingReport) {
        for _, t := range r.ProcessorTimings {
            slog.Info("started", "processor", t.ProcessorName, "took", t.Duration)
        }
    },
})

Pass Track to narrow the report to the processors worth measuring; by default it covers everything but the pipeline plumbing.

The other half of a cold start is the transport, reported separately:

observers.NewStartupTiming(observers.StartupTimingConfig{
    OnTransportTimingReport: func(r observers.TransportTimingReport) {
        if r.BotConnected != nil {
            slog.Info("bot joined", "after", *r.BotConnected)
        }
        slog.Info("client connected", "after", r.ClientConnected)
    },
})

It is built from two frames the transports push into the pipeline:

FramePushed byWhen
ClientConnectedFrametransport/rtc (and WhatsApp, which builds on it)The peer connection is established.
transport/wsserver (Twilio, Telnyx, Plivo, Exotel, RTVI)The pipeline starts: the socket was accepted before it.
transport/livekitA remote participant joins the room.
BotConnectedFrametransport/livekitThe pipeline starts: the room was joined before it.

BotConnected is nil on every transport but a room one, because there is nothing for the bot to join: the client dials it directly. On LiveKit, a participant who was already in the room when the bot joined is not reported, since they did not arrive while the bot was there to see it.

transport/localaudio reports neither: the microphone is not a caller.

Debugging the frame flow

NewDebugLog renders the fields of every frame it is given. Unfiltered that is dozens of audio frames a second per direction, so narrow it:

observers.NewDebugLog(observers.DebugLogConfig{
    Frames: []observers.DebugFrameFilter{
        // Every LLM token, wherever it travels.
        {Frame: &frames.LLMTextFrame{}},
        // User speech, but only where it reaches a streaming transcriber.
        {
            Frame:    &frames.UserStartedSpeakingFrame{},
            Match:    func(p processor.Processor) bool { _, ok := p.(*stt.StreamService); return ok },
            Endpoint: observers.DestinationEndpoint,
        },
    },
})

The three specialized loggers need no filter: each already reports one part of the conversation. LLMLog and TranscriptionLog report only what actually passed through a model or a transcriber, so the same frame types travelling elsewhere are left alone.

Observers see every handover

An observer is reported to on every hand-off between two processors, not only at the ends of the pipeline, so it can tell where each frame came from. That is what lets it distinguish a frame that has been through the output transport, and so carries real playback timing, from the same frame earlier in the chain. The EventFrameReachedDownstream and EventFrameReachedUpstream events are the narrower thing: those fire only at the pipeline source and sink.

One consequence of watching everything: a turn-taking signal is broadcast as two frames, one per direction. Observers count only the downstream half, using BroadcastSiblingID to recognize the pair. Otherwise every turn would be counted twice. If you write an observer that reacts to UserStartedSpeakingFrame, UserStoppedSpeakingFrame or InterruptionFrame, handle that pairing.

Observers run off the frame path, each on a goroutine of its own, so a slow one falls behind rather than holding up the conversation.

Metrics

Enable collection on the task, or nothing is measured:

pipeline.WorkerConfig{
	Params: pipeline.Params{
	    EnableMetrics:      true,   // TTFB, processing time
	    EnableUsageMetrics: true,   // tokens, TTS characters, STT audio duration
	},
}

The flags travel down the pipeline on the StartFrame, which is how each processor learns whether to measure. They are separate because usage metrics cost money to compute in provider round trips and TTFB does not.

telemetry/metrics exports through OpenTelemetry:

RecordedMeaning
TTFBTime to first byte from a service.
TTFATime to first audio, measured from the first audible sample, not the first byte, so leading silence does not flatter the number.
Processing timeWall time inside a service.
TokensLLM input/output.
TTS characters, STT audio secondsUsage for cost attribution.
shutdown, err := metrics.Init(ctx, metrics.Config{ /* … */ })
defer shutdown(ctx)

Metrics also travel in-band as MetricsFrames, which is how the RTVI processor forwards them to a client.

Tracing

Spans per conversation, per turn and per service call, over OpenTelemetry:

shutdown, err := tracing.Init(ctx, tracing.Config{ /* … */ })
defer shutdown(ctx)

task := pipeline.NewWorker(pipe, pipeline.WorkerConfig{
	EnableTracing:  true,
	ConversationID: sessionID, // empty generates one
	// Attributes on the conversation span, which is the root of the trace — where
	// a backend's own keys go (a session id, a user id, tags).
	AdditionalSpanAttributes: []attribute.KeyValue{
		attribute.String("langfuse.session.id", sessionID),
		attribute.String("langfuse.user.id", userID),
	},
})
task.Run(ctx)

The session is one trace, shaped like the conversation it recorded:

conversation                       conversation.id, conversation.type
└── turn                           turn.number, turn.duration_seconds,
    ├── stt                        turn.was_interrupted,
    ├── llm                        turn.user_bot_latency_seconds
    └── tts

So a slow turn can be opened up stage by stage: STT finalize → LLM first token → TTS first audio. That breakdown is the fastest way to find which provider is costing you the latency, and the turn span carries the number that matters most — turn.user_bot_latency_seconds — beside it.

Turn spans come from the turn tracking the task runs for them; set EnableTurnTracking to false to trace the conversation and its service calls without them.

Token usage lands on spans as gen_ai.usage.* attributes via tracing.SetTokenUsage, with SetTTSUsage and SetSTTUsage alongside.

examples/voicebot wires tracing end to end.

What to watch

For a voice agent, the number that matters is user-stopped-speaking → bot started. Under roughly 800 ms feels conversational; past about 1.5 s people start talking over the bot.

When it is too slow, the useful next question is which stage owns it:

  • End-of-turn detection: often the real cost, and invisible in provider metrics. Check SpeechControlParamsFrame and see Turn-taking .
  • LLM first token: usually the largest single component. A smaller model or a shorter system prompt beats micro-optimizing elsewhere.
  • TTS first audio: watch TTFA, not TTFB.

Interruption rate from TurnTracking is the other signal worth a dashboard: a rate that climbs means turn-taking is cutting users off, or the bot is too verbose.