diff --git a/apps/backend/internal/agent/runtime/agentctl/launcher/launcher.go b/apps/backend/internal/agent/runtime/agentctl/launcher/launcher.go index 7f58f3d4fe..06400a12b9 100644 --- a/apps/backend/internal/agent/runtime/agentctl/launcher/launcher.go +++ b/apps/backend/internal/agent/runtime/agentctl/launcher/launcher.go @@ -518,21 +518,94 @@ func (l *Launcher) pipeOutput(name string, scanner *bufio.Scanner) { } } -// childLogLevel extracts the level token from a line emitted by the agentctl -// child's console-format zap logger: "\t\t\t", where -// LEVEL is capitalized and may be wrapped in ANSI color codes. It returns the -// uppercased level ("INFO"/"WARN"/…) or "" when the line does not match that -// shape. +// childLogLevel extracts a recognized level from the agentctl child's trusted +// structured log formats. It returns the uppercased level ("INFO"/"WARN"/…) +// or "" when the line does not match one of those formats. func childLogLevel(line string) string { // A well-formed console record is "\t\t\t", so the // level token must be bounded by at least a following caller field. Requiring // three segments rejects truncated lines (e.g. "\t") whose second // field is not actually a level, so they fall back to WARN. fields := strings.SplitN(line, "\t", 4) - if len(fields) < 3 { + if len(fields) >= 3 { + if level := recognizedChildLogLevel(stripANSI(fields[1])); level != "" { + return level + } + } + + if level := childSlogTextLevel(line); level != "" { + return level + } + + // slog.Default uses the standard log package's date/time prefix followed by + // the level and message, for example "2026/08/12 10:00:00 INFO message". + defaultFields := strings.Fields(line) + if len(defaultFields) < 3 { return "" } - level := strings.ToUpper(stripANSI(fields[1])) + if _, err := time.Parse("2006/01/02 15:04:05", defaultFields[0]+" "+defaultFields[1]); err != nil { + return "" + } + return recognizedChildLogLevel(stripANSI(defaultFields[2])) +} + +func childSlogTextLevel(line string) string { + fields, ok := splitSlogTextFields(line) + if !ok || len(fields) < 3 || !strings.HasPrefix(fields[0], "time=") || + !strings.HasPrefix(fields[1], "level=") { + return "" + } + for _, field := range fields[2:] { + if strings.HasPrefix(field, "msg=") { + return recognizedChildLogLevel(stripANSI(strings.TrimPrefix(fields[1], "level="))) + } + } + return "" +} + +func splitSlogTextFields(line string) ([]string, bool) { + fields := make([]string, 0, 4) + start := -1 + inQuotes := false + escaped := false + for i := 0; i < len(line); i++ { + ch := line[i] + if start < 0 { + if ch == ' ' || ch == '\t' { + continue + } + start = i + } + if inQuotes { + switch { + case escaped: + escaped = false + case ch == '\\': + escaped = true + case ch == '"': + inQuotes = false + } + continue + } + switch ch { + case '"': + inQuotes = true + case ' ', '\t': + fields = append(fields, line[start:i]) + start = -1 + } + } + if inQuotes || escaped { + return nil, false + } + if start >= 0 { + fields = append(fields, line[start:]) + } + return fields, true +} + +func recognizedChildLogLevel(level string) string { + level = strings.ToUpper(level) switch level { case "DEBUG", "INFO", "WARN", "ERROR", "FATAL", "PANIC", "DPANIC": return level diff --git a/apps/backend/internal/agent/runtime/agentctl/launcher/launcher_loglevel_test.go b/apps/backend/internal/agent/runtime/agentctl/launcher/launcher_loglevel_test.go index abec2d454e..f09f2fb7b6 100644 --- a/apps/backend/internal/agent/runtime/agentctl/launcher/launcher_loglevel_test.go +++ b/apps/backend/internal/agent/runtime/agentctl/launcher/launcher_loglevel_test.go @@ -1,6 +1,12 @@ package launcher -import "testing" +import ( + "bytes" + stdlog "log" + "log/slog" + "strings" + "testing" +) func TestChildLogLevel(t *testing.T) { tests := []struct { @@ -78,6 +84,98 @@ func TestChildLogLevel(t *testing.T) { } } +func TestChildLogLevelSlogTextRecords(t *testing.T) { + tests := []struct { + name string + level string + want string + }{ + {name: "debug", level: "DEBUG", want: "DEBUG"}, + {name: "info", level: "INFO", want: "INFO"}, + {name: "warn", level: "WARN", want: "WARN"}, + {name: "error", level: "ERROR", want: "ERROR"}, + } + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + line := "time=2026-08-12T10:00:00.000Z level=" + tt.level + + " source=main.go:97 msg=\"agentctl record\"" + if got := childLogLevel(line); got != tt.want { + t.Fatalf("childLogLevel(%q) = %q, want %q", line, got, tt.want) + } + }) + } +} + +func TestChildLogLevelSlogDefaultRecords(t *testing.T) { + var output bytes.Buffer + originalWriter := stdlog.Writer() + originalFlags := stdlog.Flags() + stdlog.SetOutput(&output) + stdlog.SetFlags(stdlog.LstdFlags) + t.Cleanup(func() { + stdlog.SetOutput(originalWriter) + stdlog.SetFlags(originalFlags) + }) + + tests := []struct { + name string + write func() + want string + }{ + {name: "info", write: func() { slog.Default().Info("agentctl record", "component", "acp-conn") }, want: "INFO"}, + {name: "warn", write: func() { slog.Default().Warn("agentctl record", "component", "acp-conn") }, want: "WARN"}, + {name: "error", write: func() { slog.Default().Error("agentctl record", "component", "acp-conn") }, want: "ERROR"}, + } + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + output.Reset() + tt.write() + line := strings.TrimSpace(output.String()) + if line == "" { + t.Fatal("slog.Default produced no output") + } + if got := childLogLevel(line); got != tt.want { + t.Fatalf("childLogLevel(%q) = %q, want %q", line, got, tt.want) + } + }) + } +} + +func TestChildLogLevelRejectsMalformedSlogTextRecords(t *testing.T) { + tests := []struct { + name string + line string + }{ + { + name: "missing time anchor", + line: "level=INFO source=main.go:97 msg=\"agentctl record\"", + }, + { + name: "missing level anchor", + line: "time=2026-08-12T10:00:00.000Z msg=\"level=INFO\"", + }, + { + name: "missing message field", + line: "time=2026-08-12T10:00:00.000Z level=INFO source=main.go:97", + }, + { + name: "level anchor is not second field", + line: "time=2026-08-12T10:00:00.000Z source=main.go:97 level=INFO msg=\"record\"", + }, + { + name: "message-looking key is inside a quoted attribute", + line: `time=2026-08-12T10:00:00.000Z level=INFO attr="foo msg=bar" component=acp-conn`, + }, + } + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + if got := childLogLevel(tt.line); got != "" { + t.Fatalf("childLogLevel(%q) = %q, want no recognized level", tt.line, got) + } + }) + } +} + func TestStripANSI(t *testing.T) { tests := []struct { name string diff --git a/apps/backend/internal/mcp/handlers/task_plan_handlers_test.go b/apps/backend/internal/mcp/handlers/task_plan_handlers_test.go index acb997efba..bc85ed8661 100644 --- a/apps/backend/internal/mcp/handlers/task_plan_handlers_test.go +++ b/apps/backend/internal/mcp/handlers/task_plan_handlers_test.go @@ -4,6 +4,7 @@ import ( "context" "encoding/json" "path/filepath" + "strings" "testing" "time" @@ -13,6 +14,7 @@ import ( "github.com/kandev/kandev/internal/events/bus" "github.com/kandev/kandev/internal/task/models" "github.com/kandev/kandev/internal/task/repository" + sqliterepo "github.com/kandev/kandev/internal/task/repository/sqlite" "github.com/kandev/kandev/internal/task/service" v1 "github.com/kandev/kandev/pkg/api/v1" ws "github.com/kandev/kandev/pkg/websocket" @@ -36,6 +38,11 @@ const ( // newMCPPlanTestHandlers builds Handlers with only the plan service wired — // the plan actions touch nothing else. func newMCPPlanTestHandlers(t *testing.T) *Handlers { + h, _ := newMCPPlanTestHandlersWithRepo(t) + return h +} + +func newMCPPlanTestHandlersWithRepo(t *testing.T) (*Handlers, *sqliterepo.Repository) { t.Helper() dbConn, err := db.OpenSQLite(filepath.Join(t.TempDir(), "test.db")) if err != nil { @@ -91,7 +98,7 @@ func newMCPPlanTestHandlers(t *testing.T) *Handlers { } } - return &Handlers{planService: service.NewPlanService(repo, eventBus, log), logger: log} + return &Handlers{planService: service.NewPlanService(repo, eventBus, log), logger: log}, repo } func mcpPlanMsg(t *testing.T, action string, payload string) *ws.Message { @@ -202,6 +209,47 @@ func TestMCPPlanActionsReportMissingPlan(t *testing.T) { }) } +func TestMCPPlanCreateReportsMissingTask(t *testing.T) { + h := newMCPPlanTestHandlers(t) + out, err := h.handleCreateTaskPlan(context.Background(), mcpPlanMsg(t, ws.ActionMCPCreateTaskPlan, + `{"task_id":"task-plan-mcp-missing","content":"body"}`)) + assertMCPPlanError(t, out, err, ws.ErrorCodeNotFound, "Task not found") + if strings.Contains(strings.ToLower(string(out.Payload)), "constraint") { + t.Fatalf("error payload leaks storage details: %s", out.Payload) + } +} + +func TestMCPPlanUpdateReportsMissingTask(t *testing.T) { + h, repo := newMCPPlanTestHandlersWithRepo(t) + ctx := context.Background() + if _, err := h.planService.CreatePlan(ctx, service.CreatePlanRequest{ + TaskID: mcpPlanTaskID, Content: "initial", CreatedBy: "agent", + }); err != nil { + t.Fatalf("CreatePlan: %v", err) + } + h.planService = service.NewPlanService(&missingTaskOnPlanWriteRepo{Repository: repo}, nil, h.logger) + + out, err := h.handleUpdateTaskPlan(ctx, mcpPlanMsg(t, ws.ActionMCPUpdateTaskPlan, + `{"task_id":"`+mcpPlanTaskID+`","content":"updated"}`)) + assertMCPPlanError(t, out, err, ws.ErrorCodeNotFound, "Task not found") + if strings.Contains(strings.ToLower(string(out.Payload)), "constraint") { + t.Fatalf("error payload leaks storage details: %s", out.Payload) + } +} + +type missingTaskOnPlanWriteRepo struct { + *sqliterepo.Repository +} + +func (r *missingTaskOnPlanWriteRepo) WritePlanRevision( + context.Context, + *models.TaskPlan, + *models.TaskPlanRevision, + *string, +) error { + return repository.ErrTaskNotFound +} + // TestMCPPlanActionsSucceed pins the success payloads across a full CRUD round // trip. Two replies deliberately differ from the browser surface and must not // be "unified" away: get returns {} rather than null for a task with no plan, diff --git a/apps/backend/internal/orchestrator/reconcile_liveness.go b/apps/backend/internal/orchestrator/reconcile_liveness.go index 3952991f0f..bd79dc0098 100644 --- a/apps/backend/internal/orchestrator/reconcile_liveness.go +++ b/apps/backend/internal/orchestrator/reconcile_liveness.go @@ -186,14 +186,14 @@ func (s *Service) repairDeadRowLiveness(ctx context.Context, running *models.Exe } else { err = s.repo.RepairExecutorRunningDead(ctx, running.SessionID) } - if err != nil && !errors.Is(err, models.ErrExecutorRunningNotFound) { + if errors.Is(err, models.ErrExecutorRunningNotFound) || errors.Is(err, models.ErrExecutionRotated) { + return nil + } + if err != nil { s.logger.Warn("failed to repair executor row liveness during reconciliation", zap.String("session_id", running.SessionID), zap.Error(err)) } - if errors.Is(err, models.ErrExecutorRunningNotFound) || errors.Is(err, models.ErrExecutionRotated) { - return nil - } return err } diff --git a/apps/backend/internal/orchestrator/reconcile_liveness_test.go b/apps/backend/internal/orchestrator/reconcile_liveness_test.go index cbcf3a5590..45afdaccb5 100644 --- a/apps/backend/internal/orchestrator/reconcile_liveness_test.go +++ b/apps/backend/internal/orchestrator/reconcile_liveness_test.go @@ -13,6 +13,7 @@ import ( "github.com/kandev/kandev/internal/common/logger" "github.com/kandev/kandev/internal/task/models" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "go.uber.org/zap/zaptest/observer" ) @@ -135,6 +136,71 @@ func TestStopRuntimeForStartupCleanupPreservesUnknownRowsWithoutHandle(t *testin } } +func TestRepairDeadRowLivenessLogSeverity(t *testing.T) { + t.Run("rotated execution is expected", func(t *testing.T) { + repo := setupTestRepo(t) + ctx := context.Background() + seedSession(t, repo, "task-rotated", "session-rotated", "") + if err := repo.UpsertExecutorRunning(ctx, &models.ExecutorRunning{ + ID: "session-rotated", SessionID: "session-rotated", TaskID: "task-rotated", + AgentExecutionID: "new-execution", Status: models.ExecutorRunningStatusRunning, + }); err != nil { + t.Fatalf("UpsertExecutorRunning: %v", err) + } + current, err := repo.GetExecutorRunningBySessionID(ctx, "session-rotated") + if err != nil { + t.Fatalf("GetExecutorRunningBySessionID: %v", err) + } + stale := *current + stale.AgentExecutionID = "old-execution" + + service := createTestServiceWithAgent(repo, newMockStepGetter(), newMockTaskRepo(), &mockAgentManager{}) + core, logs := observer.New(zapcore.DebugLevel) + log, err := logger.NewFromZap(zap.New(core)) + if err != nil { + t.Fatalf("NewFromZap: %v", err) + } + service.logger = log + + if err := service.repairDeadRowLiveness(ctx, &stale); err != nil { + t.Fatalf("repairDeadRowLiveness: %v", err) + } + if entries := logs.FilterLevelExact(zapcore.WarnLevel).All(); len(entries) != 0 { + t.Fatalf("rotated repair warning count = %d, want 0", len(entries)) + } + current, err = repo.GetExecutorRunningBySessionID(ctx, "session-rotated") + if err != nil { + t.Fatalf("GetExecutorRunningBySessionID after repair: %v", err) + } + if current.AgentExecutionID != "new-execution" || current.Status != models.ExecutorRunningStatusRunning { + t.Fatalf("rotated row = %+v, want newer running execution unchanged", current) + } + }) + + t.Run("unrelated repair error remains warning", func(t *testing.T) { + repo := setupTestRepo(t) + service := createTestServiceWithAgent(repo, newMockStepGetter(), newMockTaskRepo(), &mockAgentManager{}) + core, logs := observer.New(zapcore.DebugLevel) + log, err := logger.NewFromZap(zap.New(core)) + if err != nil { + t.Fatalf("NewFromZap: %v", err) + } + service.logger = log + + err = service.repairDeadRowLiveness(context.Background(), &models.ExecutorRunning{}) + if err == nil { + t.Fatal("repairDeadRowLiveness returned nil for an invalid repair request") + } + entries := logs.FilterMessage("failed to repair executor row liveness during reconciliation").All() + if len(entries) != 1 { + t.Fatalf("unrelated repair warning count = %d, want 1", len(entries)) + } + if entries[0].Level != zapcore.WarnLevel { + t.Fatalf("unrelated repair log level = %s, want warn", entries[0].Level) + } + }) +} + func containsAll(value string, needles ...string) bool { for _, needle := range needles { if !strings.Contains(value, needle) { diff --git a/apps/backend/internal/task/handlers/task_plan_handlers_test.go b/apps/backend/internal/task/handlers/task_plan_handlers_test.go index 1cf33fb10d..a8ea8ba17c 100644 --- a/apps/backend/internal/task/handlers/task_plan_handlers_test.go +++ b/apps/backend/internal/task/handlers/task_plan_handlers_test.go @@ -4,6 +4,7 @@ import ( "context" "encoding/json" "path/filepath" + "strings" "testing" "time" @@ -13,6 +14,7 @@ import ( "github.com/kandev/kandev/internal/events/bus" "github.com/kandev/kandev/internal/task/models" "github.com/kandev/kandev/internal/task/repository" + sqliterepo "github.com/kandev/kandev/internal/task/repository/sqlite" "github.com/kandev/kandev/internal/task/service" v1 "github.com/kandev/kandev/pkg/api/v1" ws "github.com/kandev/kandev/pkg/websocket" @@ -36,6 +38,11 @@ const ( // newPlanTestHandlers builds TaskHandlers with only the plan service wired — // the plan actions touch nothing else. func newPlanTestHandlers(t *testing.T) *TaskHandlers { + h, _ := newPlanTestHandlersWithRepo(t) + return h +} + +func newPlanTestHandlersWithRepo(t *testing.T) (*TaskHandlers, *sqliterepo.Repository) { t.Helper() dbConn, err := db.OpenSQLite(filepath.Join(t.TempDir(), "test.db")) if err != nil { @@ -91,7 +98,7 @@ func newPlanTestHandlers(t *testing.T) *TaskHandlers { } } - return &TaskHandlers{planService: service.NewPlanService(repo, eventBus, log), logger: log} + return &TaskHandlers{planService: service.NewPlanService(repo, eventBus, log), logger: log}, repo } func planMsg(t *testing.T, action string, payload string) *ws.Message { @@ -186,6 +193,47 @@ func TestPlanWSActionsReportMissingPlan(t *testing.T) { }) } +func TestPlanWSCreateReportsMissingTask(t *testing.T) { + h := newPlanTestHandlers(t) + out, err := h.wsCreateTaskPlan(context.Background(), planMsg(t, ws.ActionTaskPlanCreate, + `{"task_id":"task-plan-ws-missing","content":"body"}`)) + assertPlanError(t, out, err, ws.ErrorCodeNotFound, "Task not found") + if strings.Contains(strings.ToLower(string(out.Payload)), "constraint") { + t.Fatalf("error payload leaks storage details: %s", out.Payload) + } +} + +func TestPlanWSUpdateReportsMissingTask(t *testing.T) { + h, repo := newPlanTestHandlersWithRepo(t) + ctx := context.Background() + if _, err := h.planService.CreatePlan(ctx, service.CreatePlanRequest{ + TaskID: planTaskID, Content: "initial", CreatedBy: "user", + }); err != nil { + t.Fatalf("CreatePlan: %v", err) + } + h.planService = service.NewPlanService(&missingTaskOnPlanWriteRepo{Repository: repo}, nil, h.logger) + + out, err := h.wsUpdateTaskPlan(ctx, planMsg(t, ws.ActionTaskPlanUpdate, + `{"task_id":"`+planTaskID+`","content":"updated"}`)) + assertPlanError(t, out, err, ws.ErrorCodeNotFound, "Task not found") + if strings.Contains(strings.ToLower(string(out.Payload)), "constraint") { + t.Fatalf("error payload leaks storage details: %s", out.Payload) + } +} + +type missingTaskOnPlanWriteRepo struct { + *sqliterepo.Repository +} + +func (r *missingTaskOnPlanWriteRepo) WritePlanRevision( + context.Context, + *models.TaskPlan, + *models.TaskPlanRevision, + *string, +) error { + return repository.ErrTaskNotFound +} + // TestPlanWSActionsSucceed pins the success payloads across a full CRUD round // trip, including the browser surface's null reply for a task with no plan and // its {"success":true} delete reply. diff --git a/apps/backend/internal/task/planws/errors.go b/apps/backend/internal/task/planws/errors.go index 33a331bb02..f886c778e5 100644 --- a/apps/backend/internal/task/planws/errors.go +++ b/apps/backend/internal/task/planws/errors.go @@ -13,6 +13,7 @@ package planws import ( "errors" + "github.com/kandev/kandev/internal/task/repository" "github.com/kandev/kandev/internal/task/service" ws "github.com/kandev/kandev/pkg/websocket" ) @@ -35,6 +36,7 @@ type mapping struct { // MCP tools already receive, so editing one now moves both surfaces together. var ( taskIDRequired = mapping{service.ErrTaskIDRequired, ws.ErrorCodeValidation, "task_id is required"} + taskNotFound = mapping{repository.ErrTaskNotFound, ws.ErrorCodeNotFound, "Task not found"} sessionIDRequired = mapping{service.ErrSessionIDRequired, ws.ErrorCodeValidation, "session_id is required"} sessionTaskMismatch = mapping{service.ErrSessionTaskMismatch, ws.ErrorCodeValidation, "Session does not belong to task"} planNotFound = mapping{service.ErrTaskPlanNotFound, ws.ErrorCodeNotFound, "Task plan not found"} @@ -46,6 +48,7 @@ var ( // plan or revision failure. allMappings = []mapping{ taskIDRequired, + taskNotFound, sessionIDRequired, sessionTaskMismatch, planNotFound, @@ -73,9 +76,11 @@ func errorResponse(msg *ws.Message, err error, fallback string, recognized []map // // ErrTaskPlanNotFound is deliberately absent: CreatePlan only returns it when // the plan vanishes between the write and the read-back, which is a server-side -// inconsistency rather than the caller naming a plan that does not exist. +// inconsistency rather than the caller naming a plan that does not exist. The +// repository's ErrTaskNotFound is different: it means the write target task +// did not exist and is safe to report as a not-found response. func CreateError(msg *ws.Message, err error) (*ws.Message, error) { - return errorResponse(msg, err, "Failed to create task plan: "+err.Error(), []mapping{taskIDRequired}) + return errorResponse(msg, err, "Failed to create task plan: "+err.Error(), []mapping{taskIDRequired, taskNotFound}) } // GetError maps a PlanService.GetPlan failure. The fallback omits err.Error() @@ -87,7 +92,7 @@ func GetError(msg *ws.Message, err error) (*ws.Message, error) { // UpdateError maps a PlanService.UpdatePlan failure. func UpdateError(msg *ws.Message, err error) (*ws.Message, error) { - return errorResponse(msg, err, "Failed to update task plan: "+err.Error(), []mapping{taskIDRequired, planNotFound}) + return errorResponse(msg, err, "Failed to update task plan: "+err.Error(), []mapping{taskIDRequired, taskNotFound, planNotFound}) } // DeleteError maps a PlanService.DeletePlan failure. diff --git a/apps/backend/internal/task/planws/errors_test.go b/apps/backend/internal/task/planws/errors_test.go index e1565ffabe..a34997a088 100644 --- a/apps/backend/internal/task/planws/errors_test.go +++ b/apps/backend/internal/task/planws/errors_test.go @@ -6,6 +6,7 @@ import ( "fmt" "testing" + "github.com/kandev/kandev/internal/task/repository" "github.com/kandev/kandev/internal/task/service" ws "github.com/kandev/kandev/pkg/websocket" ) @@ -36,6 +37,7 @@ func decode(t *testing.T, msg *ws.Message, err error) ws.ErrorPayload { // production message changes, which it cannot do if both read the same symbol. const ( wantTaskIDRequired = "task_id is required" + wantTaskNotFound = "Task not found" wantTaskPlanNotFound = "Task plan not found" ) @@ -57,6 +59,7 @@ func TestMappersCoverEverySentinel(t *testing.T) { message string }{ {"create/task_id", CreateError, service.ErrTaskIDRequired, ws.ErrorCodeValidation, wantTaskIDRequired}, + {"create/task_not_found", CreateError, repository.ErrTaskNotFound, ws.ErrorCodeNotFound, wantTaskNotFound}, {"create/fallback", CreateError, boom, ws.ErrorCodeInternalError, "Failed to create task plan: disk on fire"}, // CreatePlan's ErrTaskPlanNotFound means the read-back after a // successful write found nothing — a server fault, not a missing plan. @@ -67,6 +70,7 @@ func TestMappersCoverEverySentinel(t *testing.T) { {"get/fallback", GetError, boom, ws.ErrorCodeInternalError, "Failed to get task plan"}, {"update/task_id", UpdateError, service.ErrTaskIDRequired, ws.ErrorCodeValidation, wantTaskIDRequired}, + {"update/task_not_found", UpdateError, repository.ErrTaskNotFound, ws.ErrorCodeNotFound, wantTaskNotFound}, {"update/plan_not_found", UpdateError, service.ErrTaskPlanNotFound, ws.ErrorCodeNotFound, wantTaskPlanNotFound}, {"update/fallback", UpdateError, boom, ws.ErrorCodeInternalError, "Failed to update task plan: disk on fire"}, @@ -99,6 +103,7 @@ func TestErrorCoversFullVocabulary(t *testing.T) { message string }{ {service.ErrTaskIDRequired, ws.ErrorCodeValidation, wantTaskIDRequired}, + {repository.ErrTaskNotFound, ws.ErrorCodeNotFound, wantTaskNotFound}, {service.ErrSessionIDRequired, ws.ErrorCodeValidation, "session_id is required"}, {service.ErrSessionTaskMismatch, ws.ErrorCodeValidation, "Session does not belong to task"}, {service.ErrTaskPlanNotFound, ws.ErrorCodeNotFound, wantTaskPlanNotFound}, diff --git a/apps/backend/internal/task/repository/sqlite/document_plan_postgres_test.go b/apps/backend/internal/task/repository/sqlite/document_plan_postgres_test.go index c3c0baf208..545dd47e75 100644 --- a/apps/backend/internal/task/repository/sqlite/document_plan_postgres_test.go +++ b/apps/backend/internal/task/repository/sqlite/document_plan_postgres_test.go @@ -203,3 +203,27 @@ func TestPostgresWritePlanRevisionUpsertAndImplementationMarker(t *testing.T) { t.Errorf("GetTaskPlan(missing) = %+v, %v; want nil, nil", missing, err) } } + +func TestPostgresWritePlanRevisionMissingTask(t *testing.T) { + db := testutil.OpenIsolatedPostgres(t, testutil.PostgresDSNFromEnv(t)) + repo, err := NewWithDB(db, db, nil) + if err != nil { + t.Fatalf("init postgres schema: %v", err) + } + ctx := context.Background() + taskID := "task-plan-pg-missing" + + err = repo.WritePlanRevision(ctx, + &models.TaskPlan{ID: "plan-pg-missing", TaskID: taskID, Title: "Plan", Content: "body"}, + &models.TaskPlanRevision{TaskID: taskID, Title: "Plan", Content: "body", AuthorKind: "agent"}, + nil) + if !errors.Is(err, ErrTaskNotFound) { + t.Fatalf("WritePlanRevision error = %v, want ErrTaskNotFound", err) + } + if got := countRows(t, repo, `SELECT COUNT(1) FROM task_plans WHERE task_id = ?`, taskID); got != 0 { + t.Fatalf("plan HEAD rows = %d, want 0 after rollback", got) + } + if got := countRows(t, repo, `SELECT COUNT(1) FROM task_plan_revisions WHERE task_id = ?`, taskID); got != 0 { + t.Fatalf("plan revision rows = %d, want 0 after rollback", got) + } +} diff --git a/apps/backend/internal/task/repository/sqlite/plan.go b/apps/backend/internal/task/repository/sqlite/plan.go index 05a75fd13c..c3e3b8b424 100644 --- a/apps/backend/internal/task/repository/sqlite/plan.go +++ b/apps/backend/internal/task/repository/sqlite/plan.go @@ -8,6 +8,7 @@ import ( "github.com/google/uuid" "github.com/jmoiron/sqlx" + internaldb "github.com/kandev/kandev/internal/db" "github.com/kandev/kandev/internal/task/models" ) @@ -333,6 +334,9 @@ func upsertPlanHead(ctx context.Context, tx *sqlx.Tx, db *sqlx.DB, head *models. created_by = excluded.created_by, updated_at = excluded.updated_at `), head.ID, head.TaskID, head.Title, head.Content, head.CreatedBy, head.CreatedAt, head.UpdatedAt); err != nil { + if internaldb.IsForeignKeyViolation(err) { + return fmt.Errorf("upsert task plan head for task %s: %w", head.TaskID, ErrTaskNotFound) + } return fmt.Errorf("upsert task plan head: %w", err) } return nil diff --git a/apps/backend/internal/task/repository/sqlite/plan_test.go b/apps/backend/internal/task/repository/sqlite/plan_test.go index c1455bf2f7..28e2b73e8c 100644 --- a/apps/backend/internal/task/repository/sqlite/plan_test.go +++ b/apps/backend/internal/task/repository/sqlite/plan_test.go @@ -582,6 +582,26 @@ func TestWritePlanRevisionCreatesHeadAndFirstRevision(t *testing.T) { assertPlanRevisionEqual(t, gotRev, rev) } +func TestWritePlanRevisionMissingTask(t *testing.T) { + repo := newRepoForEntityTests(t) + ctx := context.Background() + taskID := "task-writeplan-missing" + + err := repo.WritePlanRevision(ctx, + &models.TaskPlan{ID: "plan-missing", TaskID: taskID, Title: "Plan", Content: "body"}, + &models.TaskPlanRevision{TaskID: taskID, Title: "Plan", Content: "body", AuthorKind: "agent"}, + nil) + if !errors.Is(err, ErrTaskNotFound) { + t.Fatalf("WritePlanRevision error = %v, want ErrTaskNotFound", err) + } + if got := countRows(t, repo, `SELECT COUNT(1) FROM task_plans WHERE task_id = ?`, taskID); got != 0 { + t.Fatalf("plan HEAD rows = %d, want 0 after rollback", got) + } + if got := countRows(t, repo, `SELECT COUNT(1) FROM task_plan_revisions WHERE task_id = ?`, taskID); got != 0 { + t.Fatalf("plan revision rows = %d, want 0 after rollback", got) + } +} + func TestWritePlanRevisionUpsertsHeadAndAppendsRevisions(t *testing.T) { repo := newRepoForEntityTests(t) ctx := context.Background() diff --git a/apps/backend/internal/task/service/plan_service.go b/apps/backend/internal/task/service/plan_service.go index 743b2c2e37..70dd6391f3 100644 --- a/apps/backend/internal/task/service/plan_service.go +++ b/apps/backend/internal/task/service/plan_service.go @@ -238,7 +238,7 @@ func (s *PlanService) upsertPlan(ctx context.Context, req CreatePlanRequest) (*m } if err := s.repo.WritePlanRevision(ctx, plan, rev, coalesceID); err != nil { - s.logger.Error("write plan revision", zap.String("task_id", req.TaskID), zap.Error(err)) + s.logPlanWriteError(req.TaskID, err) return nil, err } @@ -497,6 +497,7 @@ func (s *PlanService) RevertPlan(ctx context.Context, req RevertPlanRequest) (*m RevertOfRevisionID: &targetID, } if err := s.repo.WritePlanRevision(ctx, plan, rev, nil); err != nil { + s.logPlanWriteError(req.TaskID, err) return nil, err } @@ -513,6 +514,15 @@ func (s *PlanService) RevertPlan(ctx context.Context, req RevertPlanRequest) (*m return rev, nil } +func (s *PlanService) logPlanWriteError(taskID string, err error) { + fields := []zap.Field{zap.String("task_id", taskID), zap.Error(err)} + if errors.Is(err, repository.ErrTaskNotFound) { + s.logger.Debug("write plan revision", fields...) + return + } + s.logger.Error("write plan revision", fields...) +} + func (s *PlanService) publishPlanEvent(ctx context.Context, eventType string, plan *models.TaskPlan) { if s.eventBus == nil { return diff --git a/apps/backend/internal/task/service/plan_service_logging_test.go b/apps/backend/internal/task/service/plan_service_logging_test.go new file mode 100644 index 0000000000..d63bf11710 --- /dev/null +++ b/apps/backend/internal/task/service/plan_service_logging_test.go @@ -0,0 +1,145 @@ +package service + +import ( + "context" + "errors" + "testing" + + "github.com/kandev/kandev/internal/task/models" + "github.com/kandev/kandev/internal/task/repository/repoerrors" + "go.uber.org/zap/zapcore" +) + +func TestPlanServiceMissingTaskWriteLogSeverity(t *testing.T) { + svc, _, _ := createTestPlanService(t) + log, logs := newObservedServiceLogger(t) + svc.logger = log + + _, err := svc.CreatePlan(context.Background(), CreatePlanRequest{ + TaskID: "task-plan-service-missing", Content: "body", + }) + if !errors.Is(err, repoerrors.ErrTaskNotFound) { + t.Fatalf("CreatePlan error = %v, want ErrTaskNotFound", err) + } + entries := logs.FilterMessage("write plan revision").All() + if len(entries) != 1 { + t.Fatalf("write-plan log count = %d, want 1", len(entries)) + } + if entries[0].Level != zapcore.DebugLevel { + t.Fatalf("write-plan log level = %s, want debug", entries[0].Level) + } + if errorsCount := logs.FilterLevelExact(zapcore.ErrorLevel).Len(); errorsCount != 0 { + t.Fatalf("error log count = %d, want 0 for missing task", errorsCount) + } +} + +func TestPlanServiceOtherWriteErrorLogSeverity(t *testing.T) { + svc, _, repo := createTestPlanService(t) + injected := errors.New("database unavailable") + svc.repo = &planWriteErrorRepo{planRepo: repo, err: injected} + log, logs := newObservedServiceLogger(t) + svc.logger = log + + _, err := svc.CreatePlan(context.Background(), CreatePlanRequest{ + TaskID: "task-plan-service-error", Content: "body", + }) + if !errors.Is(err, injected) { + t.Fatalf("CreatePlan error = %v, want injected error", err) + } + entries := logs.FilterMessage("write plan revision").All() + if len(entries) != 1 { + t.Fatalf("write-plan log count = %d, want 1", len(entries)) + } + if entries[0].Level != zapcore.ErrorLevel { + t.Fatalf("write-plan log level = %s, want error", entries[0].Level) + } +} + +func TestPlanServiceRevertMissingTaskWriteLogSeverity(t *testing.T) { + svc, _, repo := createTestPlanService(t) + ctx := context.Background() + seedTask(t, ctx, repo, "task-plan-revert-missing") + + _, err := svc.CreatePlan(ctx, CreatePlanRequest{ + TaskID: "task-plan-revert-missing", Content: "body", + }) + if err != nil { + t.Fatalf("CreatePlan error = %v", err) + } + revision, err := repo.GetLatestTaskPlanRevision(ctx, "task-plan-revert-missing") + if err != nil { + t.Fatalf("GetLatestTaskPlanRevision error = %v", err) + } + + svc.repo = &planWriteErrorRepo{planRepo: repo, err: repoerrors.ErrTaskNotFound} + log, logs := newObservedServiceLogger(t) + svc.logger = log + + _, err = svc.RevertPlan(ctx, RevertPlanRequest{ + TaskID: "task-plan-revert-missing", + TargetRevisionID: revision.ID, + }) + if !errors.Is(err, repoerrors.ErrTaskNotFound) { + t.Fatalf("RevertPlan error = %v, want ErrTaskNotFound", err) + } + entries := logs.FilterMessage("write plan revision").All() + if len(entries) != 1 { + t.Fatalf("write-plan log count = %d, want 1", len(entries)) + } + if entries[0].Level != zapcore.DebugLevel { + t.Fatalf("write-plan log level = %s, want debug", entries[0].Level) + } + if errorsCount := logs.FilterLevelExact(zapcore.ErrorLevel).Len(); errorsCount != 0 { + t.Fatalf("error log count = %d, want 0 for missing task", errorsCount) + } +} + +func TestPlanServiceRevertOtherWriteErrorLogSeverity(t *testing.T) { + svc, _, repo := createTestPlanService(t) + ctx := context.Background() + seedTask(t, ctx, repo, "task-plan-revert-error") + + _, err := svc.CreatePlan(ctx, CreatePlanRequest{ + TaskID: "task-plan-revert-error", Content: "body", + }) + if err != nil { + t.Fatalf("CreatePlan error = %v", err) + } + revision, err := repo.GetLatestTaskPlanRevision(ctx, "task-plan-revert-error") + if err != nil { + t.Fatalf("GetLatestTaskPlanRevision error = %v", err) + } + injected := errors.New("database unavailable") + svc.repo = &planWriteErrorRepo{planRepo: repo, err: injected} + log, logs := newObservedServiceLogger(t) + svc.logger = log + + _, err = svc.RevertPlan(ctx, RevertPlanRequest{ + TaskID: "task-plan-revert-error", + TargetRevisionID: revision.ID, + }) + if !errors.Is(err, injected) { + t.Fatalf("RevertPlan error = %v, want injected error", err) + } + entries := logs.FilterMessage("write plan revision").All() + if len(entries) != 1 { + t.Fatalf("write-plan log count = %d, want 1", len(entries)) + } + if entries[0].Level != zapcore.ErrorLevel { + t.Fatalf("write-plan log level = %s, want error", entries[0].Level) + } +} + +type planWriteErrorRepo struct { + planRepo + err error +} + +func (r *planWriteErrorRepo) WritePlanRevision( + context.Context, + *models.TaskPlan, + *models.TaskPlanRevision, + *string, +) error { + return r.err +} diff --git a/apps/backend/internal/task/service/service_turns.go b/apps/backend/internal/task/service/service_turns.go index 825fe0a2ba..151ab6910d 100644 --- a/apps/backend/internal/task/service/service_turns.go +++ b/apps/backend/internal/task/service/service_turns.go @@ -20,6 +20,7 @@ import ( "github.com/kandev/kandev/internal/events/bus" "github.com/kandev/kandev/internal/steptelemetry" "github.com/kandev/kandev/internal/task/models" + taskrepo "github.com/kandev/kandev/internal/task/repository" "github.com/kandev/kandev/internal/worktree" ) @@ -852,10 +853,16 @@ func (s *Service) GetWorkspaceInfoForSession(ctx context.Context, taskID, sessio if session.TaskEnvironmentID != "" { env, envErr := s.taskEnvironments.GetTaskEnvironment(ctx, session.TaskEnvironmentID) if envErr != nil { - s.logger.Warn("failed to get task environment for session", + logFields := []zap.Field{ zap.String("session_id", sessionID), zap.String("task_environment_id", session.TaskEnvironmentID), - zap.Error(envErr)) + zap.Error(envErr), + } + if errors.Is(envErr, taskrepo.ErrTaskEnvironmentNotFound) { + s.logger.Debug("failed to get task environment for session", logFields...) + } else { + s.logger.Warn("failed to get task environment for session", logFields...) + } } else { taskEnv = env } diff --git a/apps/backend/internal/task/service/service_turns_logging_test.go b/apps/backend/internal/task/service/service_turns_logging_test.go new file mode 100644 index 0000000000..0f60134401 --- /dev/null +++ b/apps/backend/internal/task/service/service_turns_logging_test.go @@ -0,0 +1,102 @@ +package service + +import ( + "context" + "errors" + "testing" + + commonlogger "github.com/kandev/kandev/internal/common/logger" + "github.com/kandev/kandev/internal/task/models" + "github.com/kandev/kandev/internal/task/repository" + "go.uber.org/zap" + "go.uber.org/zap/zapcore" + "go.uber.org/zap/zaptest/observer" +) + +func TestGetWorkspaceInfoForSession_MissingEnvironmentLogSeverity(t *testing.T) { + svc, _, repo := createTestService(t) + ctx := context.Background() + setupTestTask(t, repo) + if err := repo.CreateTaskSession(ctx, &models.TaskSession{ + ID: "session-stale-environment", TaskID: "task-123", + TaskEnvironmentID: "env-stale", State: models.TaskSessionStateCompleted, + }); err != nil { + t.Fatalf("CreateTaskSession: %v", err) + } + createTestEnvironment(t, repo, "env-current", "task-123") + + log, logs := newObservedServiceLogger(t) + svc.logger = log + + info, err := svc.GetWorkspaceInfoForSession(ctx, "task-123", "session-stale-environment") + if err != nil { + t.Fatalf("GetWorkspaceInfoForSession: %v", err) + } + if info.TaskEnvironmentID != "env-current" { + t.Fatalf("TaskEnvironmentID = %q, want env-current", info.TaskEnvironmentID) + } + if entries := logs.FilterLevelExact(zapcore.WarnLevel).All(); len(entries) != 0 { + t.Fatalf("stale environment warning count = %d, want 0", len(entries)) + } + entries := logs.FilterMessage("failed to get task environment for session").All() + if len(entries) != 1 { + t.Fatalf("stale environment debug evidence count = %d, want 1", len(entries)) + } + if entries[0].Level != zapcore.DebugLevel { + t.Fatalf("stale environment log level = %s, want debug", entries[0].Level) + } +} + +func TestGetWorkspaceInfoForSession_UnexpectedEnvironmentErrorLogSeverity(t *testing.T) { + svc, _, repo := createTestService(t) + ctx := context.Background() + setupTestTask(t, repo) + if err := repo.CreateTaskSession(ctx, &models.TaskSession{ + ID: "session-environment-error", TaskID: "task-123", + TaskEnvironmentID: "env-unavailable", State: models.TaskSessionStateCompleted, + }); err != nil { + t.Fatalf("CreateTaskSession: %v", err) + } + createTestEnvironment(t, repo, "env-current", "task-123") + svc.taskEnvironments = &workspaceInfoTaskEnvironmentRepo{ + TaskEnvironmentRepository: repo, + directErr: errors.New("environment store unavailable"), + } + + log, logs := newObservedServiceLogger(t) + svc.logger = log + + info, err := svc.GetWorkspaceInfoForSession(ctx, "task-123", "session-environment-error") + if err != nil { + t.Fatalf("GetWorkspaceInfoForSession: %v", err) + } + if info.TaskEnvironmentID != "env-current" { + t.Fatalf("TaskEnvironmentID = %q, want env-current", info.TaskEnvironmentID) + } + entries := logs.FilterMessage("failed to get task environment for session").All() + if len(entries) != 1 { + t.Fatalf("unexpected environment warning count = %d, want 1", len(entries)) + } + if entries[0].Level != zapcore.WarnLevel { + t.Fatalf("unexpected environment log level = %s, want warn", entries[0].Level) + } +} + +type workspaceInfoTaskEnvironmentRepo struct { + repository.TaskEnvironmentRepository + directErr error +} + +func (r *workspaceInfoTaskEnvironmentRepo) GetTaskEnvironment(context.Context, string) (*models.TaskEnvironment, error) { + return nil, r.directErr +} + +func newObservedServiceLogger(t *testing.T) (*commonlogger.Logger, *observer.ObservedLogs) { + t.Helper() + core, logs := observer.New(zapcore.DebugLevel) + log, err := commonlogger.NewFromZap(zap.New(core)) + if err != nil { + t.Fatalf("NewFromZap: %v", err) + } + return log, logs +} diff --git a/docs/plans/backend-diagnostic-signal-quality/plan.md b/docs/plans/backend-diagnostic-signal-quality/plan.md new file mode 100644 index 0000000000..a74a3a9f3a --- /dev/null +++ b/docs/plans/backend-diagnostic-signal-quality/plan.md @@ -0,0 +1,98 @@ +--- +spec: docs/specs/platform/requirements/expected-runtime-log-severity.md +created: 2026-08-28 +status: implemented +--- + +# Implementation Plan: Backend diagnostic signal quality + +## Overview + +This repair removes false warning and error entries from four confirmed backend +paths. It preserves warnings for unknown child output and unexpected storage +errors. + +The work changes no successful API payload, process lifecycle, workspace +selection, or runtime cleanup result. A plan write for a missing task changes +from an internal storage error to the stable `not_found` contract. + +## Specifications + +- [Expected runtime log severity requirements](../../specs/platform/requirements/expected-runtime-log-severity.md) +- [Expected runtime log severity design](../../specs/platform/system-design/expected-runtime-log-severity.md) +- [Task runtime cleanup requirements](../../specs/tasks/requirements/runtime-cleanup.md) +- [Task runtime cleanup design](../../specs/tasks/system-design/runtime-cleanup.md) +- [Task documents requirements](../../specs/tasks/requirements/documents.md) +- [Task plan write lifecycle design](../../specs/tasks/system-design/plan-write-lifecycle.md) + +## Implementation order + +Wave 1 contains four independent backend corrections: + +- [x] [Task 01: Preserve child log severity](task-01-preserve-child-log-severity.md) +- [x] [Task 02: Quiet stale environment fallback](task-02-quiet-stale-environment-fallback.md) +- [x] [Task 03: Quiet rotated liveness repair](task-03-quiet-rotated-liveness-repair.md) +- [x] [Task 04: Classify missing-task plan writes](task-04-classify-missing-task-plan-writes.md) + +Wave 2 depends on Task 04: + +- [x] [Task 05: Map missing-task plan responses](task-05-map-missing-task-plan-responses.md) + +Implementation remains sequential in the primary conversation unless the user +explicitly authorizes delegation. + +## TDD strategy + +Each work order starts with a focused regression that fails on the current +behavior. The implementation then makes that regression pass without changing +the neighboring error path. + +Repository coverage runs against SQLite. The existing environment-gated +PostgreSQL suite proves dialect parity for the plan foreign-key mapping. + +No browser end-to-end test is required. The changed behavior is a backend log +contract and a shared WebSocket error response. Handler integration tests cover +both browser and MCP surfaces. + +## Final verification + +Run these commands from the repository root after all work orders are complete: + +```bash +cd apps/backend && go test ./internal/agent/runtime/agentctl/launcher ./internal/task/service ./internal/orchestrator ./internal/task/repository/sqlite ./internal/task/planws ./internal/task/handlers ./internal/mcp/handlers -count=1 +make -C apps/backend lint +git diff --check +``` + +If `KANDEV_TEST_POSTGRES_DSN` is available, also run: + +```bash +cd apps/backend && go test ./internal/task/repository/sqlite -run TestPostgresWritePlanRevisionMissingTask -count=1 +``` + +## Risks + +- A permissive child-log parser can hide unstructured stderr. The parser must + accept only anchored Zap and Go `slog` records. +- A broad not-found check can hide a database outage. The service must match the + typed task-environment sentinel only. +- A liveness repair can race a newer execution. The fix must preserve the newer + row and change only the log classification. +- Foreign-key text differs by database. The repository must use + `internal/db.IsForeignKeyViolation` instead of matching new strings. +- A missing-task plan rejection can race after access validation. The write + transaction remains the authoritative check. + +## Out of scope + +- Enabling authentication or changing bind addresses. +- Changing authentication warning text or severity. +- Repairing third-party plugin webhook defaults or provider outages. +- Changing the designed host-utility idle-repair behavior. +- Reclassifying network disconnect warnings without a confirmed caller defect. +- Changing raw ACP collection, retention, or diagnostic bundle size. +- Migrating plans to the generalized task-documents model. + +## Open questions + +None. diff --git a/docs/plans/backend-diagnostic-signal-quality/task-01-preserve-child-log-severity.md b/docs/plans/backend-diagnostic-signal-quality/task-01-preserve-child-log-severity.md new file mode 100644 index 0000000000..b2111eb807 --- /dev/null +++ b/docs/plans/backend-diagnostic-signal-quality/task-01-preserve-child-log-severity.md @@ -0,0 +1,78 @@ +--- +id: "01-preserve-child-log-severity" +title: "Preserve child log severity" +status: done +wave: 1 +depends_on: [] +plan: "plan.md" +spec: "../../specs/platform/requirements/expected-runtime-log-severity.md" +--- + +# Task 01: Preserve child log severity + +Extend the agentctl launcher parser to recognize the Go `slog` formats used by +the child process. + +## Scope + +- Extend `childLogLevel` with anchored Go `slog` TextHandler and default-handler + parsers. +- Keep the existing Zap console parser and ANSI handling. +- Keep unrecognized stderr on the warning fallback. + +## Exclusions + +- Do not change child logger configuration. +- Do not parse arbitrary level-like words from messages. +- Do not change stdout handling. + +## Traceability + +- `REQ-PLATFORM-EXPECTED-RUNTIME-LOG-SEVERITY-001` +- `AC-PLATFORM-EXPECTED-RUNTIME-LOG-SEVERITY-001.9` +- `AC-PLATFORM-EXPECTED-RUNTIME-LOG-SEVERITY-001.10` +- `AC-PLATFORM-EXPECTED-RUNTIME-LOG-SEVERITY-001.13` +- `AC-PLATFORM-EXPECTED-RUNTIME-LOG-SEVERITY-001.14` +- Design: `docs/specs/platform/system-design/expected-runtime-log-severity.md` + +## Acceptance + +- Recognized Go `slog` `DEBUG`, `INFO`, `WARN`, and `ERROR` records use the + matching parent severity. +- Both `slog.TextHandler` key/value output and the default handler's standard + log date/time output are recognized. +- Existing Zap console records keep their current classification. +- Malformed and unstructured stderr remains at warning level. + +## Verification + +```bash +cd apps/backend && go test ./internal/agent/runtime/agentctl/launcher -run 'Test(ChildLogLevel|PipeOutput)' -count=1 +``` + +The new `slog` case must fail before the production change because the current +parser accepts only tab-separated Zap console records. + +## Files likely touched + +- `apps/backend/internal/agent/runtime/agentctl/launcher/launcher.go` +- `apps/backend/internal/agent/runtime/agentctl/launcher/launcher_loglevel_test.go` + +## Dependencies + +None. + +## Results + +Implemented anchored Go `slog.TextHandler` and default-handler parsing while +preserving the existing Zap parser and warning fallback. The text parser is +quote-aware so a `msg=` substring inside an attribute cannot change severity. +Added coverage for actual `slog.Default()` output, all standard TextHandler +levels, and malformed/unstructured records. + +Verification: + +```text +cd apps/backend && go test ./internal/agent/runtime/agentctl/launcher -run 'Test(ChildLogLevel|PipeOutput)' -count=1 +Go test: 28 passed in 1 packages +``` diff --git a/docs/plans/backend-diagnostic-signal-quality/task-02-quiet-stale-environment-fallback.md b/docs/plans/backend-diagnostic-signal-quality/task-02-quiet-stale-environment-fallback.md new file mode 100644 index 0000000000..f7b8686707 --- /dev/null +++ b/docs/plans/backend-diagnostic-signal-quality/task-02-quiet-stale-environment-fallback.md @@ -0,0 +1,75 @@ +--- +id: "02-quiet-stale-environment-fallback" +title: "Quiet stale environment fallback" +status: done +wave: 1 +depends_on: [] +plan: "plan.md" +spec: "../../specs/platform/requirements/expected-runtime-log-severity.md" +--- + +# Task 02: Quiet stale environment fallback + +Classify a stale session environment reference as an expected fallback. + +## Scope + +- Match `taskrepo.ErrTaskEnvironmentNotFound` before the warning log. +- Use debug severity for that typed condition. +- Preserve the task-based environment fallback and workspace result. +- Keep warnings for all other lookup errors. + +## Exclusions + +- Do not change session or task-environment persistence. +- Do not remove the fallback lookup. +- Do not classify errors by message text. + +## Traceability + +- `REQ-PLATFORM-EXPECTED-RUNTIME-LOG-SEVERITY-001` +- `AC-PLATFORM-EXPECTED-RUNTIME-LOG-SEVERITY-001.11` +- `AC-PLATFORM-EXPECTED-RUNTIME-LOG-SEVERITY-001.12` +- `AC-PLATFORM-EXPECTED-RUNTIME-LOG-SEVERITY-001.15` +- `AC-PLATFORM-EXPECTED-RUNTIME-LOG-SEVERITY-001.16` +- Design: `docs/specs/platform/system-design/expected-runtime-log-severity.md` + +## Acceptance + +- A typed missing environment emits no warning and still returns the task + fallback result. +- An unexpected environment lookup error still emits one warning. +- The fallback keeps the authoritative task-environment identifier. + +## Verification + +```bash +cd apps/backend && go test ./internal/task/service -run 'TestGetWorkspaceInfoForSession_(AlignsTaskEnvironmentIDOnFallback|MissingEnvironmentLogSeverity|UnexpectedEnvironmentErrorLogSeverity)' -count=1 +``` + +The missing-environment log test must fail before the production change because +the current branch records every direct lookup error as a warning. + +## Files likely touched + +- `apps/backend/internal/task/service/service_turns.go` +- `apps/backend/internal/task/service/service_turns_test.go` +- `apps/backend/internal/task/service/service_turns_logging_test.go` + +## Dependencies + +None. + +## Results + +Implemented typed not-found classification before logging the stale session +environment lookup. The task fallback remains authoritative, with debug +evidence for the expected miss and warning-level evidence for unexpected +lookup errors. + +Verification: + +```text +cd apps/backend && go test ./internal/task/service -run 'TestGetWorkspaceInfoForSession_(AlignsTaskEnvironmentIDOnFallback|MissingEnvironmentLogSeverity|UnexpectedEnvironmentErrorLogSeverity)' -count=1 +Go test: 3 passed in 1 packages +``` diff --git a/docs/plans/backend-diagnostic-signal-quality/task-03-quiet-rotated-liveness-repair.md b/docs/plans/backend-diagnostic-signal-quality/task-03-quiet-rotated-liveness-repair.md new file mode 100644 index 0000000000..200c0daa42 --- /dev/null +++ b/docs/plans/backend-diagnostic-signal-quality/task-03-quiet-rotated-liveness-repair.md @@ -0,0 +1,68 @@ +--- +id: "03-quiet-rotated-liveness-repair" +title: "Quiet rotated liveness repair" +status: done +wave: 1 +depends_on: [] +plan: "plan.md" +spec: "../../specs/tasks/requirements/runtime-cleanup.md" +--- + +# Task 03: Quiet rotated liveness repair + +Treat a lost liveness compare-and-set as expected reconciliation convergence. + +## Scope + +- Classify `models.ErrExecutionRotated` before the warning branch. +- Return success without changing the newer execution row. +- Keep the warning and returned error for unrelated repair failures. + +## Exclusions + +- Do not change the compare-and-set repository operation. +- Do not retry against the newer execution identity. +- Do not change row deletion or resume-safety rules. + +## Traceability + +- `REQ-TASKS-RUNTIME-CLEANUP-001` +- `AC-TASKS-RUNTIME-CLEANUP-001.8` +- Design: `docs/specs/tasks/system-design/runtime-cleanup.md` + +## Acceptance + +- `models.ErrExecutionRotated` returns success and emits no warning. +- `models.ErrExecutorRunningNotFound` keeps its existing successful behavior. +- An unrelated repair error returns the error and emits one warning. + +## Verification + +```bash +cd apps/backend && go test ./internal/orchestrator -run TestRepairDeadRowLivenessLogSeverity -count=1 +``` + +The rotated case must fail before the production change because the current +branch emits a warning before it returns success. + +## Files likely touched + +- `apps/backend/internal/orchestrator/reconcile_liveness.go` +- `apps/backend/internal/orchestrator/reconcile_liveness_test.go` + +## Dependencies + +None. + +## Results + +Moved the expected `models.ErrExecutionRotated` and existing missing-row +classification ahead of the warning branch. The newer execution row remains +unchanged, while unrelated repair errors still return and emit one warning. + +Verification: + +```text +cd apps/backend && go test ./internal/orchestrator -run TestRepairDeadRowLivenessLogSeverity -count=1 +Go test: 3 passed in 1 packages +``` diff --git a/docs/plans/backend-diagnostic-signal-quality/task-04-classify-missing-task-plan-writes.md b/docs/plans/backend-diagnostic-signal-quality/task-04-classify-missing-task-plan-writes.md new file mode 100644 index 0000000000..cc77f42484 --- /dev/null +++ b/docs/plans/backend-diagnostic-signal-quality/task-04-classify-missing-task-plan-writes.md @@ -0,0 +1,88 @@ +--- +id: "04-classify-missing-task-plan-writes" +title: "Classify missing-task plan writes" +status: done +wave: 1 +depends_on: [] +plan: "plan.md" +spec: "../../specs/tasks/requirements/documents.md" +--- + +# Task 04: Classify missing-task plan writes + +Translate a plan foreign-key rejection to the shared missing-task sentinel. + +## Scope + +- Use `internal/db.IsForeignKeyViolation` at the plan-head write boundary. +- Return `repoerrors.ErrTaskNotFound` with wrapped operation context. +- Preserve transaction rollback for the plan head and revision. +- Record the expected service rejection at debug level for both the upsert and + revert write paths. +- Add SQLite coverage and environment-gated PostgreSQL parity coverage. + +## Exclusions + +- Do not add a separate task existence query before the transaction. +- Do not change successful plan coalescing or revision numbering. +- Do not change other foreign-key mappings. + +## Traceability + +- `REQ-TASKS-DOCUMENTS-001` +- `AC-TASKS-DOCUMENTS-001.2` +- Design: `docs/specs/tasks/system-design/plan-write-lifecycle.md` + +## Acceptance + +- A plan write for a missing task returns an error that matches + `repoerrors.ErrTaskNotFound` on SQLite and PostgreSQL. +- The rejected transaction creates no plan head or revision. +- The plan service emits a debug entry for that sentinel from both + `upsertPlan` and `RevertPlan`. Other write errors retain + their error-level entry. Existing create/update coverage remains intact. + +## Verification + +```bash +cd apps/backend && go test ./internal/task/repository/sqlite -run 'TestWritePlanRevisionMissingTask|TestPostgresWritePlanRevisionMissingTask' -count=1 +cd apps/backend && go test ./internal/task/service -run 'TestPlanService(MissingTaskWriteLogSeverity|OtherWriteErrorLogSeverity|RevertMissingTaskWriteLogSeverity|RevertOtherWriteErrorLogSeverity)' -count=1 +``` + +The repository test must fail before the production change because the current +error exposes the raw foreign-key constraint failure. + +The PostgreSQL case skips when `KANDEV_TEST_POSTGRES_DSN` is not set. CI runs +the environment-gated parity suite. + +## Files likely touched + +- `apps/backend/internal/task/repository/sqlite/plan.go` +- `apps/backend/internal/task/repository/sqlite/plan_test.go` +- `apps/backend/internal/task/repository/sqlite/document_plan_postgres_test.go` +- `apps/backend/internal/task/service/plan_service.go` +- `apps/backend/internal/task/service/plan_service_logging_test.go` + +## Dependencies + +None. + +## Results + +Implemented dialect-aware foreign-key classification at the plan-head write +boundary. Missing-task writes now return `repoerrors.ErrTaskNotFound`, roll +back both plan tables, and log at debug in `PlanService`; unrelated write +errors retain error-level logging. Both `upsertPlan` and `RevertPlan` use +the same classifier, with observer-backed coverage for the missing-task and +unrelated-error paths. Added SQLite, environment-gated PostgreSQL, and service +severity coverage without removing create/update coverage. + +Verification: + +```text +cd apps/backend && go test ./internal/task/repository/sqlite -run 'TestWritePlanRevisionMissingTask|TestPostgresWritePlanRevisionMissingTask' -count=1 +Go test: 1 passed in 1 packages + +cd apps/backend && go test ./internal/task/service -run 'TestPlanService(MissingTaskWriteLogSeverity|OtherWriteErrorLogSeverity|RevertMissingTaskWriteLogSeverity|RevertOtherWriteErrorLogSeverity)' -count=1 +Go test: 4 passed in 1 packages +``` diff --git a/docs/plans/backend-diagnostic-signal-quality/task-05-map-missing-task-plan-responses.md b/docs/plans/backend-diagnostic-signal-quality/task-05-map-missing-task-plan-responses.md new file mode 100644 index 0000000000..cc5474ade0 --- /dev/null +++ b/docs/plans/backend-diagnostic-signal-quality/task-05-map-missing-task-plan-responses.md @@ -0,0 +1,78 @@ +--- +id: "05-map-missing-task-plan-responses" +title: "Map missing-task plan responses" +status: done +wave: 2 +depends_on: + - "04-classify-missing-task-plan-writes" +plan: "plan.md" +spec: "../../specs/tasks/requirements/documents.md" +--- + +# Task 05: Map missing-task plan responses + +Return the stable `not_found` contract from both task-plan handler surfaces. + +## Scope + +- Add the shared task-not-found sentinel to `planws` create and update mappings. +- Keep `ErrTaskPlanNotFound` semantics unchanged. +- Add shared mapper coverage and integration coverage for browser and MCP plan + creation against a missing task. +- Assert that responses contain no database constraint details. + +## Exclusions + +- Do not change success payloads or action names. +- Do not change plan-get or plan-delete behavior. +- Do not duplicate error mapping in each handler package. + +## Traceability + +- `REQ-TASKS-DOCUMENTS-001` +- `AC-TASKS-DOCUMENTS-001.2` +- Design: `docs/specs/tasks/system-design/plan-write-lifecycle.md` + +## Acceptance + +- Browser and MCP plan creation for a missing task returns + `ws.ErrorCodeNotFound`. +- Both responses use a stable task-not-found message and omit storage details. +- Unrelated plan write errors remain `ws.ErrorCodeInternalError`. + +## Verification + +```bash +cd apps/backend && go test ./internal/task/planws -run TestMappersCoverEverySentinel -count=1 +cd apps/backend && go test ./internal/task/handlers ./internal/mcp/handlers -run 'Test.*Plan.*MissingTask' -count=1 +``` + +The handler tests must fail before the production change because the current +create mapping returns `internal_error` with the foreign-key message. + +## Files likely touched + +- `apps/backend/internal/task/planws/errors.go` +- `apps/backend/internal/task/planws/errors_test.go` +- `apps/backend/internal/task/handlers/task_plan_handlers_test.go` +- `apps/backend/internal/mcp/handlers/task_plan_handlers_test.go` + +## Dependencies + +- Task 04 must expose `repository.ErrTaskNotFound` from the write boundary. + +## Results + +Implemented the shared missing-task mapping for create and update plan +responses. Browser and MCP creation and update tests now verify the stable +`not_found` message and reject leaked database constraint details. + +Verification: + +```text +cd apps/backend && go test ./internal/task/planws -run TestMappersCoverEverySentinel -count=1 +Go test: 14 passed in 1 packages + +cd apps/backend && go test ./internal/task/handlers ./internal/mcp/handlers -run 'Test.*Plan.*MissingTask' -count=1 +Go test: 14 passed in 2 packages +``` diff --git a/docs/specs/platform/README.md b/docs/specs/platform/README.md index 5a9e57b0ca..d598e6b29b 100644 --- a/docs/specs/platform/README.md +++ b/docs/specs/platform/README.md @@ -78,6 +78,7 @@ localization, feature toggles, health, and shared session recovery services. - [Bounded Task Status Delivery](system-design/bounded-task-status-delivery.md) - [Diagnostic logging System Design Part 1](system-design/diagnostic-logging-01.md) - [Diagnostic logging System Design Part 2](system-design/diagnostic-logging-02.md) +- [Expected runtime log severity](system-design/expected-runtime-log-severity.md) - [Health Endpoint — Surface the Running Version](system-design/health-endpoint-version.md) - [Internationalization (i18n)](system-design/i18n.md) - [LSP File Intelligence System Design Part 1](system-design/lsp-file-intelligence-01.md) diff --git a/docs/specs/platform/requirements/expected-runtime-log-severity.md b/docs/specs/platform/requirements/expected-runtime-log-severity.md index fbdb436b05..6e9cb34b23 100644 --- a/docs/specs/platform/requirements/expected-runtime-log-severity.md +++ b/docs/specs/platform/requirements/expected-runtime-log-severity.md @@ -2,6 +2,7 @@ status: active system: platform created: 2026-08-23 +updated: 2026-08-28 owners: - kandev --- @@ -9,7 +10,8 @@ owners: ## Overview -Normal review and first-launch timing conditions currently look like backend failures in the logs. This obscures actionable errors and makes diagnostic bundles harder to triage. +Expected runtime conditions and forwarded child logs can use the wrong severity. +This behavior obscures actionable errors and makes diagnostic bundles harder to triage. ## Requirements @@ -27,6 +29,14 @@ Normal review and first-launch timing conditions currently look like backend fai - **AC-PLATFORM-EXPECTED-RUNTIME-LOG-SEVERITY-001.6:** **GIVEN** an active session and a dependency failure unrelated to a missing file, **WHEN** `workspace.file.get` requests a path, **THEN** the response has the `internal_error` error code and an error-level entry is emitted. - **AC-PLATFORM-EXPECTED-RUNTIME-LOG-SEVERITY-001.7:** **GIVEN** a physical worktree has been materialized before its task environment row exists, **WHEN** worktree persistence receives `ErrEnvironmentNotResolved`, **THEN** the call succeeds, emits a debug-level deferred-persistence entry, and does not remove the physical worktree. - **AC-PLATFORM-EXPECTED-RUNTIME-LOG-SEVERITY-001.8:** **GIVEN** worktree persistence receives any other store error, **WHEN** the manager handles it, **THEN** the existing error and cleanup behavior remains unchanged. +- **AC-PLATFORM-EXPECTED-RUNTIME-LOG-SEVERITY-001.9:** The launcher shall preserve a recognized child log level from Zap console records and Go `slog` text records. +- **AC-PLATFORM-EXPECTED-RUNTIME-LOG-SEVERITY-001.10:** The launcher shall record unrecognized child stderr at warning level so that unstructured panics and tracebacks remain visible. +- **AC-PLATFORM-EXPECTED-RUNTIME-LOG-SEVERITY-001.11:** A missing task environment referenced by a session shall use the existing task fallback without a warning entry. +- **AC-PLATFORM-EXPECTED-RUNTIME-LOG-SEVERITY-001.12:** A task-environment lookup error that is not a typed not-found condition shall retain its warning entry. +- **AC-PLATFORM-EXPECTED-RUNTIME-LOG-SEVERITY-001.13:** **GIVEN** a child emits a recognized `INFO` record, **WHEN** the launcher forwards stderr, **THEN** the parent records the line at info level. +- **AC-PLATFORM-EXPECTED-RUNTIME-LOG-SEVERITY-001.14:** **GIVEN** a child emits unstructured stderr, **WHEN** the launcher forwards the line, **THEN** the parent records it at warning level. +- **AC-PLATFORM-EXPECTED-RUNTIME-LOG-SEVERITY-001.15:** **GIVEN** a session references a missing task environment, **WHEN** workspace information is loaded, **THEN** the task fallback succeeds without a warning entry. +- **AC-PLATFORM-EXPECTED-RUNTIME-LOG-SEVERITY-001.16:** **GIVEN** a task-environment lookup returns another error, **WHEN** workspace information is loaded, **THEN** the existing fallback and warning behavior remains unchanged. ## Migrated source detail @@ -49,6 +59,10 @@ bundles harder to triage. owns persistence of its record. - Other worktree persistence failures keep their existing return, cleanup, and logging behavior. +- Forwarded child stderr keeps recognized Zap and Go `slog` levels. Unknown + stderr stays at warning level. +- A missing session task environment uses the existing task fallback without a + warning. Other lookup errors keep their warning. ## API surface @@ -71,6 +85,12 @@ status and message path. remove the newly created physical worktree. - Any other worktree store failure remains an actual persistence failure and follows the current cleanup and retry boundary. +- The launcher accepts only anchored child log formats. Unrecognized stderr + remains visible at warning level. +- A typed missing task environment is an expected stale-reference condition. + The task fallback remains authoritative for workspace information. +- Other task-environment lookup errors can indicate a storage problem and + remain warnings. ## Persistence guarantees @@ -95,10 +115,21 @@ persistence, or cleanup behavior across backend restarts. - **GIVEN** worktree persistence receives any other store error, **WHEN** the manager handles it, **THEN** the existing error and cleanup behavior remains unchanged. +- **GIVEN** a child emits a recognized `INFO` record, **WHEN** the launcher + forwards stderr, **THEN** the parent records the line at info level. +- **GIVEN** a child emits unstructured stderr, **WHEN** the launcher forwards + the line, **THEN** the parent records it at warning level. +- **GIVEN** a session references a missing task environment, **WHEN** workspace + information is loaded, **THEN** the task fallback succeeds without a warning + entry. +- **GIVEN** a task-environment lookup returns another error, **WHEN** workspace + information is loaded, **THEN** the existing fallback and warning behavior + remains unchanged. ## Out of scope - Changing frontend diff rendering or review-file status behavior. - Changing worktree ownership, task-environment transactions, cleanup policy, or startup reconciliation. -- Reclassifying unrelated integration, ACP, or startup warnings. +- Reclassifying integration failures, raw ACP frames, host-utility idle repair, + network disconnects, or authentication warnings. diff --git a/docs/specs/platform/system-design/expected-runtime-log-severity.md b/docs/specs/platform/system-design/expected-runtime-log-severity.md new file mode 100644 index 0000000000..40e79320b3 --- /dev/null +++ b/docs/specs/platform/system-design/expected-runtime-log-severity.md @@ -0,0 +1,75 @@ +--- +status: current +system: platform +requirements: + - REQ-PLATFORM-EXPECTED-RUNTIME-LOG-SEVERITY-001 +created: 2026-08-28 +owners: + - kandev +--- +# Expected runtime log severity System Design + +## Purpose and boundaries + +This design preserves the severity of recognized child logs. It also removes +warnings from one expected task-environment fallback. + +The design does not change process control, workspace selection, or returned +errors. Unknown child stderr remains visible at warning level. + +## Requirement mapping + +| Requirement | Design section | +| --- | --- | +| `REQ-PLATFORM-EXPECTED-RUNTIME-LOG-SEVERITY-001` | [Child log forwarding](#child-log-forwarding) and [Task-environment fallback](#task-environment-fallback) | + +## Child log forwarding + +`internal/agent/runtime/agentctl/launcher` owns the parent-side log forwarder. +The forwarder accepts these anchored child record formats: + +- Zap console records with a tab-separated level field. +- Go `slog` `TextHandler` records with `time`, `level`, and a message field. +- Go `slog.Default` records with the standard log date/time prefix, level, and + message. + +The parser returns only recognized levels. The forwarder maps `DEBUG`, `INFO`, +`WARN`, and error-class levels to the equivalent parent logger method. + +The parser does not infer a level from an arbitrary word. If a line does not +match a trusted format, the forwarder records it at warning level. This fallback +keeps panics, tracebacks, and malformed child output visible. + +## Task-environment fallback + +`internal/task/service.GetWorkspaceInfoForSession` first reads the environment +that the session references. A stale reference can return the typed +task-environment not-found error. + +The service classifies that typed error before it records a log entry. It uses +the existing task-based fallback and records only debug evidence. A different +lookup error keeps the current warning and fallback behavior. + +The fallback result, workspace metadata, and caller response do not change. + +## Failure and recovery + +An unknown child record remains a warning. This rule prevents a parser change +from hiding unstructured failures. + +An unexpected task-environment lookup error remains a warning. The task-based +fallback can still return usable workspace information, but the storage error +remains diagnostic evidence. + +## Observability + +The parent log keeps the original child line and `stream` field. Only the parent +severity changes when the parser recognizes the child severity. + +The stale task-environment path keeps the session and environment identifiers +at debug level. Unexpected lookup errors keep the existing warning fields. + +## Test strategy + +Table tests cover Zap, Go `slog`, malformed, and unstructured child lines. +Observer-backed service tests cover typed not-found and unexpected lookup errors. diff --git a/docs/specs/tasks/README.md b/docs/specs/tasks/README.md index 072a561eb1..e3469c058b 100644 --- a/docs/specs/tasks/README.md +++ b/docs/specs/tasks/README.md @@ -121,6 +121,7 @@ signals, and task-scoped scheduling contracts. - [Task model unification](system-design/model-unification.md) - [Remote Contribution Tasks](system-design/remote-contribution-tasks.md) - [Task Archive Confirmation](system-design/archive-confirmation.md) +- [Task plan write lifecycle](system-design/plan-write-lifecycle.md) - [Task Runtime Cleanup](system-design/runtime-cleanup.md) - [Queued Run Scheduling](system-design/run-scheduling.md) - [Session Delete Preserves Task Workspaces](system-design/session-delete-resource-cleanup.md) diff --git a/docs/specs/tasks/requirements/documents.md b/docs/specs/tasks/requirements/documents.md index 01182082b3..6b26525051 100644 --- a/docs/specs/tasks/requirements/documents.md +++ b/docs/specs/tasks/requirements/documents.md @@ -2,6 +2,7 @@ status: active system: tasks created: 2026-04-29 +updated: 2026-08-28 owners: - cfl --- @@ -20,6 +21,7 @@ This document is the migrated task-system source for the capability. The source #### Acceptance criteria - **AC-TASKS-DOCUMENTS-001.1:** When a consumer uses this capability, the system shall provide the observable behavior and exclusions documented below. +- **AC-TASKS-DOCUMENTS-001.2:** When a plan write targets a missing task, the system shall return `not_found`, create no plan data, and expose no storage constraint details. This expected rejection shall create a debug entry and no error-level entry. ## Migrated source detail @@ -103,10 +105,12 @@ POST /tasks/:id/documents/:key/revisions/:revId/restore → restore from prior - **GIVEN** the existing MCP tool `plan_create`, **WHEN** called with a task ID and content, **THEN** it creates/updates the document with `key=plan` (backward compatible, no behavior change). +- **GIVEN** a missing or deleted task, **WHEN** a consumer writes its plan, **THEN** the response is `not_found`, no plan data exists, and no storage error is exposed. + ## Out of scope - Real-time collaborative editing (one writer at a time, last-write-wins) - Document templates (e.g. auto-populate spec template on creation) - Cross-task document linking (documents belong to one task) - Attachment revision history (attachments are replace-only, not versioned) -- Image/file preview rendering in the UI (download link only for now) \ No newline at end of file +- Image/file preview rendering in the UI (download link only for now) diff --git a/docs/specs/tasks/requirements/runtime-cleanup.md b/docs/specs/tasks/requirements/runtime-cleanup.md index 1504798914..e6346acd3b 100644 --- a/docs/specs/tasks/requirements/runtime-cleanup.md +++ b/docs/specs/tasks/requirements/runtime-cleanup.md @@ -2,7 +2,7 @@ status: draft system: tasks created: 2026-06-22 -updated: 2026-08-24 +updated: 2026-08-28 owners: - cfl --- @@ -32,3 +32,4 @@ and safe when runtimes or task rows are already gone. cleanup removed its physical worktree, resuming the task shall recreate or reactivate the recoverable task-owned worktree instead of requiring attach-only reuse of the deleted workspace. +- **AC-TASKS-RUNTIME-CLEANUP-001.8:** When dead-row repair loses its compare-and-set to a newer execution, reconciliation shall preserve the newer row without a warning. Other repair errors shall remain warnings. diff --git a/docs/specs/tasks/system-design/plan-write-lifecycle.md b/docs/specs/tasks/system-design/plan-write-lifecycle.md new file mode 100644 index 0000000000..25d5b1a27d --- /dev/null +++ b/docs/specs/tasks/system-design/plan-write-lifecycle.md @@ -0,0 +1,69 @@ +--- +status: current +system: tasks +requirements: + - REQ-TASKS-DOCUMENTS-001 +created: 2026-08-28 +owners: + - kandev +--- +# Task plan write lifecycle System Design + +## Purpose and boundaries + +This design defines the missing-task boundary for backward-compatible task-plan +writes. It does not implement the broader task-documents migration. + +## Requirement mapping + +| Requirement | Design section | +| --- | --- | +| `REQ-TASKS-DOCUMENTS-001` | [Transactional write](#transactional-write) and [Error contract](#error-contract) | + +## Components and responsibilities + +- `internal/task/repository/sqlite.Repository` owns the transaction and database + error classification for SQLite and PostgreSQL. +- `internal/task/service.PlanService` owns operational logging and preserves + typed repository errors. +- `internal/task/planws` owns the shared WebSocket error contract for browser + handlers and MCP handlers. + +## Transactional write + +`WritePlanRevision` writes the plan head before it writes or merges a revision. +Both plan tables reference the task row with foreign keys. + +If the head write reports a foreign-key violation, the repository returns the +shared `ErrTaskNotFound` sentinel. The transaction then rolls back. No plan head +or revision remains. + +The repository uses `internal/db.IsForeignKeyViolation` for both supported +database dialects. It does not inspect a raw database error outside that helper. + +## Error contract + +The plan service passes `ErrTaskNotFound` to its callers. It records the +expected rejection at debug level. Other write errors remain error-level +entries. + +`planws.CreateError` and `planws.UpdateError` map `ErrTaskNotFound` to the +existing `not_found` WebSocket code. The response does not include a database +constraint message. + +The browser and MCP surfaces use the same `planws` mapping. No request or +success payload changes. + +## Failure and recovery + +A concurrent task deletion can occur after access validation and before the +plan transaction. The foreign-key classification closes that race without a +separate task existence query. + +An unrelated database error keeps its wrapped diagnostic context. The service +records it at error level and the wire contract returns `internal_error`. + +## Test strategy + +SQLite and PostgreSQL repository tests cover the sentinel and rollback. Service +tests cover log severity. Shared contract tests cover browser and MCP mappings. diff --git a/docs/specs/tasks/system-design/runtime-cleanup.md b/docs/specs/tasks/system-design/runtime-cleanup.md index 5e43247cfe..cc4b4acce5 100644 --- a/docs/specs/tasks/system-design/runtime-cleanup.md +++ b/docs/specs/tasks/system-design/runtime-cleanup.md @@ -114,10 +114,8 @@ worktrees, or executor rows behind and the machine slowly runs out of memory. - Archive, delete, cascade, workspace-delete, and quick-chat expiration persist a cleanup intent and resource snapshot before mutating or deleting task state. Cleanup is performed by a durable worker rather than a detached goroutine. -- Stop-owner registration is advisory. It uses a non-blocking attempt to acquire - the per-session `cancelInFlightGuard` before it records teardown ownership. -- If that guard is in use, registration skips the claim and the requested stop - continues. Durable cleanup and idempotent runtime teardown handle later races. +- Advisory stop-owner registration skips a contended `cancelInFlightGuard` claim + without blocking; the requested stop and durable cleanup continue. - A durable cleanup job makes at most eight attempts. Failed attempts back off for 1 minute, 5 minutes, 15 minutes, 1 hour, 3 hours, 6 hours, and 12 hours before the next claim. An eighth failed attempt becomes terminal `failed` @@ -255,8 +253,8 @@ primary stop operation when `agent_execution_id` is available. Fallback cleanup runtime-specific and must be bounded by context. `TaskExecutionStopper.RegisterExecutionStopOwner(sessionID, executionID, force)` -must not wait for the per-session cancellation guard. Registration can skip a -contended claim because it is advisory and does not replace the stop operation. +must not wait for the session guard; it may skip a contended claim and never +replaces `StopExecution`. ## State Machine @@ -299,14 +297,15 @@ The durable cleanup job wraps that resource lifecycle: the task only if existing product behavior requires it, but destructive runtime cleanup must fail closed: do not remove runtime rows or worktrees based on an empty or partial inventory. -- If stop-owner registration finds the session guard in use, it skips the claim. - The explicit stop continues, and durable cleanup preserves any retryable work. +- A contended owner claim is skipped; explicit stop continues and durable cleanup + preserves retryable work. - If stopping a runtime execution times out, the process manager escalates to a process-group kill and waits for confirmation. If confirmation still fails, the runtime row remains retryable. - If a runtime row points at a missing in-memory execution, cleanup attempts the runtime-specific persisted handle when available. If no handle can be used, the row is preserved with a warning instead of being silently dropped. +- Keep `models.ErrExecutionRotated` (newer won); warn on other errors. - If a stop operation reports the execution or session is not found and the owned row is a confirmed-dead local runtime, cleanup records the stop as successful, prunes or repairs the row under the resume-safety invariant, proceeds with any @@ -476,6 +475,8 @@ The durable cleanup job wraps that resource lifecycle: a not-found stop is reclassified as successful, **THEN** the row is repaired in place (token and worktree preserved) rather than deleted, per `RowMustBePreserved`. +- **WHEN** compare-and-set returns `models.ErrExecutionRotated`, **THEN** keep + the newer row silently. - **GIVEN** agentctl is stopped while an ACP child process ignores stdin EOF, **WHEN** the stop timeout expires, **THEN** the ACP process group is killed and no ACP child is reparented to PID 1.