From 4cf4ee0121b228dd14c6339508bea5f90ce5b20d Mon Sep 17 00:00:00 2001 From: Hugo Dutka Date: Mon, 15 Jun 2026 14:13:22 +0200 Subject: [PATCH] chore(coderd/x/chatd): log all chat errors (#26371) When a chat hits a terminal error, for example "Request failed unexpectedly", we don't log the full underlying error anywhere. This fixes that. --- coderd/x/chatd/chatd_test.go | 74 ++++++++++++++++++++++++++++++++++++ coderd/x/chatd/generation.go | 15 ++++++++ 2 files changed, 89 insertions(+) diff --git a/coderd/x/chatd/chatd_test.go b/coderd/x/chatd/chatd_test.go index 3ed65b6953..9873e91161 100644 --- a/coderd/x/chatd/chatd_test.go +++ b/coderd/x/chatd/chatd_test.go @@ -8221,6 +8221,80 @@ func newActiveTestServer( return server } +// sinkFieldValue returns the value of the named field from a captured log +// entry. +func sinkFieldValue(fields slog.Map, name string) (any, bool) { + for _, f := range fields { + if f.Name == name { + return f.Value, true + } + } + return nil, false +} + +// TestActiveServer_GenerationErrorLogged drives a full chat worker against a +// provider that returns a terminal error and asserts that chatd logs the +// unsanitized failure so an administrator can later diagnose the underlying +// reason, even though the user-facing message is sanitized. +func TestActiveServer_GenerationErrorLogged(t *testing.T) { + t.Parallel() + + ctx := testutil.Context(t, testutil.WaitLong) + db, ps := dbtestutil.NewDB(t) + sink := testutil.NewFakeSink(t) + + const providerErrMessage = "synthetic provider failure for logging test" + openAIURL := chattest.NewOpenAI(t, func(req *chattest.OpenAIRequest) chattest.OpenAIResponse { + if !req.Stream { + return chattest.OpenAINonStreamingResponse("title") + } + // A 400 is non-retryable, so the worker fails the turn immediately + // instead of entering retry backoff. + return chattest.OpenAIErrorResponse(http.StatusBadRequest, "invalid_request_error", providerErrMessage) + }) + user, org, model := seedChatDependenciesWithProvider(t, db, "openai", openAIURL) + server := newActiveTestServer(t, db, ps, func(cfg *chatd.Config) { + cfg.Logger = sink.Logger() + }) + + chat := createChatThroughServer(ctx, t, db, server, org.ID, user.ID, model.ID, "hello") + failed := waitForChatStatus(ctx, t, db, chat.ID, database.ChatStatusError) + require.True(t, failed.LastError.Valid) + + isGenerationFailure := func(e slog.SinkEntry) bool { + return e.Level == slog.LevelWarn && e.Message == "chat generation failed" + } + var entry slog.SinkEntry + testutil.Eventually(ctx, t, func(context.Context) bool { + entries := sink.Entries(isGenerationFailure) + if len(entries) == 0 { + return false + } + entry = entries[0] + return true + }, testutil.IntervalFast) + + chatID, ok := sinkFieldValue(entry.Fields, "chat_id") + require.True(t, ok, "chat_id field present") + require.Equal(t, chat.ID, chatID) + + provider, ok := sinkFieldValue(entry.Fields, "provider") + require.True(t, ok, "provider field present") + require.Equal(t, "openai", provider) + + statusCode, ok := sinkFieldValue(entry.Fields, "status_code") + require.True(t, ok, "status_code field present") + require.Equal(t, http.StatusBadRequest, statusCode) + + // The unsanitized cause must be logged so administrators can see the + // underlying provider reason, even though the persisted user-facing + // message omits it. + errValue, ok := sinkFieldValue(entry.Fields, "error") + require.True(t, ok, "error field present") + require.Contains(t, fmt.Sprintf("%v", errValue), providerErrMessage) + require.NotContains(t, chatLastErrorMessage(failed.LastError), providerErrMessage) +} + func TestProposeChatTitle_DebugRun(t *testing.T) { t.Parallel() diff --git a/coderd/x/chatd/generation.go b/coderd/x/chatd/generation.go index 47b17c8e45..43b255262e 100644 --- a/coderd/x/chatd/generation.go +++ b/coderd/x/chatd/generation.go @@ -13,6 +13,7 @@ import ( "github.com/sqlc-dev/pqtype" "golang.org/x/xerrors" + "cdr.dev/slog/v3" "github.com/coder/coder/v2/coderd/database" "github.com/coder/coder/v2/coderd/x/chatd/chatdebug" "github.com/coder/coder/v2/coderd/x/chatd/chaterror" @@ -1017,6 +1018,20 @@ func (s *taskStarter) finishGenerationError( cause error, attemptFence generationAttemptFence, ) error { + classified := chaterror.Classify(cause) + // Log the unsanitized cause before persisting so administrators can + // diagnose the failure even when the classified user-facing message + // omits the underlying reason, and even if the persist below fails. + s.opts.Logger.Warn(ctx, "chat generation failed", + slog.F("chat_id", input.ChatID), + slog.F("worker_id", input.WorkerID), + slog.F("generation_attempt", input.GenerationAttempt), + slog.F("error_kind", classified.Kind), + slog.F("provider", classified.Provider), + slog.F("status_code", classified.StatusCode), + slog.F("retryable", classified.Retryable), + slog.Error(cause), + ) lastError, message := generationLastError(cause) var committed database.Chat err := machine.Update(ctx, func(tx *chatstate.Tx, store database.Store) error {