coder · jscottmiller · Aug 27, 2026
diff --git a/coderd/coderd.go b/coderd/coderd.go
@@ -955,6 +955,7 @@ func New(options *Options) *API {
 				HookDispatcher:                 hookDispatcher,
 				UsageTracker:                   options.WorkspaceUsageTracker,
 				PrometheusRegistry:             options.PrometheusRegistry,
+				TracerProvider:                 options.TracerProvider,
 				AgentCapacityUnlock:            options.ChatAgentCapacityUnlock,
 				OIDCTokenSource:                oidcMCPSrc,
 				NotificationsEnqueuer:          options.NotificationsEnqueuer,

diff --git a/coderd/x/chatd/ARCHITECTURE.md b/coderd/x/chatd/ARCHITECTURE.md
@@ -655,6 +655,8 @@ For every matching chat, it locks it, checks if the chat still meets the aforeme
 
 When a chat is successfully acquired, the acquisition loop requests the [Runner manager](#runner-manager) to spawn a chat runner for it.
 
+<!-- TODO: document the acquisition loop's per-chat capacity refusal tracking, which now emits the `capacity_wait` lifecycle stage on the acquisition that follows a refusal. -->
+
 ### Load balancing
 
 The design doesn't attempt to distribute load between workers fairly. Whenever a chat needs an owner, all replicas race to acquire it. If there's a coder replica that has a lower latency to the database, it'll tend to acquire chats more frequently than other replicas.
@@ -778,6 +780,8 @@ State updates processed by the loop come from:
 
 The runner is responsible for subscribing to the `chat:update:{chat_id}` pubsub channel. During bootstrap, it must first subscribe to the channel and then fetch the initial state of the chat from the database to avoid missing any updates.
 
+<!-- TODO: document that the runner owns the turn-scoped `chat_turn` trace span, started by the first generation task and ended when the runner exits, and that the generation goroutine's stages hang off it. -->
+
 ### Event shape
 
 Every event that the runner loop processes has the following shape:
@@ -859,6 +863,8 @@ The generation goroutine is responsible for calling the LLM API and executing to
 
 It inspects the chat's message history, and decides what's the next step to take. The result of that step is the application of one of the following core state machine transitions:
 
+<!-- TODO: document the generation goroutine's lifecycle stages (`generation_step`, `prepare`, `mcp_connect`, `provider_attempt`, `stream`, `time_to_first_token`, `thinking`, `tool_call`, `commit`, `compaction`, `queue_wait`) and the `coderd_chatd_stage_duration_seconds` histogram they feed. -->
+
 - `CommitStep`: applied when an LLM API call returns a response.
 - `FinishTurn`: applied when the chat processing logic determines that there's no more work to do for the current message history (no pending tool calls, user message is not the last message in the history, etc.).
 - `FinishError`: applied when the LLM API call fails and the retry limit is reached, determined by the `generation_attempt` value.

diff --git a/coderd/x/chatd/capacity.go b/coderd/x/chatd/capacity.go
@@ -2,11 +2,14 @@ package chatd
 
 import (
 	"context"
+	"time"
 
 	"github.com/google/uuid"
 	"github.com/prometheus/client_golang/prometheus"
+	"go.opentelemetry.io/otel/attribute"
 
 	"github.com/coder/coder/v2/coderd/database"
+	"github.com/coder/coder/v2/coderd/x/chatd/chatloop"
 )
 
 type capacityMetrics struct {
@@ -46,6 +49,52 @@ func (w *chatWorker) capacityMetricsLoop(ctx context.Context) {
 	}
 }
 
+// noteCapacityRefused remembers when a chat was first refused a
+// capacity slot. Only the acquisition loop touches the map, so it
+// needs no lock.
+func (w *chatWorker) noteCapacityRefused(chatID uuid.UUID) {
+	if _, ok := w.capacityWaitSince[chatID]; ok {
+		return
+	}
+	w.capacityWaitSince[chatID] = time.Now()
+}
+
+// recordCapacityWait emits the capacity_wait stage for a chat that is
+// being acquired after at least one capacity refusal, measured from
+// the first refusal this worker saw. Chats admitted on their first
+// attempt record nothing. The acquisition pass runs before the turn
+// span exists, so the turn scope is stated explicitly.
+func (w *chatWorker) recordCapacityWait(ctx context.Context, chat database.Chat) {
+	since, waited := w.capacityWaitSince[chat.ID]
+	if !waited {
+		return
+	}
+	delete(w.capacityWaitSince, chat.ID)
+	w.server.stages.RecordAs(ctx, chatloop.StageCapacityWait, chatloop.ScopeTurn, chatloop.StageModel{},
+		since, time.Now(), nil,
+		attribute.String(chatloop.AttrChatID, chat.ID.String()),
+		attribute.String(chatloop.AttrChatKind, chatKindAttr(chat)),
+	)
+}
+
+// pruneCapacityWaits drops wait starts for chats that are no longer
+// acquisition candidates, which happens when they are archived,
+// deleted, or picked up by another worker.
+func (w *chatWorker) pruneCapacityWaits(candidates []database.GetChatWorkerAcquisitionCandidatesRow) {
+	if len(w.capacityWaitSince) == 0 {
+		return
+	}
+	stillCandidate := make(map[uuid.UUID]struct{}, len(candidates))
+	for _, row := range candidates {
+		stillCandidate[row.ID] = struct{}{}
+	}
+	for chatID := range w.capacityWaitSince {
+		if _, ok := stillCandidate[chatID]; !ok {
+			delete(w.capacityWaitSince, chatID)
+		}
+	}
+}
+
 func (w *chatWorker) refreshCapacityMetrics(ctx context.Context) {
 	active, err := w.opts.Store.CountChatCapacityActiveByPool(ctx, database.CountChatCapacityActiveByPoolParams{
 		ExcludeChatID: uuid.Nil,

diff --git a/coderd/x/chatd/chatd.go b/coderd/x/chatd/chatd.go
@@ -21,6 +21,8 @@ import (
 	"github.com/google/uuid"
 	"github.com/prometheus/client_golang/prometheus"
 	"github.com/sqlc-dev/pqtype"
+	"go.opentelemetry.io/otel/attribute"
+	"go.opentelemetry.io/otel/trace"
 	"golang.org/x/sync/errgroup"
 	"golang.org/x/xerrors"
 
@@ -199,6 +201,7 @@ type Server struct {
 	usageTracker         *workspacestats.UsageTracker
 	clock                quartz.Clock
 	metrics              *chatloop.Metrics
+	stages               *chatloop.StageTracer
 	chatWorker           *chatWorker
 	messagePartBuffer    *messagepartbuffer.Buffer
 	streamSyncPoller     *streamSyncPoller
@@ -2143,9 +2146,10 @@ func (p *Server) PromoteQueued(
 	}
 
 	var (
-		result      PromoteQueuedResult
-		refreshChat database.Chat
-		refreshedOK bool
+		result           PromoteQueuedResult
+		refreshChat      database.Chat
+		refreshedOK      bool
+		promotedQueuedAt time.Time
 	)
 	machine := p.newChatMachine(opts.ChatID)
 	updateErr := machine.Update(ctx, func(tx *chatstate.Tx, store database.Store) error {
@@ -2165,6 +2169,7 @@ func (p *Server) PromoteQueued(
 		}
 		if promoteResult.InsertedMessage != nil {
 			result.PromotedMessage = *promoteResult.InsertedMessage
+			promotedQueuedAt = promoteResult.QueuedMessage.CreatedAt
 		}
 		// Capture the chat inside the transaction so the watch event
 		// published below uses the snapshot bump and status change
@@ -2184,6 +2189,12 @@ func (p *Server) PromoteQueued(
 	if refreshedOK {
 		p.publishChatPubsubEvent(refreshChat, codersdk.ChatWatchEventKindStatusChange, nil)
 	}
+	if !promotedQueuedAt.IsZero() {
+		p.stages.Record(ctx, chatloop.StageQueueWait, chatloop.StageModel{},
+			promotedQueuedAt, time.Now(), nil,
+			attribute.String(chatloop.AttrChatID, opts.ChatID.String()),
+		)
+	}
 	return result, nil
 }
 
@@ -3061,6 +3072,9 @@ type Config struct {
 	AIBridgeTransportFactory       *atomic.Pointer[aibridge.TransportFactory]
 	Experiments                    codersdk.Experiments
 	PrometheusRegistry             prometheus.Registerer
+	// TracerProvider supplies the tracer used for chat lifecycle
+	// spans. Nil disables tracing without disabling metrics.
+	TracerProvider trace.TracerProvider
 
 	AgentCapacityUnlock AgentCapacityUnlock
 
@@ -3190,6 +3204,7 @@ func New(ps pubsub.Pubsub, cfg Config) *Server {
 	} else {
 		p.metrics = chatloop.NopMetrics()
 	}
+	p.stages = chatloop.NewStageTracer(cfg.TracerProvider, p.metrics)
 	p.messagePartBuffer = messagepartbuffer.New(messagepartbuffer.Options{Clock: clk})
 	localStreamPartsDialer := NewLocalStreamPartsDialer(LocalStreamPartsDialerConfig{
 		Buffer: p.messagePartBuffer,
@@ -5081,7 +5096,11 @@ func (p *Server) Close() error {
 // must be called once the work completes to release the shutdown hook.
 // The caller is responsible for providing their own timeout.
 func (p *Server) inflightContext(reqCtx context.Context) (context.Context, func()) {
-	ctx, cancel := context.WithCancel(context.WithoutCancel(reqCtx))
+	// Inflight work outlives the caller, so the caller's span is
+	// stripped from the context: spans started on this context become
+	// their own roots instead of children that end after their parent.
+	detached := trace.ContextWithSpanContext(context.WithoutCancel(reqCtx), trace.SpanContext{})
+	ctx, cancel := context.WithCancel(detached)
 	stop := context.AfterFunc(p.ctx, cancel)
 	return ctx, func() {
 		stop()

diff --git a/coderd/x/chatd/chatloop/chatloop.go b/coderd/x/chatd/chatloop/chatloop.go
@@ -18,6 +18,7 @@ import (
 	fantasyanthropic "charm.land/fantasy/providers/anthropic"
 	"charm.land/fantasy/schema"
 	"github.com/google/uuid"
+	"go.opentelemetry.io/otel/attribute"
 	"golang.org/x/xerrors"
 
 	"cdr.dev/slog/v3"
@@ -234,6 +235,12 @@ type GenerateAssistantOptions struct {
 	OnModelStreamStart func()
 	Logger             slog.Logger
 	Metrics            *Metrics
+	// Stages records the stream and time_to_first_token stages. A nil
+	// tracer discards them.
+	Stages *StageTracer
+	// StageModel labels the stage spans and durations with the resolved
+	// model and effective reasoning effort.
+	StageModel StageModel
 }
 
 // AssistantOutcome is the durable assistant-side result from one model call.
@@ -437,8 +444,12 @@ func GenerateAssistant(ctx context.Context, opts GenerateAssistantOptions) (Assi
 		opts.OnModelStreamStart()
 	}
 	stepCtx := chatdebug.ReuseStep(ctx)
+	streamCtx, streamSpan := opts.Stages.Start(stepCtx, StageStream,
+		attribute.String(AttrProvider, provider),
+	)
+	streamSpan.SetModel(opts.StageModel)
 	attempt, streamErr := guardedStream(
-		stepCtx,
+		streamCtx,
 		provider,
 		modelName,
 		opts.Clock,
@@ -447,8 +458,11 @@ func GenerateAssistant(ctx context.Context, opts GenerateAssistantOptions) (Assi
 			return opts.Model.Stream(attemptCtx, call)
 		},
 		opts.Metrics,
+		opts.Stages,
+		opts.StageModel,
 	)
 	if streamErr != nil {
+		streamSpan.End(streamErr)
 		wrappedErr := wrapProviderStreamError(errorProvider, streamErr)
 		classified := chaterror.Classify(wrappedErr).WithProvider(errorProvider)
 		if classified.Retryable {
@@ -460,6 +474,7 @@ func GenerateAssistant(ctx context.Context, opts GenerateAssistantOptions) (Assi
 
 	result, processErr := processStepStream(attempt.ctx, attempt.stream, opts.Clock, publishMessagePart)
 	if err := attempt.finish(processErr); err != nil {
+		streamSpan.End(err)
 		if errors.Is(err, ErrInterrupted) {
 			return AssistantOutcome{}, ErrInterrupted
 		}
@@ -472,6 +487,7 @@ func GenerateAssistant(ctx context.Context, opts GenerateAssistantOptions) (Assi
 	}
 
 	contextLimit := extractContextLimitWithFallback(result.providerMetadata, opts.ContextLimitFallback)
+	streamSpan.End(nil)
 	result.content = chatsanitize.SanitizeAnthropicProviderToolStepContent(
 		ctx, opts.Logger, provider, modelName,
 		"assistant_helper", 0, result.finishReason, result.content,
@@ -874,37 +890,62 @@ func classifyStreamSilenceTimeout(
 	})
 }
 
+// errNoFirstToken marks a time_to_first_token window that ended when
+// the attempt was released or failed before any part streamed.
+var errNoFirstToken = xerrors.New("stream ended before the first token")
+
 func guardedStream(
 	parent context.Context,
 	provider, model string,
 	clock quartz.Clock,
 	timeout time.Duration,
 	openStream func(context.Context) (fantasy.StreamResponse, error),
 	metrics *Metrics,
+	stages *StageTracer,
+	stageModel StageModel,
 ) (guardedAttempt, error) {
 	attemptCtx, cancelAttempt := context.WithCancelCause(parent)
 	guard := newStreamSilenceGuard(clock, timeout, cancelAttempt)
+	streamStart := clock.Now()
+	_, ttftSpan := stages.Start(parent, StageTimeToFirstToken,
+		attribute.String(AttrProvider, provider),
+	)
+	ttftSpan.SetModel(stageModel)
+	var ttftOnce sync.Once
+	// finishTTFT closes the time_to_first_token window exactly once,
+	// either on the first streamed part or when the attempt is released
+	// without one. The TTFT histogram only counts windows that a part
+	// actually closed.
+	finishTTFT := func(err error) {
+		ttftOnce.Do(func() {
+			if err == nil {
+				metrics.TTFTSeconds.WithLabelValues(provider, model).Observe(
+					clock.Since(streamStart).Seconds(),
+				)
+			}
+			ttftSpan.End(err)
+		})
+	}
 	var releaseOnce sync.Once
 	release := func() {
 		releaseOnce.Do(func() {
 			guard.Disarm()
 			cancelAttempt(nil)
+			finishTTFT(errNoFirstToken)
 		})
 	}
 
-	streamStart := clock.Now()
 	stream, err := openStream(attemptCtx)
 	if err != nil {
 		err = classifyStreamSilenceTimeout(attemptCtx, provider, err)
+		finishTTFT(err)
 		release()
 		return guardedAttempt{}, err
 	}
 
-	recordTTFT := sync.OnceFunc(func() {
-		metrics.TTFTSeconds.WithLabelValues(provider, model).Observe(
-			clock.Since(streamStart).Seconds(),
-		)
-	})
+	recordTTFT := func() {
+		finishTTFT(nil)
+	}
 	return guardedAttempt{
 		ctx: attemptCtx,
 		stream: fantasy.StreamResponse(func(yield func(fantasy.StreamPart) bool) {

diff --git a/coderd/x/chatd/chatloop/metrics.go b/coderd/x/chatd/chatloop/metrics.go
@@ -3,6 +3,7 @@ package chatloop
 import (
 	"context"
 	"errors"
+	"time"
 
 	"charm.land/fantasy"
 	"github.com/prometheus/client_golang/prometheus"
@@ -34,6 +35,7 @@ type Metrics struct {
 	ToolResultTruncatedTotal  *prometheus.CounterVec
 	ToolErrorsTotal           *prometheus.CounterVec
 	TTFTSeconds               *prometheus.HistogramVec
+	StageDurationSeconds      *prometheus.HistogramVec
 	CompactionTotal           *prometheus.CounterVec
 	StepsTotal                *prometheus.CounterVec
 	StreamRetriesTotal        *prometheus.CounterVec
@@ -95,6 +97,14 @@ func NewMetrics(reg prometheus.Registerer) *Metrics {
 			Help:      "Time-to-first-token: wall time from LLM request to first streamed chunk.",
 			Buckets:   []float64{0.05, 0.1, 0.25, 0.5, 1, 2.5, 5, 10, 30, 60},
 		}, []string{"provider", "model"}),
+		StageDurationSeconds: factory.NewHistogramVec(prometheus.HistogramOpts{
+			Namespace: metricsNamespace,
+			Subsystem: metricsSubsystem,
+			Name:      "stage_duration_seconds",
+			Help:      "Wall time spent in each chat lifecycle stage. Stages overlap in wall time; this is a stage-time profile, not a partition of the turn. The scope label separates stages that run inside a chat turn from detached background work. The model and effort labels are empty for stages that run before a model is resolved.",
+			// 10ms .. ~11m, log-spaced.
+			Buckets: prometheus.ExponentialBuckets(0.01, 2, 17),
+		}, []string{"stage", "scope", "model", "effort"}),
 		CompactionTotal: factory.NewCounterVec(prometheus.CounterOpts{
 			Namespace: metricsNamespace,
 			Subsystem: metricsSubsystem,
@@ -153,6 +163,16 @@ func NopMetrics() *Metrics {
 	return NewMetrics(prometheus.NewRegistry())
 }
 
+// RecordStageDuration observes one chat lifecycle stage duration.
+// model and effort are empty when the stage ran before a model was
+// resolved. Negative durations are dropped. No-op when m is nil.
+func (m *Metrics) RecordStageDuration(stage, scope, model, effort string, elapsed time.Duration) {
+	if m == nil || elapsed < 0 {
+		return
+	}
+	m.StageDurationSeconds.WithLabelValues(stage, scope, model, effort).Observe(elapsed.Seconds())
+}
+
 // RecordCompaction classifies and records a compaction attempt.
 // It is a no-op when m is nil.
 func (m *Metrics) RecordCompaction(provider, model string, compacted bool, err error) {