Files
Kyle Carberry 385146000b feat: record created_at/completed_at on reasoning ChatMessageParts (#24789)
Records reasoning start and end times on persisted reasoning
`ChatMessagePart`s so reasoning duration can be computed for stored
chats. Backend-only: no SSE changes and no frontend rendering ship in
this PR.

The `created_at` field on `ChatMessagePart` is extended to also be
present on `reasoning` parts (it previously appeared only on `tool-call`
and `tool-result`), and a new `completed_at` field is added for
`reasoning` parts.

### How timestamps are recorded

- `StreamPartTypeReasoningStart`: stamp `startedAt = dbtime.Now()` on
the active reasoning state.
- `StreamPartTypeReasoningEnd`: stamp `completedAt = dbtime.Now()` and
append both into parallel `[]time.Time` slices on `stepResult`.
- Persistence reads the slices in occurrence order (reasoning has no
provider-side ID) and applies them to the matching `ChatMessagePart` via
`buildAssistantPartsForPersist`. The first reasoning block's stamps go
onto the first reasoning part, and so on.
- `flushActiveState` flushes partial reasoning interrupted before
`StreamPartTypeReasoningEnd` with `startedAt` from the active state and
`completedAt = dbtime.Now()` at the interruption.

### Why two fields, not one?

Tool calls and results are point events. The frontend computes their
duration by subtracting the call's `created_at` from the result's
`created_at`. Reasoning is one assistant part that brackets a span, so
we record both endpoints on the part itself.

### Why not stamp in `PartFromContent`?

Same rationale as #24101: `PartFromContent` is called during both SSE
publishing and persistence. Stamping there would yield incorrect
persistence-time timestamps for reasoning blocks that finished much
earlier in the step. Instead we capture in the chatloop and apply during
persistence.

<details><summary>Implementation plan</summary>

- `codersdk/chats.go`: extend `CreatedAt`'s `variants` to include
`reasoning?`; add `CompletedAt *time.Time` with `variants:"reasoning?"`.
- `coderd/x/chatd/chatloop/chatloop.go`: extend `reasoningState` with
`startedAt`; extend `stepResult` and `PersistedStep` with parallel
`[]time.Time` reasoning slices; stamp on
`ReasoningStart`/`ReasoningEnd`; thread the slices through all
`PersistStep` call sites including the interrupt-safe path; record
partial reasoning in `flushActiveState`.
- `coderd/x/chatd/attachments.go`: walk reasoning parts in occurrence
order and apply `step.ReasoningStartedAt[i]` to `part.CreatedAt` and
`step.ReasoningCompletedAt[i]` to `part.CompletedAt`.

### Tests

- `codersdk/chats_test.go` round-trips `created_at` + `completed_at` on
reasoning parts and verifies omission when absent and partial
interrupted parts.
- `coderd/x/chatd/chatprompt/chatprompt_test.go` asserts
`PartFromContent(ReasoningContent{})` does NOT stamp timestamps.
- `coderd/x/chatd/chatloop/chatloop_test.go`
`TestRun_ReasoningTimestamps` drives a stream with two reasoning blocks
and verifies parallel slices, monotonicity, ordering, non-zero values,
and content-block ordering.
`TestRun_InterruptedReasoningFlushesTimestamps` cancels mid-reasoning
and verifies `flushActiveState` records a non-zero pair.
- `coderd/x/chatd/attachments_test.go` covers
`buildAssistantPartsForPersist` for normal interleaved reasoning,
partial (zero `completed_at`), and missing slices.

</details>

> Generated by Coder Agents.

Co-authored-by: Coder Agent <agent@coder.com>
2026-05-18 12:30:30 -04:00

82 lines
2.5 KiB
Go

package chatd
import (
"context"
"charm.land/fantasy"
"github.com/google/uuid"
"cdr.dev/slog/v3"
"github.com/coder/coder/v2/coderd/x/chatd/chatloop"
"github.com/coder/coder/v2/coderd/x/chatd/chatprompt"
"github.com/coder/coder/v2/coderd/x/chatd/chattool"
"github.com/coder/coder/v2/codersdk"
)
func buildAssistantPartsForPersist(
ctx context.Context,
logger slog.Logger,
assistantBlocks []fantasy.Content,
toolResults []fantasy.ToolResultContent,
step chatloop.PersistedStep,
toolNameToConfigID map[string]uuid.UUID,
) []codersdk.ChatMessagePart {
parts := make([]codersdk.ChatMessagePart, 0, len(assistantBlocks)+len(toolResults))
// reasoningIdx walks reasoning blocks in occurrence order so we
// can apply the matching ReasoningStartedAt/ReasoningCompletedAt
// entry from step onto each reasoning part's CreatedAt and
// CompletedAt.
reasoningIdx := 0
for _, block := range assistantBlocks {
part := chatprompt.PartFromContentWithLogger(ctx, logger, block)
if part.ToolName != "" {
if configID, ok := toolNameToConfigID[part.ToolName]; ok {
part.MCPServerConfigID = uuid.NullUUID{UUID: configID, Valid: true}
}
}
if part.Type == codersdk.ChatMessagePartTypeToolCall && part.ToolCallID != "" && step.ToolCallCreatedAt != nil {
if ts, ok := step.ToolCallCreatedAt[part.ToolCallID]; ok {
part.CreatedAt = &ts
}
}
if part.Type == codersdk.ChatMessagePartTypeToolResult && part.ToolCallID != "" && step.ToolResultCreatedAt != nil {
if ts, ok := step.ToolResultCreatedAt[part.ToolCallID]; ok {
part.CreatedAt = &ts
}
}
if part.Type == codersdk.ChatMessagePartTypeReasoning {
if reasoningIdx < len(step.ReasoningStartedAt) {
if ts := step.ReasoningStartedAt[reasoningIdx]; !ts.IsZero() {
part.CreatedAt = &ts
}
}
if reasoningIdx < len(step.ReasoningCompletedAt) {
if ts := step.ReasoningCompletedAt[reasoningIdx]; !ts.IsZero() {
part.CompletedAt = &ts
}
}
reasoningIdx++
}
parts = append(parts, part)
}
for _, tr := range toolResults {
attachments, err := chattool.AttachmentsFromMetadata(tr.ClientMetadata)
if err != nil {
logger.Warn(ctx, "skipping malformed tool attachment metadata",
slog.F("tool_name", tr.ToolName),
slog.F("tool_call_id", tr.ToolCallID),
slog.Error(err),
)
continue
}
for _, attachment := range attachments {
parts = append(parts, codersdk.ChatMessageFile(
attachment.FileID,
attachment.MediaType,
attachment.Name,
))
}
}
return parts
}