opensource/coder
3
0
Fork 0
mirror of https://github.com/coder/coder.git synced 2026-09-24 15:04:27 +08:00
Code Issues Packages Projects Releases Wiki Activity

feat(coderd): wire debug logging into chat lifecycle (#23917)

Browse Source
This commit is contained in:
Thomas Kosiewski
2026-04-20 12:27:16 +02:00
committed by GitHub
parent fc2493780f
commit df7e838c21
22 changed files with 2426 additions and 177 deletions
Download Patch File Download Diff File Expand all files Collapse all files
coderd/database/dbauthz/dbauthz.go
+3 -3
View File
@@ -1871,15 +1871,15 @@ func (q *querier) DeleteChatDebugDataAfterMessageID(ctx context.Context, arg dat
return q.db.DeleteChatDebugDataAfterMessageID(ctx, arg)
}
func (q *querier) DeleteChatDebugDataByChatID(ctx context.Context, chatID uuid.UUID) (int64, error) {
chat, err := q.db.GetChatByID(ctx, chatID)
func (q *querier) DeleteChatDebugDataByChatID(ctx context.Context, arg database.DeleteChatDebugDataByChatIDParams) (int64, error) {
chat, err := q.db.GetChatByID(ctx, arg.ChatID)
if err != nil {
return 0, err
}
if err := q.authorizeContext(ctx, policy.ActionUpdate, chat); err != nil {
return 0, err
}
return q.db.DeleteChatDebugDataByChatID(ctx, chatID)
return q.db.DeleteChatDebugDataByChatID(ctx, arg)
}
func (q *querier) DeleteChatModelConfigByID(ctx context.Context, id uuid.UUID) error {
coderd/database/dbauthz/dbauthz_test.go
+4 -3
View File
@@ -463,16 +463,17 @@ func (s *MethodTestSuite) TestChats() {
}))
s.Run("DeleteChatDebugDataAfterMessageID", s.Mocked(func(dbm *dbmock.MockStore, faker *gofakeit.Faker, check *expects) {
chat := testutil.Fake(s.T(), faker, database.Chat{})
arg := database.DeleteChatDebugDataAfterMessageIDParams{ChatID: chat.ID, MessageID: 123}
arg := database.DeleteChatDebugDataAfterMessageIDParams{ChatID: chat.ID, StartedBefore: dbtime.Now(), MessageID: 123}
dbm.EXPECT().GetChatByID(gomock.Any(), chat.ID).Return(chat, nil).AnyTimes()
dbm.EXPECT().DeleteChatDebugDataAfterMessageID(gomock.Any(), arg).Return(int64(1), nil).AnyTimes()
check.Args(arg).Asserts(chat, policy.ActionUpdate).Returns(int64(1))
}))
s.Run("DeleteChatDebugDataByChatID", s.Mocked(func(dbm *dbmock.MockStore, faker *gofakeit.Faker, check *expects) {
chat := testutil.Fake(s.T(), faker, database.Chat{})
arg := database.DeleteChatDebugDataByChatIDParams{ChatID: chat.ID, StartedBefore: dbtime.Now()}
dbm.EXPECT().GetChatByID(gomock.Any(), chat.ID).Return(chat, nil).AnyTimes()
dbm.EXPECT().DeleteChatDebugDataByChatID(gomock.Any(), chat.ID).Return(int64(1), nil).AnyTimes()
check.Args(chat.ID).Asserts(chat, policy.ActionUpdate).Returns(int64(1))
dbm.EXPECT().DeleteChatDebugDataByChatID(gomock.Any(), arg).Return(int64(1), nil).AnyTimes()
check.Args(arg).Asserts(chat, policy.ActionUpdate).Returns(int64(1))
}))
s.Run("FinalizeStaleChatDebugRows", s.Mocked(func(dbm *dbmock.MockStore, _ *gofakeit.Faker, check *expects) {
now := dbtime.Now()
coderd/database/dbmetrics/querymetrics.go
+1 -1
View File
@@ -424,7 +424,7 @@ func (m queryMetricsStore) DeleteChatDebugDataAfterMessageID(ctx context.Context
return r0, r1
}
func (m queryMetricsStore) DeleteChatDebugDataByChatID(ctx context.Context, chatID uuid.UUID) (int64, error) {
func (m queryMetricsStore) DeleteChatDebugDataByChatID(ctx context.Context, chatID database.DeleteChatDebugDataByChatIDParams) (int64, error) {
start := time.Now()
r0, r1 := m.s.DeleteChatDebugDataByChatID(ctx, chatID)
m.queryLatencies.WithLabelValues("DeleteChatDebugDataByChatID").Observe(time.Since(start).Seconds())
coderd/database/dbmock/dbmock.go
+4 -4
View File
@@ -687,18 +687,18 @@ func (mr *MockStoreMockRecorder) DeleteChatDebugDataAfterMessageID(ctx, arg any)
}
// DeleteChatDebugDataByChatID mocks base method.
func (m *MockStore) DeleteChatDebugDataByChatID(ctx context.Context, chatID uuid.UUID) (int64, error) {
func (m *MockStore) DeleteChatDebugDataByChatID(ctx context.Context, arg database.DeleteChatDebugDataByChatIDParams) (int64, error) {
m.ctrl.T.Helper()
ret := m.ctrl.Call(m, "DeleteChatDebugDataByChatID", ctx, chatID)
ret := m.ctrl.Call(m, "DeleteChatDebugDataByChatID", ctx, arg)
ret0, _ := ret[0].(int64)
ret1, _ := ret[1].(error)
return ret0, ret1
}
// DeleteChatDebugDataByChatID indicates an expected call of DeleteChatDebugDataByChatID.
func (mr *MockStoreMockRecorder) DeleteChatDebugDataByChatID(ctx, chatID any) *gomock.Call {
func (mr *MockStoreMockRecorder) DeleteChatDebugDataByChatID(ctx, arg any) *gomock.Call {
mr.mock.ctrl.T.Helper()
return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "DeleteChatDebugDataByChatID", reflect.TypeOf((*MockStore)(nil).DeleteChatDebugDataByChatID), ctx, chatID)
return mr.mock.ctrl.RecordCallWithMethodType(mr.mock, "DeleteChatDebugDataByChatID", reflect.TypeOf((*MockStore)(nil).DeleteChatDebugDataByChatID), ctx, arg)
}
// DeleteChatModelConfigByID mocks base method.
coderd/database/querier.go
+9 -1
View File
@@ -102,8 +102,16 @@ type sqlcQuerier interface {
// be recreated.
DeleteAllWebpushSubscriptions(ctx context.Context) error
DeleteApplicationConnectAPIKeysByUserID(ctx context.Context, userID uuid.UUID) error
// Deletes debug runs (and their cascaded steps) whose message IDs
// exceed the cutoff. The started_before bound prevents retried
// cleanup from deleting runs created by a replacement turn that
// raced ahead of the retry window.
DeleteChatDebugDataAfterMessageID(ctx context.Context, arg DeleteChatDebugDataAfterMessageIDParams) (int64, error)
DeleteChatDebugDataByChatID(ctx context.Context, chatID uuid.UUID) (int64, error)
// The started_before bound prevents retried cleanup from deleting
// runs created by a replacement turn that races ahead of the retry
// window (for example, after an unarchive races with a pending
// archive-cleanup retry).
DeleteChatDebugDataByChatID(ctx context.Context, arg DeleteChatDebugDataByChatIDParams) (int64, error)
DeleteChatModelConfigByID(ctx context.Context, id uuid.UUID) error
DeleteChatProviderByID(ctx context.Context, id uuid.UUID) error
DeleteChatQueuedMessage(ctx context.Context, arg DeleteChatQueuedMessageParams) error
coderd/database/querier_test.go
+215 -4
View File
@@ -11524,8 +11524,9 @@ func TestDeleteChatDebugDataAfterMessageIDIncludesTriggeredRuns(t *testing.T) {
require.NoError(t, err)
deletedRows, err := store.DeleteChatDebugDataAfterMessageID(ctx, database.DeleteChatDebugDataAfterMessageIDParams{
ChatID: chat.ID,
MessageID: cutoff,
ChatID: chat.ID,
MessageID: cutoff,
StartedBefore: time.Now().Add(time.Minute),
})
require.NoError(t, err)
require.EqualValues(t, 3, deletedRows)
@@ -12406,8 +12407,9 @@ func TestDeleteChatDebugDataAfterMessageIDNullMessagesSurvive(t *testing.T) {
// Delete with an arbitrary cutoff. The run and its step should
// survive because NULL > cutoff evaluates to NULL, not TRUE.
deletedRows, err := store.DeleteChatDebugDataAfterMessageID(ctx, database.DeleteChatDebugDataAfterMessageIDParams{
ChatID: chat.ID,
MessageID: 1,
ChatID: chat.ID,
MessageID: 1,
StartedBefore: time.Now().Add(time.Minute),
})
require.NoError(t, err)
require.EqualValues(t, 0, deletedRows, "rows with NULL message IDs must not be deleted")
@@ -12424,6 +12426,215 @@ func TestDeleteChatDebugDataAfterMessageIDNullMessagesSurvive(t *testing.T) {
require.Equal(t, nullMsgStep.ID, remainingSteps[0].ID)
}
// TestDeleteChatDebugDataAfterMessageIDStartedBeforeFiltersNewerRuns
// verifies the started_before bound on DeleteChatDebugDataAfterMessageID.
// The bound exists so that retried cleanup (e.g. after edit or archive)
// cannot delete runs started by a replacement turn that races ahead of
// the retry window. Without this filter, a stale cleanup would wipe
// fresh debug rows.
func TestDeleteChatDebugDataAfterMessageIDStartedBeforeFiltersNewerRuns(t *testing.T) {
t.Parallel()
store, _ := dbtestutil.NewDB(t)
ctx := testutil.Context(t, testutil.WaitMedium)
org := dbgen.Organization(t, store, database.Organization{})
user := dbgen.User(t, store, database.User{})
providerName := "openai"
modelName := "debug-model-started-before-" + uuid.NewString()
_, err := store.InsertChatProvider(ctx, database.InsertChatProviderParams{
Provider: providerName,
DisplayName: "Debug Provider",
APIKey: "test-key",
Enabled: true,
CentralApiKeyEnabled: true,
})
require.NoError(t, err)
modelCfg, err := store.InsertChatModelConfig(ctx, database.InsertChatModelConfigParams{
Provider: providerName,
Model: modelName,
DisplayName: "Debug Model",
CreatedBy: uuid.NullUUID{UUID: user.ID, Valid: true},
UpdatedBy: uuid.NullUUID{UUID: user.ID, Valid: true},
Enabled: true,
IsDefault: true,
ContextLimit: 128000,
CompressionThreshold: 80,
Options: json.RawMessage(`{}`),
})
require.NoError(t, err)
chat, err := store.InsertChat(ctx, database.InsertChatParams{
OrganizationID: org.ID,
Status: database.ChatStatusWaiting,
ClientType: database.ChatClientTypeUi,
OwnerID: user.ID,
LastModelConfigID: modelCfg.ID,
Title: "chat-debug-started-before-" + uuid.NewString(),
})
require.NoError(t, err)
const cutoff int64 = 50
// oldRun started an hour ago: must be deleted because it started
// before the bound.
oldStartedAt := time.Now().Add(-1 * time.Hour).UTC().
Truncate(time.Microsecond)
oldRun, err := store.InsertChatDebugRun(ctx, database.InsertChatDebugRunParams{
ChatID: chat.ID,
ModelConfigID: uuid.NullUUID{UUID: modelCfg.ID, Valid: true},
TriggerMessageID: sql.NullInt64{Int64: cutoff + 1, Valid: true},
HistoryTipMessageID: sql.NullInt64{Int64: cutoff + 1, Valid: true},
Kind: "chat_turn",
Status: "in_progress",
Provider: sql.NullString{String: providerName, Valid: true},
Model: sql.NullString{String: modelName, Valid: true},
StartedAt: sql.NullTime{Time: oldStartedAt, Valid: true},
UpdatedAt: sql.NullTime{Time: oldStartedAt, Valid: true},
})
require.NoError(t, err)
// Bound sits between the two runs. Any run whose started_at is at
// or after this instant must survive.
cutoffTime := time.Now().Add(-30 * time.Minute).UTC().
Truncate(time.Microsecond)
// newRun started after cutoffTime with identical message_id values
// that would otherwise match the delete predicate. It must survive
// because started_before excludes it.
newStartedAt := time.Now().UTC().Truncate(time.Microsecond)
newRun, err := store.InsertChatDebugRun(ctx, database.InsertChatDebugRunParams{
ChatID: chat.ID,
ModelConfigID: uuid.NullUUID{UUID: modelCfg.ID, Valid: true},
TriggerMessageID: sql.NullInt64{Int64: cutoff + 1, Valid: true},
HistoryTipMessageID: sql.NullInt64{Int64: cutoff + 1, Valid: true},
Kind: "chat_turn",
Status: "in_progress",
Provider: sql.NullString{String: providerName, Valid: true},
Model: sql.NullString{String: modelName, Valid: true},
StartedAt: sql.NullTime{Time: newStartedAt, Valid: true},
UpdatedAt: sql.NullTime{Time: newStartedAt, Valid: true},
})
require.NoError(t, err)
deletedRows, err := store.DeleteChatDebugDataAfterMessageID(ctx, database.DeleteChatDebugDataAfterMessageIDParams{
ChatID: chat.ID,
MessageID: cutoff,
StartedBefore: cutoffTime,
})
require.NoError(t, err)
require.EqualValues(t, 1, deletedRows,
"only the pre-cutoff run should be deleted")
// oldRun must be gone.
_, err = store.GetChatDebugRunByID(ctx, oldRun.ID)
require.ErrorIs(t, err, sql.ErrNoRows)
// newRun must survive the retry window.
remaining, err := store.GetChatDebugRunByID(ctx, newRun.ID)
require.NoError(t, err)
require.Equal(t, newRun.ID, remaining.ID)
}
// TestDeleteChatDebugDataByChatIDStartedBeforeFiltersNewerRuns verifies
// the started_before bound on DeleteChatDebugDataByChatID. Archive
// cleanup retries rely on this bound to avoid deleting runs created
// by a replacement turn that starts after an unarchive races ahead of
// the retry window.
func TestDeleteChatDebugDataByChatIDStartedBeforeFiltersNewerRuns(t *testing.T) {
t.Parallel()
store, _ := dbtestutil.NewDB(t)
ctx := testutil.Context(t, testutil.WaitMedium)
org := dbgen.Organization(t, store, database.Organization{})
user := dbgen.User(t, store, database.User{})
providerName := "openai"
modelName := "debug-model-by-chat-started-before-" + uuid.NewString()
_, err := store.InsertChatProvider(ctx, database.InsertChatProviderParams{
Provider: providerName,
DisplayName: "Debug Provider",
APIKey: "test-key",
Enabled: true,
CentralApiKeyEnabled: true,
})
require.NoError(t, err)
modelCfg, err := store.InsertChatModelConfig(ctx, database.InsertChatModelConfigParams{
Provider: providerName,
Model: modelName,
DisplayName: "Debug Model",
CreatedBy: uuid.NullUUID{UUID: user.ID, Valid: true},
UpdatedBy: uuid.NullUUID{UUID: user.ID, Valid: true},
Enabled: true,
IsDefault: true,
ContextLimit: 128000,
CompressionThreshold: 80,
Options: json.RawMessage(`{}`),
})
require.NoError(t, err)
chat, err := store.InsertChat(ctx, database.InsertChatParams{
OrganizationID: org.ID,
Status: database.ChatStatusWaiting,
ClientType: database.ChatClientTypeUi,
OwnerID: user.ID,
LastModelConfigID: modelCfg.ID,
Title: "chat-debug-by-chat-" + uuid.NewString(),
})
require.NoError(t, err)
oldStartedAt := time.Now().Add(-1 * time.Hour).UTC().
Truncate(time.Microsecond)
oldRun, err := store.InsertChatDebugRun(ctx, database.InsertChatDebugRunParams{
ChatID: chat.ID,
ModelConfigID: uuid.NullUUID{UUID: modelCfg.ID, Valid: true},
Kind: "chat_turn",
Status: "in_progress",
Provider: sql.NullString{String: providerName, Valid: true},
Model: sql.NullString{String: modelName, Valid: true},
StartedAt: sql.NullTime{Time: oldStartedAt, Valid: true},
UpdatedAt: sql.NullTime{Time: oldStartedAt, Valid: true},
})
require.NoError(t, err)
cutoffTime := time.Now().Add(-30 * time.Minute).UTC().
Truncate(time.Microsecond)
newStartedAt := time.Now().UTC().Truncate(time.Microsecond)
newRun, err := store.InsertChatDebugRun(ctx, database.InsertChatDebugRunParams{
ChatID: chat.ID,
ModelConfigID: uuid.NullUUID{UUID: modelCfg.ID, Valid: true},
Kind: "chat_turn",
Status: "in_progress",
Provider: sql.NullString{String: providerName, Valid: true},
Model: sql.NullString{String: modelName, Valid: true},
StartedAt: sql.NullTime{Time: newStartedAt, Valid: true},
UpdatedAt: sql.NullTime{Time: newStartedAt, Valid: true},
})
require.NoError(t, err)
deletedRows, err := store.DeleteChatDebugDataByChatID(ctx, database.DeleteChatDebugDataByChatIDParams{
ChatID: chat.ID,
StartedBefore: cutoffTime,
})
require.NoError(t, err)
require.EqualValues(t, 1, deletedRows,
"only the pre-cutoff run should be deleted")
_, err = store.GetChatDebugRunByID(ctx, oldRun.ID)
require.ErrorIs(t, err, sql.ErrNoRows)
remaining, err := store.GetChatDebugRunByID(ctx, newRun.ID)
require.NoError(t, err)
require.Equal(t, newRun.ID, remaining.ID)
}
func TestChatHasUnread(t *testing.T) {
t.Parallel()
coderd/database/queries.sql.go
+28 -9
View File
@@ -2905,19 +2905,23 @@ WITH affected_runs AS (
SELECT DISTINCT run.id
FROM chat_debug_runs run
WHERE run.chat_id = $1::uuid
AND run.started_at < $2::timestamptz
AND (
run.history_tip_message_id > $2::bigint
OR run.trigger_message_id > $2::bigint
run.history_tip_message_id > $3::bigint
OR run.trigger_message_id > $3::bigint
)
UNION
SELECT DISTINCT step.run_id AS id
FROM chat_debug_steps step
JOIN chat_debug_runs run ON run.id = step.run_id
AND run.chat_id = step.chat_id
WHERE step.chat_id = $1::uuid
AND run.started_at < $2::timestamptz
AND (
step.assistant_message_id > $2::bigint
OR step.history_tip_message_id > $2::bigint
step.assistant_message_id > $3::bigint
OR step.history_tip_message_id > $3::bigint
)
)
DELETE FROM chat_debug_runs
@@ -2926,12 +2930,17 @@ WHERE chat_id = $1::uuid
`
type DeleteChatDebugDataAfterMessageIDParams struct {
ChatID uuid.UUID `db:"chat_id" json:"chat_id"`
MessageID int64 `db:"message_id" json:"message_id"`
ChatID uuid.UUID `db:"chat_id" json:"chat_id"`
StartedBefore time.Time `db:"started_before" json:"started_before"`
MessageID int64 `db:"message_id" json:"message_id"`
}
// Deletes debug runs (and their cascaded steps) whose message IDs
// exceed the cutoff. The started_before bound prevents retried
// cleanup from deleting runs created by a replacement turn that
// raced ahead of the retry window.
func (q *sqlQuerier) DeleteChatDebugDataAfterMessageID(ctx context.Context, arg DeleteChatDebugDataAfterMessageIDParams) (int64, error) {
result, err := q.db.ExecContext(ctx, deleteChatDebugDataAfterMessageID, arg.ChatID, arg.MessageID)
result, err := q.db.ExecContext(ctx, deleteChatDebugDataAfterMessageID, arg.ChatID, arg.StartedBefore, arg.MessageID)
if err != nil {
return 0, err
}
@@ -2941,10 +2950,20 @@ func (q *sqlQuerier) DeleteChatDebugDataAfterMessageID(ctx context.Context, arg
const deleteChatDebugDataByChatID = `-- name: DeleteChatDebugDataByChatID :execrows
DELETE FROM chat_debug_runs
WHERE chat_id = $1::uuid
AND started_at < $2::timestamptz
`
func (q *sqlQuerier) DeleteChatDebugDataByChatID(ctx context.Context, chatID uuid.UUID) (int64, error) {
result, err := q.db.ExecContext(ctx, deleteChatDebugDataByChatID, chatID)
type DeleteChatDebugDataByChatIDParams struct {
ChatID uuid.UUID `db:"chat_id" json:"chat_id"`
StartedBefore time.Time `db:"started_before" json:"started_before"`
}
// The started_before bound prevents retried cleanup from deleting
// runs created by a replacement turn that races ahead of the retry
// window (for example, after an unarchive races with a pending
// archive-cleanup retry).
func (q *sqlQuerier) DeleteChatDebugDataByChatID(ctx context.Context, arg DeleteChatDebugDataByChatIDParams) (int64, error) {
result, err := q.db.ExecContext(ctx, deleteChatDebugDataByChatID, arg.ChatID, arg.StartedBefore)
if err != nil {
return 0, err
}
coderd/database/queries/chatdebug.sql
+14 -1
View File
@@ -206,14 +206,24 @@ WHERE run_id = @run_id::uuid
ORDER BY step_number ASC, started_at ASC;
-- name: DeleteChatDebugDataByChatID :execrows
-- The started_before bound prevents retried cleanup from deleting
-- runs created by a replacement turn that races ahead of the retry
-- window (for example, after an unarchive races with a pending
-- archive-cleanup retry).
DELETE FROM chat_debug_runs
WHERE chat_id = @chat_id::uuid;
WHERE chat_id = @chat_id::uuid
AND started_at < @started_before::timestamptz;
-- name: DeleteChatDebugDataAfterMessageID :execrows
-- Deletes debug runs (and their cascaded steps) whose message IDs
-- exceed the cutoff. The started_before bound prevents retried
-- cleanup from deleting runs created by a replacement turn that
-- raced ahead of the retry window.
WITH affected_runs AS (
SELECT DISTINCT run.id
FROM chat_debug_runs run
WHERE run.chat_id = @chat_id::uuid
AND run.started_at < @started_before::timestamptz
AND (
run.history_tip_message_id > @message_id::bigint
OR run.trigger_message_id > @message_id::bigint
@@ -223,7 +233,10 @@ WITH affected_runs AS (
SELECT DISTINCT step.run_id AS id
FROM chat_debug_steps step
JOIN chat_debug_runs run ON run.id = step.run_id
AND run.chat_id = step.chat_id
WHERE step.chat_id = @chat_id::uuid
AND run.started_at < @started_before::timestamptz
AND (
step.assistant_message_id > @message_id::bigint
OR step.history_tip_message_id > @message_id::bigint