feat: tag chat-originating agent logs with chat_id (#25019)

Workspace-agent logs emitted while serving chatd-driven requests were
not correlated with the originating chat, making agent logs hard to
attribute to the corresponding/originating chat.

This adds agent-side chat context middleware that parses `Coder-Chat-Id`
once, enriches agent access logs and structured handler/background logs,
and adds a chatd bridge log when chat headers are attached to an agent
connection.

Closes CODAGT-324
This commit is contained in:
Ethan
2026-05-08 13:25:30 +10:00
committed by GitHub
parent e9f0385198
commit 3a9080fff6
15 changed files with 380 additions and 95 deletions
+13 -11
View File
@@ -13,6 +13,7 @@ import (
"github.com/google/uuid"
"cdr.dev/slog/v3"
"github.com/coder/coder/v2/agent/agentchat"
"github.com/coder/coder/v2/agent/agentexec"
"github.com/coder/coder/v2/agent/agentgit"
"github.com/coder/coder/v2/coderd/httpapi"
@@ -80,8 +81,8 @@ func (api *API) handleStartProcess(rw http.ResponseWriter, r *http.Request) {
}
var chatID string
if id, _, ok := agentgit.ExtractChatContext(r); ok {
chatID = id.String()
if chatContext, ok := agentchat.FromContext(ctx); ok {
chatID = chatContext.ID.String()
}
proc, err := api.manager.start(req, chatID)
@@ -97,8 +98,8 @@ func (api *API) handleStartProcess(rw http.ResponseWriter, r *http.Request) {
// file changes made by the command are visible in the scan.
// If a workdir is provided, track it as a path as well.
if api.pathStore != nil {
if chatID, ancestorIDs, ok := agentgit.ExtractChatContext(r); ok {
allIDs := append([]uuid.UUID{chatID}, ancestorIDs...)
if chatContext, ok := agentchat.FromContext(ctx); ok {
allIDs := append([]uuid.UUID{chatContext.ID}, chatContext.AncestorIDs...)
go func() {
<-proc.done
if req.WorkDir != "" {
@@ -121,8 +122,8 @@ func (api *API) handleListProcesses(rw http.ResponseWriter, r *http.Request) {
ctx := r.Context()
var chatID string
if id, _, ok := agentgit.ExtractChatContext(r); ok {
chatID = id.String()
if chatContext, ok := agentchat.FromContext(ctx); ok {
chatID = chatContext.ID.String()
}
infos := api.manager.list(chatID)
@@ -150,6 +151,7 @@ func (api *API) handleListProcesses(rw http.ResponseWriter, r *http.Request) {
// handleProcessOutput returns the output of a process.
func (api *API) handleProcessOutput(rw http.ResponseWriter, r *http.Request) {
ctx := r.Context()
logger := api.logger.With(agentchat.Fields(ctx)...)
id := chi.URLParam(r, "id")
proc, ok := api.manager.get(id)
@@ -163,8 +165,8 @@ func (api *API) handleProcessOutput(rw http.ResponseWriter, r *http.Request) {
// Enforce chat ID isolation. If the request carries
// a chat context, only allow access to processes
// belonging to that chat.
if chatID, _, ok := agentgit.ExtractChatContext(r); ok {
if proc.chatID != "" && proc.chatID != chatID.String() {
if chatContext, ok := agentchat.FromContext(ctx); ok {
if proc.chatID != "" && proc.chatID != chatContext.ID.String() {
httpapi.Write(ctx, rw, http.StatusNotFound, codersdk.Response{
Message: fmt.Sprintf("Process %q not found.", id),
})
@@ -184,7 +186,7 @@ func (api *API) handleProcessOutput(rw http.ResponseWriter, r *http.Request) {
// Add headroom beyond the wait timeout so there's time to
// write the response after the blocking wait completes.
if err := rc.SetWriteDeadline(time.Now().Add(maxWaitDuration + 30*time.Second)); err != nil {
api.logger.Error(ctx, "extend write deadline for blocking process output",
logger.Error(ctx, "extend write deadline for blocking process output",
slog.Error(err),
)
}
@@ -216,9 +218,9 @@ func (api *API) handleSignalProcess(rw http.ResponseWriter, r *http.Request) {
id := chi.URLParam(r, "id")
// Enforce chat ID isolation.
if chatID, _, ok := agentgit.ExtractChatContext(r); ok {
if chatContext, ok := agentchat.FromContext(ctx); ok {
proc, procOK := api.manager.get(id)
if procOK && proc.chatID != "" && proc.chatID != chatID.String() {
if procOK && proc.chatID != "" && proc.chatID != chatContext.ID.String() {
httpapi.Write(ctx, rw, http.StatusNotFound, codersdk.Response{
Message: fmt.Sprintf("Process %q not found.", id),
})
+33 -2
View File
@@ -20,9 +20,12 @@ import (
"cdr.dev/slog/v3"
"cdr.dev/slog/v3/sloggers/slogtest"
"github.com/coder/coder/v2/agent/agentchat"
"github.com/coder/coder/v2/agent/agentexec"
"github.com/coder/coder/v2/agent/agentgit"
"github.com/coder/coder/v2/agent/agentproc"
"github.com/coder/coder/v2/coderd/httpmw/loggermw"
"github.com/coder/coder/v2/coderd/tracing"
"github.com/coder/coder/v2/codersdk"
"github.com/coder/coder/v2/codersdk/workspacesdk"
"github.com/coder/coder/v2/testutil"
@@ -137,7 +140,35 @@ func newTestAPIWithOptions(t *testing.T, updateEnv func([]string) ([]string, err
t.Cleanup(func() {
_ = api.Close()
})
return api.Routes()
return agentchat.Middleware(api.Routes())
}
func TestAccessLogIncludesChatID(t *testing.T) {
t.Parallel()
sink := testutil.NewFakeSink(t)
logger := sink.Logger()
api := agentproc.NewAPI(logger, agentexec.DefaultExecer, nil, nil, nil)
t.Cleanup(func() {
_ = api.Close()
})
handler := tracing.StatusWriterMiddleware(loggermw.Logger(logger)(
agentchat.Middleware(api.Routes()),
))
chatID := uuid.New().String()
w := getListWithChatHeader(t, handler, chatID)
require.Equal(t, http.StatusOK, w.Code)
entries := sink.Entries(func(entry slog.SinkEntry) bool {
return entry.Message == http.MethodGet
})
require.Len(t, entries, 1)
fields := make(map[string]any, len(entries[0].Fields))
for _, field := range entries[0].Fields {
fields[field.Name] = field.Value
}
require.Equal(t, chatID, fields["chat_id"])
}
// waitForExit polls the output endpoint until the process is
@@ -1058,7 +1089,7 @@ func TestHandleStartProcess_ChatHeaders_EmptyWorkDir_StillNotifies(t *testing.T)
}, pathStore, nil)
defer api.Close()
routes := api.Routes()
routes := agentchat.Middleware(api.Routes())
body, err := json.Marshal(workspacesdk.StartProcessRequest{
Command: "echo hello",
+8 -2
View File
@@ -38,6 +38,7 @@ type process struct {
cmd *exec.Cmd
cancel context.CancelFunc
buf *HeadTailBuffer
logger slog.Logger
running bool
exitCode *int
startedAt int64
@@ -105,6 +106,10 @@ func (m *manager) start(req workspacesdk.StartProcessRequest, chatID string) (*p
m.mu.Unlock()
id := uuid.New().String()
logger := m.logger
if chatID != "" {
logger = logger.With(slog.F("chat_id", chatID))
}
// Use a cancellable context so Close() can terminate
// all processes. context.Background() is the parent so
@@ -132,7 +137,7 @@ func (m *manager) start(req workspacesdk.StartProcessRequest, chatID string) (*p
if m.updateEnv != nil {
updated, err := m.updateEnv(baseEnv)
if err != nil {
m.logger.Warn(
logger.Warn(
context.Background(),
"failed to update command environment, falling back to os env",
slog.Error(err),
@@ -169,6 +174,7 @@ func (m *manager) start(req workspacesdk.StartProcessRequest, chatID string) (*p
cmd: cmd,
cancel: cancel,
buf: buf,
logger: logger,
running: true,
startedAt: now,
done: make(chan struct{}),
@@ -202,7 +208,7 @@ func (m *manager) start(req workspacesdk.StartProcessRequest, chatID string) (*p
} else {
// Unknown error; use -1 as a sentinel.
code = -1
m.logger.Warn(
proc.logger.Warn(
context.Background(),
"process wait returned non-exit error",
slog.F("id", id),