fix(backend): classify expected diagnostic failures (#3120)

This commit is contained in:
Carlos Florêncio
2026-08-28 19:24:27 +00:00
committed by GitHub
parent 2015ecb0cd
commit e07a0f98e1
29 changed files with 1355 additions and 32 deletions
@@ -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: "<ts>\t<LEVEL>\t<caller>\t<msg>", 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 "<ts>\t<LEVEL>\t<caller>\t<msg>", so the
// level token must be bounded by at least a following caller field. Requiring
// three segments rejects truncated lines (e.g. "<ts>\t<token>") 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
@@ -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
@@ -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,
@@ -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
}
@@ -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) {
@@ -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.
+8 -3
View File
@@ -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.
@@ -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},
@@ -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)
}
}
@@ -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
@@ -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()
@@ -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
@@ -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
}
@@ -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
}
@@ -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
}
@@ -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.
@@ -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
```
@@ -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
```
@@ -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
```
@@ -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
```
@@ -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
```
+1
View File
@@ -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)
@@ -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.
@@ -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.
+1
View File
@@ -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)
+5 -1
View File
@@ -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)
- Image/file preview rendering in the UI (download link only for now)
@@ -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.
@@ -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.
@@ -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.