diff --git a/apps/backend/internal/backendapp/cron.go b/apps/backend/internal/backendapp/cron.go index a1c825601c..3be3f44ad0 100644 --- a/apps/backend/internal/backendapp/cron.go +++ b/apps/backend/internal/backendapp/cron.go @@ -151,9 +151,12 @@ func (l *heartbeatTaskLister) ListActiveTasksAtStep( // 1. AgentInstance.Status — paused/stopped agents never receive // heartbeats. (idle and working both pass; the runs scheduler's // own checkout layer handles concurrency.) -// 2. CooldownSec since LastRunFinishedAt — when a run finished +// 2. CooldownSec (from agent_profiles) since +// office_agent_runtime.last_run_finished_at — when a run finished // recently the gate suppresses heartbeats so the cooldown is -// respected end-to-end (heartbeat ≠ scheduler). +// respected end-to-end (heartbeat ≠ scheduler). This is a distinct +// column from agent_profiles' own same-named last_run_finished_at, +// which no Office write path stamps and must not be read here. type heartbeatAgentRuntime struct { office *officesqlite.Repository } @@ -175,11 +178,19 @@ func (r *heartbeatAgentRuntime) AllowFire( case officemodels.AgentStatusPaused, officemodels.AgentStatusStopped: return false, nil } - if agent.LastRunFinishedAt != nil && agent.CooldownSec > 0 { - gateUntil := agent.LastRunFinishedAt.Add(time.Duration(agent.CooldownSec) * time.Second) - if now.Before(gateUntil) { - return false, nil - } + if agent.CooldownSec <= 0 { + return true, nil + } + runtime, err := r.office.GetAgentRuntime(ctx, agentID) + if err != nil { + return false, err + } + if runtime == nil || runtime.LastRunFinishedAt == nil { + return true, nil + } + gateUntil := runtime.LastRunFinishedAt.Add(time.Duration(agent.CooldownSec) * time.Second) + if now.Before(gateUntil) { + return false, nil } return true, nil } diff --git a/apps/backend/internal/backendapp/cron_test.go b/apps/backend/internal/backendapp/cron_test.go new file mode 100644 index 0000000000..ec98c671e3 --- /dev/null +++ b/apps/backend/internal/backendapp/cron_test.go @@ -0,0 +1,227 @@ +package backendapp + +import ( + "context" + "path/filepath" + "testing" + "time" + + "github.com/jmoiron/sqlx" + + "github.com/kandev/kandev/internal/agent/settings/store" + "github.com/kandev/kandev/internal/db" + "github.com/kandev/kandev/internal/office/models" + officesqlite "github.com/kandev/kandev/internal/office/repository/sqlite" +) + +// newTestOfficeRepoForCron builds a real office SQLite repository (plus the +// shared agent_profiles schema owned by internal/agent/settings/store) so +// the cooldown gate regression test exercises the actual SELECT/UPDATE +// statements rather than a fake — this is a repository-column bug +// (reading the wrong table's last_run_finished_at), and a fake would +// hide exactly that class of defect. +func newTestOfficeRepoForCron(t *testing.T) (*officesqlite.Repository, *sqlx.DB) { + t.Helper() + dbConn, err := db.OpenSQLite(filepath.Join(t.TempDir(), "cron-cooldown.db")) + if err != nil { + t.Fatalf("open sqlite: %v", err) + } + database := sqlx.NewDb(dbConn, "sqlite3") + t.Cleanup(func() { _ = database.Close() }) + _, cleanup, err := store.Provide(database, database, nil) + if err != nil { + t.Fatalf("agent settings store migrations: %v", err) + } + t.Cleanup(func() { _ = cleanup() }) + repo, err := officesqlite.NewWithDB(database, database, nil) + if err != nil { + t.Fatalf("office migrations: %v", err) + } + // agent_profiles.agent_id is a FK into agents (CLI tool registrations); + // seed one so CreateAgentInstance's insert satisfies it. + now := time.Now().UTC() + if _, err := database.ExecContext(context.Background(), + `INSERT INTO agents (id, name, created_at, updated_at) VALUES (?, ?, ?, ?)`, + "agent-cli-tool", "cli-tool", now, now, + ); err != nil { + t.Fatalf("seed agents row: %v", err) + } + return repo, database +} + +// TestHeartbeatAgentRuntime_AllowFire_ReadsOfficeRuntimeCooldown is the +// regression test for the cooldown-gate defect: AllowFire must gate on +// office_agent_runtime.last_run_finished_at (the column +// Service.stampRunFinished actually maintains), not +// agent_profiles.last_run_finished_at (a same-named column inherited +// from the shared kanban agent-settings table that no Office write path +// ever stamps). Before the fix, AllowFire read the agent_profiles +// column, which stays NULL for Office agents, so the cooldown branch +// never triggered and every case below returned true regardless of the +// office_agent_runtime state. +func TestHeartbeatAgentRuntime_AllowFire_ReadsOfficeRuntimeCooldown(t *testing.T) { + repo, _ := newTestOfficeRepoForCron(t) + ctx := context.Background() + gate := &heartbeatAgentRuntime{office: repo} + + agent := &models.AgentInstance{ + ID: "agent-cooldown-1", + WorkspaceID: "ws-1", + Name: "cooldown-worker", + Role: models.AgentRoleWorker, + Status: models.AgentStatusIdle, + CooldownSec: 60, + } + if err := repo.CreateAgentInstance(ctx, agent); err != nil { + t.Fatalf("create agent: %v", err) + } + + now := time.Now().UTC() + + // Poison agent_profiles.last_run_finished_at with a value inside the + // 60s cooldown window (now - 5s), not outside it. If AllowFire were + // still reading this column instead of office_agent_runtime, this + // poisoned value alone would gate Case 1 below (no office_agent_runtime + // row yet, wants true) since it never changes across cases — proving + // the column is not consulted. Also confirms this column round-trips + // harmlessly and is not itself relied on by the fixed gate. + staleAgentProfilesValue := now.Add(-5 * time.Second) + agent.LastRunFinishedAt = &staleAgentProfilesValue + if err := repo.UpdateAgentInstance(ctx, agent); err != nil { + t.Fatalf("poison agent_profiles.last_run_finished_at: %v", err) + } + + // Case 1: no office_agent_runtime row yet -> an agent that has never + // run is not gated by cooldown. + allowed, err := gate.AllowFire(ctx, agent.ID, now) + if err != nil { + t.Fatalf("AllowFire (no runtime row): %v", err) + } + if !allowed { + t.Error("AllowFire (no runtime row) = false, want true (never-run agent must not be gated)") + } + + // Stamp office_agent_runtime.last_run_finished_at to "just now". + if err := repo.UpdateRuntimeLastRunFinished(ctx, agent.ID, now); err != nil { + t.Fatalf("stamp runtime: %v", err) + } + runtime, err := repo.GetAgentRuntime(ctx, agent.ID) + if err != nil || runtime == nil || runtime.LastRunFinishedAt == nil { + t.Fatalf("read stamped runtime: runtime=%+v, err=%v", runtime, err) + } + + // Case 2: 30s into a 60s cooldown -> blocked. + allowed, err = gate.AllowFire(ctx, agent.ID, runtime.LastRunFinishedAt.Add(30*time.Second)) + if err != nil { + t.Fatalf("AllowFire (within cooldown): %v", err) + } + if allowed { + t.Error("AllowFire (within cooldown) = true, want false") + } + + // Case 3: exactly 60s after the stamp -> cooldown elapsed, allowed. + allowed, err = gate.AllowFire(ctx, agent.ID, runtime.LastRunFinishedAt.Add(60*time.Second)) + if err != nil { + t.Fatalf("AllowFire (at cooldown boundary): %v", err) + } + if !allowed { + t.Error("AllowFire (at cooldown boundary) = false, want true") + } +} + +func TestHeartbeatAgentRuntime_AllowFire_NullRuntimeTimestampAllows(t *testing.T) { + repo, database := newTestOfficeRepoForCron(t) + ctx := context.Background() + gate := &heartbeatAgentRuntime{office: repo} + agent := &models.AgentInstance{ + ID: "agent-cooldown-null", + WorkspaceID: "ws-1", + Name: "null-timestamp-worker", + Role: models.AgentRoleWorker, + Status: models.AgentStatusIdle, + CooldownSec: 60, + } + if err := repo.CreateAgentInstance(ctx, agent); err != nil { + t.Fatalf("create agent: %v", err) + } + if err := repo.UpdateRuntimeLastRunFinished(ctx, agent.ID, time.Now().UTC()); err != nil { + t.Fatalf("stamp runtime: %v", err) + } + if _, err := database.ExecContext(ctx, + `UPDATE office_agent_runtime SET last_run_finished_at = NULL WHERE agent_id = ?`, + agent.ID, + ); err != nil { + t.Fatalf("clear runtime timestamp: %v", err) + } + + allowed, err := gate.AllowFire(ctx, agent.ID, time.Now().UTC()) + if err != nil { + t.Fatalf("AllowFire (null runtime timestamp): %v", err) + } + if !allowed { + t.Error("AllowFire (null runtime timestamp) = false, want true") + } +} + +func TestHeartbeatAgentRuntime_AllowFire_RuntimeLookupErrorBlocks(t *testing.T) { + repo, database := newTestOfficeRepoForCron(t) + ctx := context.Background() + gate := &heartbeatAgentRuntime{office: repo} + agent := &models.AgentInstance{ + ID: "agent-cooldown-error", + WorkspaceID: "ws-1", + Name: "lookup-error-worker", + Role: models.AgentRoleWorker, + Status: models.AgentStatusIdle, + CooldownSec: 60, + } + if err := repo.CreateAgentInstance(ctx, agent); err != nil { + t.Fatalf("create agent: %v", err) + } + if _, err := database.ExecContext(ctx, `DROP TABLE office_agent_runtime`); err != nil { + t.Fatalf("drop runtime table: %v", err) + } + + allowed, err := gate.AllowFire(ctx, agent.ID, time.Now().UTC()) + if err == nil { + t.Fatal("AllowFire (runtime lookup error) returned nil error") + } + if allowed { + t.Error("AllowFire (runtime lookup error) = true, want false") + } +} + +// TestHeartbeatAgentRuntime_AllowFire_ZeroCooldownSkipsRuntimeLookup +// pins the existing short-circuit: cooldown_sec <= 0 always allows +// firing without querying office_agent_runtime at all. The runtime +// table is dropped before the call, so an implementation that queries +// it anyway (instead of skipping) would surface as an error here +// rather than an unproven true. +func TestHeartbeatAgentRuntime_AllowFire_ZeroCooldownSkipsRuntimeLookup(t *testing.T) { + repo, database := newTestOfficeRepoForCron(t) + ctx := context.Background() + gate := &heartbeatAgentRuntime{office: repo} + + agent := &models.AgentInstance{ + ID: "agent-cooldown-2", + WorkspaceID: "ws-1", + Name: "no-cooldown-worker", + Role: models.AgentRoleWorker, + Status: models.AgentStatusIdle, + CooldownSec: 0, + } + if err := repo.CreateAgentInstance(ctx, agent); err != nil { + t.Fatalf("create agent: %v", err) + } + if _, err := database.ExecContext(ctx, `DROP TABLE office_agent_runtime`); err != nil { + t.Fatalf("drop office_agent_runtime: %v", err) + } + + allowed, err := gate.AllowFire(ctx, agent.ID, time.Now().UTC()) + if err != nil { + t.Fatalf("AllowFire queried office_agent_runtime despite cooldown_sec=0: %v", err) + } + if !allowed { + t.Error("AllowFire (cooldown_sec=0) = false, want true") + } +} diff --git a/apps/backend/internal/office/service/failure.go b/apps/backend/internal/office/service/failure.go index 45a2c897e3..9da61abf2e 100644 --- a/apps/backend/internal/office/service/failure.go +++ b/apps/backend/internal/office/service/failure.go @@ -27,6 +27,9 @@ const ( // is treated as terminal. The run is marked failed with the verbatim // error message, the consecutive-failure counter is incremented, and // when it crosses the effective threshold the agent is auto-paused. +// It also stamps office_agent_runtime.last_run_finished_at the same as +// the completed/stopped paths, so cooldown_sec paces the agent's next +// heartbeat-driven fire regardless of why the previous run ended. // // No retry is scheduled — the user resolves via Resume session in the // chat or Mark fixed in the inbox. @@ -50,6 +53,7 @@ func (s *Service) HandleAgentFailure( // here keeps the agent out of a stuck "working" even if the failure // bookkeeping that follows errors out. s.clearAgentWorking(ctx, run.AgentProfileID, run.ID) + s.stampRunFinished(ctx, run) count, err := s.repo.IncrementAgentConsecutiveFailures(ctx, run.AgentProfileID) if err != nil { diff --git a/apps/backend/internal/office/service/scheduler_checkout_release_test.go b/apps/backend/internal/office/service/scheduler_checkout_release_test.go index c5ed401244..f463d17607 100644 --- a/apps/backend/internal/office/service/scheduler_checkout_release_test.go +++ b/apps/backend/internal/office/service/scheduler_checkout_release_test.go @@ -39,7 +39,6 @@ func TestSchedulerTick_AgentCompletedReleasesTaskCheckout(t *testing.T) { t.Fatalf("register subscribers: %v", err) } beforePublish := time.Now().UTC() - agent := &models.AgentInstance{ ID: "profile-checkout-release", WorkspaceID: "ws-1", @@ -113,7 +112,11 @@ func TestSchedulerTick_AgentCompletedReleasesTaskCheckout(t *testing.T) { // TestSchedulerTick_AgentFailedReleasesTaskCheckout is the failure-path // counterpart: HandleAgentFailure calls repo.MarkRunFailed directly // (not Service.FailRun / transitionRunTerminal), so it needs the same -// checkout-release treatment as the completion path. +// checkout-release treatment as the completion path. It also covers the +// cooldown-stamp parity gap: HandleAgentFailure must stamp +// office_agent_runtime.last_run_finished_at the same as the +// completed/stopped paths do, so a below-threshold failing agent is +// still paced by cooldown_sec on its next heartbeat-driven fire. func TestSchedulerTick_AgentFailedReleasesTaskCheckout(t *testing.T) { mock := &mockTaskStarter{} svc := newTestService(t, service.ServiceOptions{TaskStarter: mock}) @@ -169,6 +172,7 @@ func TestSchedulerTick_AgentFailedReleasesTaskCheckout(t *testing.T) { "error_message": "boom", "agent_profile_id": agent.ID, }) + beforePublish := time.Now().UTC() if err := eb.Publish(ctx, events.AgentFailed, event); err != nil { t.Fatalf("publish agent failed: %v", err) } @@ -180,6 +184,17 @@ func TestSchedulerTick_AgentFailedReleasesTaskCheckout(t *testing.T) { if !ok { t.Fatal("expected task checkout to be released after AgentFailed, but another agent still cannot check it out") } + + runtime, err := svc.GetAgentRuntimeForTest(ctx, agent.ID) + if err != nil { + t.Fatalf("get agent runtime: %v", err) + } + if runtime == nil || runtime.LastRunFinishedAt == nil { + t.Fatal("expected last_run_finished_at to be stamped after AgentFailed, but it is still unset") + } + if runtime.LastRunFinishedAt.Before(beforePublish) { + t.Errorf("last_run_finished_at = %v, want at/after %v", runtime.LastRunFinishedAt, beforePublish) + } } // TestSchedulerTick_TasklessAgentCompletedStampsRuntime is the taskless-path diff --git a/docs/plans/office-cooldown-wire/plan.md b/docs/plans/office-cooldown-wire/plan.md new file mode 100644 index 0000000000..5342341fac --- /dev/null +++ b/docs/plans/office-cooldown-wire/plan.md @@ -0,0 +1,81 @@ +--- +spec: docs/specs/office/agents.md +created: 2026-08-22 +status: done +--- + +# Implementation Plan: Wire the Office agent cooldown gate + +## Overview + +PR #2902 fixed `office_agent_runtime.last_run_finished_at` to be stamped correctly on every +completed/stopped run (sync and async, task-bound and taskless), but explicitly scoped out two +follow-ups. This plan closes both, resolved together because they're the same underlying question +("what does the Office heartbeat cooldown gate mean?"): + +1. **Wrong column.** `heartbeatAgentRuntime.AllowFire` (`internal/backendapp/cron.go`) reads + `agent_profiles.last_run_finished_at` — a column from the shared kanban agent-settings table + that no Office write path ever stamps — instead of `office_agent_runtime.last_run_finished_at`, + the column `Service.stampRunFinished` actually maintains. `agent.LastRunFinishedAt != nil` is + therefore always false and the cooldown branch never fires: Office heartbeat cooldown is + silently a no-op today, regardless of `cooldown_sec`. +2. **Missing stamp on failure.** `HandleAgentFailure` (`internal/office/service/failure.go`) marks + a run failed and releases its task checkout but never calls `stampRunFinished`. Once (1) is + fixed, a below-threshold failing agent would be exempt from cooldown pacing entirely (unlike a + successful or stopped run), letting a flapping agent retry with zero pacing until it crosses the + auto-pause threshold. + +Resolved spec decision (see amendments below): cooldown paces **every** terminal run outcome for an +agent — completed, stopped, taskless-completed, and failed alike — uniformly. It is a run-pacing +mechanism, not a success tracker. The separate consecutive-failure counter / auto-pause threshold +remains the mechanism for stopping a chronically broken agent; cooldown only paces the failures that +happen before that threshold is reached. + +Out of scope: removing or migrating the dead `agent_profiles.last_run_finished_at` column (bigger +blast radius across the shared kanban agent-settings table; not needed to fix the bug — the gate +just needs to stop reading it). No schema change. No frontend change. + +## Spec amendments (already applied) + +- `docs/specs/office/agents.md` — persistence-guarantees bullet for `office_agent_runtime` now + names the exact gate (`heartbeatAgentRuntime.AllowFire`), states which column it must read, and + explicitly calls out the `agent_profiles` same-named column as dead/not-authoritative. +- `docs/specs/office/runtime.md` — "Retry policy" section states that a terminal failure stamps the + cooldown timestamp same as success; a new persistence-guarantee bullet and a new GIVEN/WHEN/THEN + scenario cover it. + +## Backend + +### Task 01: Cooldown gate reads `office_agent_runtime`, not `agent_profiles` — done + +`heartbeatAgentRuntime.AllowFire` currently gates on `agent.LastRunFinishedAt` (from +`office.GetAgentInstance`, i.e. `agent_profiles`). Change it to load the runtime row via +`office.GetAgentRuntime(ctx, agentID)` (already exists, returns `*officesqlite.RuntimeState` with +`LastRunFinishedAt *time.Time`, `nil, nil` when no row) and gate on that timestamp instead. +`agent.CooldownSec` still comes from `agent_profiles` (that field is actively written and unrelated +to this bug). No repository or schema change — `GetAgentRuntime` already exists and is already +exercised by other tests. + +### Task 02: `HandleAgentFailure` stamps the cooldown timestamp — done + +Add a `s.stampRunFinished(ctx, run)` call to `HandleAgentFailure` (`internal/office/service/failure.go`), +placed after `s.releaseTaskCheckoutForRun(ctx, run)` and before the consecutive-failure counter +work, mirroring the completed/stopped paths' ordering (finish/mark → release checkout → stamp). +`stampRunFinished` is already shared, idempotent, and no-ops safely on a nil run or empty +`AgentProfileID`; this task is a one-line call plus a test. + +## Task waves + +| Wave | Tasks | Parallel-safe | +|------|-------|----------------| +| 1 | 01, 02 | Yes — disjoint files (`internal/backendapp/cron.go` vs `internal/office/service/failure.go`), disjoint test files, no shared schema/migration/generated contract. | + +Default `parallelism: sequential` in each task file per repo convention; the table above is a human +dispatch aid, not standing authorization to delegate to subagents. + +## Validation + +```bash +cd apps/backend && go test ./internal/backendapp/... ./internal/office/service/... ./internal/office/repository/sqlite/... +cd apps/backend && golangci-lint run ./internal/backendapp/... ./internal/office/service/... --timeout=5m +``` diff --git a/docs/plans/office-cooldown-wire/task-01-cooldown-gate-column.md b/docs/plans/office-cooldown-wire/task-01-cooldown-gate-column.md new file mode 100644 index 0000000000..20171fb41f --- /dev/null +++ b/docs/plans/office-cooldown-wire/task-01-cooldown-gate-column.md @@ -0,0 +1,136 @@ +--- +id: "01-cooldown-gate-column" +title: "Wire the heartbeat cooldown gate to office_agent_runtime" +status: done +wave: 1 +depends_on: [] +plan: "plan.md" +spec: "../../specs/office/agents.md" +--- + +# Task 01: Wire the heartbeat cooldown gate to `office_agent_runtime` + +## Root cause + +`heartbeatAgentRuntime.AllowFire` (`apps/backend/internal/backendapp/cron.go:160-184`) loads the +agent via `r.office.GetAgentInstance(ctx, agentID)` and gates on `agent.LastRunFinishedAt`. That +field is `models.AgentInstance.LastRunFinishedAt`, which maps to `agent_profiles.last_run_finished_at` +— a column owned by the shared kanban agent-settings store +(`internal/agent/settings/store/sqlite.go`). No Office write path ever sets that field (confirmed: +`grep -rn '\.LastRunFinishedAt\s*=' apps/backend/internal` outside test files matches nothing), so +it round-trips as whatever the row already had — effectively always NULL for Office agents. The gate +condition `agent.LastRunFinishedAt != nil && agent.CooldownSec > 0` is therefore always false and the +cooldown branch never executes. + +PR #2902 correctly and centrally stamps `office_agent_runtime.last_run_finished_at` (via +`Service.stampRunFinished` -> `Repository.UpdateRuntimeLastRunFinished`) on every completed/stopped +run. That is the column the spec (`docs/specs/office/agents.md` persistence guarantees, and now this +plan's spec amendment) documents as the cooldown guard's source of truth. `office.GetAgentRuntime(ctx, +agentID)` (`internal/office/repository/sqlite/runtime.go:20`) already reads it and returns +`*RuntimeState{LastRunFinishedAt *time.Time}`, `nil, nil` when the agent has no runtime row yet. + +## Acceptance + +- `heartbeatAgentRuntime.AllowFire` gates on `office_agent_runtime.last_run_finished_at` (via + `office.GetAgentRuntime`), not `agent_profiles.last_run_finished_at`. +- `agent.CooldownSec` (from `agent_profiles`, via `GetAgentInstance`) is still the cooldown duration + source — unchanged. +- No runtime row (`GetAgentRuntime` returns `nil, nil`) or `LastRunFinishedAt == nil` on the runtime + row still allows firing (an agent that has never run is not gated) — same behavior as today, just + reading the right column. +- `CooldownSec <= 0` still skips the runtime lookup entirely and always allows firing — preserve the + existing short-circuit / avoid an unconditional extra query. +- Update the doc comment above `heartbeatAgentRuntime` (lines ~149-155) to name the column + explicitly instead of the generic "LastRunFinishedAt" it currently says. + +## Regression test + +Add `apps/backend/internal/backendapp/cron_test.go` (package `backendapp`, same package as +`cron.go` — `heartbeatAgentRuntime` is unexported). Follow the harness pattern already used in +`adapters_office_test.go`'s `newOfficeTaskAdapterHarness` (`db.OpenSQLite` + `officesqlite.NewWithDB`) +to build a real `*officesqlite.Repository` — this is a repository-column bug, so exercise the actual +SQL, not a fake. + +Test (must fail before the fix, pass after): + +1. Create an `AgentInstance` with `CooldownSec: 60`, `Status: idle`. +2. Stamp `office_agent_runtime.last_run_finished_at` to `time.Now().UTC()` via + `repo.UpdateRuntimeLastRunFinished(ctx, agent.ID, now)`. +3. Separately write a stale/irrelevant value into `agent_profiles.last_run_finished_at` for the same + agent (e.g. `repo.UpdateAgentInstance` with `LastRunFinishedAt: &tenMinutesAgo`, or raw SQL) to + prove the gate does not read that column — pre-fix this would make the test pass for the wrong + reason if the assertion only checked "blocked", so assert specifically that firing is blocked + despite `agent_profiles.last_run_finished_at` being far outside any cooldown window. +4. Call `(&heartbeatAgentRuntime{office: repo}).AllowFire(ctx, agent.ID, now.Add(30*time.Second))` + (30s into a 60s cooldown) and assert `false, nil`. +5. Call `AllowFire` again with `now.Add(61*time.Second)` and assert `true, nil` (cooldown elapsed). +6. A second case with no `office_agent_runtime` row at all (skip step 2) asserts `true, nil` — + never-run agents are not gated. + +## Verification + +```bash +cd apps/backend && go test ./internal/backendapp/... -run TestHeartbeatAgentRuntime -v +cd apps/backend && go test ./internal/backendapp/... +cd apps/backend && golangci-lint run ./internal/backendapp/... --new-from-rev=HEAD~1 --timeout=5m +``` + +## Files likely touched + +- `apps/backend/internal/backendapp/cron.go` +- `apps/backend/internal/backendapp/cron_test.go` (new) + +## Dependencies + +None. + +## Parallelism + +Sequential. Marked parallel-safe with Task 02 at the plan level (disjoint files/tests, no shared +schema) but this repo's convention keeps `parallelism: sequential` as the per-task default; delegate +only on explicit user authorization. + +## Inputs + +- Spec: `docs/specs/office/agents.md` persistence-guarantees bullet (amended by this plan). +- Existing pattern: `apps/backend/internal/office/repository/sqlite/runtime_test.go` for + `GetAgentRuntime`/`UpdateRuntimeLastRunFinished` behavior; `adapters_office_test.go` for the + `backendapp`-package office-repo test harness. + +## Risks + +- `GetAgentInstance` and `GetAgentRuntime` are two separate queries per positive-cooldown + `AllowFire` call (previously one). The heartbeat handler calls the gate for each candidate task, + so the extra runtime query is per candidate task that reaches this gate. This remains a small + load for the heartbeat pass; do not attempt to fold the queries into a JOIN as part of this fix. +- Do not touch `agent_profiles.last_run_finished_at` itself (no migration, no field removal) — out + of scope per the plan; it's dead for Office cooldown purposes but may still round-trip harmlessly + through the shared kanban settings store. + +## Output contract + +Report the exact `AllowFire` behavior before/after, files changed, exact commands and results, +blockers/risks, then mark this task `done` and update its checkbox in `plan.md`. + +## Completion report + +- **Before**: `AllowFire` gated on `agent.LastRunFinishedAt` (`agent_profiles.last_run_finished_at` + via `GetAgentInstance`), a column no Office write path ever stamps — the cooldown branch never + fired. Reproduced by `TestHeartbeatAgentRuntime_AllowFire_ReadsOfficeRuntimeCooldown`, which failed + pre-fix with `AllowFire (within cooldown) = true, want false`. +- **After**: `AllowFire` short-circuits to `true` when `CooldownSec <= 0` (unchanged), otherwise loads + `office_agent_runtime` via `office.GetAgentRuntime` and gates on `runtime.LastRunFinishedAt`. No + runtime row, or a nil `LastRunFinishedAt`, still allows firing (never-run agent not gated). + `agent_profiles.last_run_finished_at` is no longer read by the gate at all. +- Files changed: `apps/backend/internal/backendapp/cron.go` (production fix + doc comment), + `apps/backend/internal/backendapp/cron_test.go` (new — two regression tests). +- Commands and results: + - `go test ./internal/backendapp/... -run TestHeartbeatAgentRuntime -v` — fails before the fix + (`within cooldown` case wrongly allows), passes after (both tests green). + - `go test ./internal/backendapp/...` — `ok` (all packages). + - `golangci-lint run ./internal/backendapp/... --new-from-rev=HEAD --timeout=5m` — `0 issues`. +- Blockers/risks: none. Confirmed two extra one-time setup steps needed in the test harness beyond + the plan's sketch: the shared `agent_profiles`/`agents` schema is owned by + `internal/agent/settings/store` (not the office or task repos), and `agent_profiles.agent_id` has a + FK into `agents` that required seeding one row — both are test-only harness details, no production + code implication. diff --git a/docs/plans/office-cooldown-wire/task-02-stamp-on-failure.md b/docs/plans/office-cooldown-wire/task-02-stamp-on-failure.md new file mode 100644 index 0000000000..7d8d699cf5 --- /dev/null +++ b/docs/plans/office-cooldown-wire/task-02-stamp-on-failure.md @@ -0,0 +1,141 @@ +--- +id: "02-stamp-on-failure" +title: "Stamp last_run_finished_at on agent failure" +status: done +wave: 1 +depends_on: [] +plan: "plan.md" +spec: "../../specs/office/runtime.md" +--- + +# Task 02: Stamp `last_run_finished_at` on agent failure + +## Root cause / resolved decision + +`HandleAgentFailure` (`apps/backend/internal/office/service/failure.go:29-66`) marks the run failed +(`MarkRunFailed`) and releases the task checkout (`releaseTaskCheckoutForRun`) but never calls +`stampRunFinished`. Flagged by Greptile on PR #2902 +(https://github.com/kdlbs/kandev/pull/2902#discussion_r3832467867) and confirmed real by reading the +code. PR #2902 deliberately scoped its own fix to `AgentCompleted`/`AgentStopped` (and their taskless +variants) only. + +Resolved via the spec amendment in this plan (`docs/specs/office/runtime.md` "Retry policy"): +cooldown paces every terminal run outcome uniformly, including failure. Rationale: `cooldown_sec` +is a run-pacing mechanism keyed on "time since this agent last ran," not a success tracker — the +column name (`last_run_finished_at`, not `last_success_finished_at`) and the pre-existing spec +language ("cooldown between agent runs") already point this way. Once Task 01 wires the gate +correctly, an unstamped failure path would leave a below-threshold failing agent completely exempt +from pacing (unlike success/stop), which is the opposite of the safe default: a flapping provider or +a misconfigured agent could re-fire immediately after every failure with zero pacing, burning +cost/tokens on repeated attempts before the separate consecutive-failure/auto-pause threshold (a +different, coarser mechanism — unaffected by this change) eventually kicks in. + +Note `HandleAgentFailure` is only reached when `tryPostStartFallback` (the routing-dispatcher retry +path, gated on `run.ResolvedProviderID` via `markShortProviderCooldown`) returns `false` — i.e. only +for a genuinely terminal failure, not a provider-routing retry. Stamping here does not double up with +or interfere with that separate, already-cooldown-aware retry path. + +## Acceptance + +- `HandleAgentFailure` calls `s.stampRunFinished(ctx, run)`, placed after + `s.releaseTaskCheckoutForRun(ctx, run)` and before `IncrementAgentConsecutiveFailures`, mirroring + the completed/stopped paths' ordering (terminal-mark -> release checkout -> stamp). +- The shared `stampRunFinished` helper remains a no-op for `run == nil` or an empty + `run.AgentProfileID`. `HandleAgentFailure` itself still requires a non-nil run because it reads + `run.ID` before it calls the helper. +- No change to the consecutive-failure counter, auto-pause threshold, or auto-pause behavior — this + task only adds the cooldown stamp. + +## Regression test + +Extend the existing `TestSchedulerTick_AgentFailedReleasesTaskCheckout` in +`apps/backend/internal/office/service/scheduler_checkout_release_test.go` (does not currently assert +the runtime stamp — only checkout release) rather than duplicating its full setup in a new function. +Mirror the assertion already used by `TestSchedulerTick_AgentCompletedReleasesTaskCheckout` in the +same file: + +1. Capture `beforePublish := time.Now().UTC()` immediately before publishing the + `events.AgentFailed` event, after setup and scheduler dispatch. +2. After the existing checkout-reacquisition assertion, add: + ```go + runtime, err := svc.GetAgentRuntimeForTest(ctx, agent.ID) + if err != nil { + t.Fatalf("get agent runtime: %v", err) + } + if runtime == nil || runtime.LastRunFinishedAt == nil { + t.Fatal("expected last_run_finished_at to be stamped after AgentFailed, but it is still unset") + } + if runtime.LastRunFinishedAt.Before(beforePublish) { + t.Errorf("last_run_finished_at = %v, want at/after %v", runtime.LastRunFinishedAt, beforePublish) + } + ``` +3. Update the function's doc comment (currently states it is "the failure-path counterpart" only for + checkout release) to also note it now covers the cooldown-stamp parity. + +This assertion must fail before the code change (no stamp call exists yet -> `runtime` is nil or +`LastRunFinishedAt` is nil) and pass after. + +## Verification + +```bash +cd apps/backend && go test ./internal/office/service/... -run TestSchedulerTick_AgentFailed -v +cd apps/backend && go test ./internal/office/service/... +cd apps/backend && golangci-lint run ./internal/office/service/... --new-from-rev=HEAD --timeout=5m +``` + +## Files likely touched + +- `apps/backend/internal/office/service/failure.go` +- `apps/backend/internal/office/service/scheduler_checkout_release_test.go` + +## Dependencies + +None. + +## Parallelism + +Sequential. Marked parallel-safe with Task 01 at the plan level (disjoint files/tests, no shared +schema) but this repo's convention keeps `parallelism: sequential` as the per-task default; delegate +only on explicit user authorization. + +## Inputs + +- Spec: `docs/specs/office/runtime.md` "Retry policy" section and the new persistence-guarantee + bullet / scenario (amended by this plan). +- Existing pattern: `TestSchedulerTick_AgentCompletedReleasesTaskCheckout` and + `TestSchedulerTick_TasklessAgentCompletedStampsRuntime` in the same test file — both already + assert the identical `GetAgentRuntimeForTest` / `LastRunFinishedAt` shape for the success paths. + +## Risks + +- None expected — `stampRunFinished` is already shared, already covered by its own nil/empty-ID + guard, and already exercised by three other call sites. This is additive; no existing behavior + changes. + +## Output contract + +Report the exact before/after stamping behavior, files changed, exact commands and results, +blockers/risks, then mark this task `done` and update its checkbox in `plan.md`. + +## Completion report + +- **Before**: `HandleAgentFailure` marked the run failed and released the task checkout but never + called `stampRunFinished` — `office_agent_runtime.last_run_finished_at` stayed unset after a + failure, exempting a below-threshold failing agent from cooldown pacing entirely. Reproduced by + extending `TestSchedulerTick_AgentFailedReleasesTaskCheckout`, which failed pre-fix with + `expected last_run_finished_at to be stamped after AgentFailed, but it is still unset`. +- **After**: `HandleAgentFailure` calls `s.stampRunFinished(ctx, run)` immediately after + `s.releaseTaskCheckoutForRun(ctx, run)`, before the consecutive-failure counter logic — mirroring + the completed/stopped paths' ordering. No change to the counter, threshold, or auto-pause behavior. +- Files changed: `apps/backend/internal/office/service/failure.go` (one-line call + doc comment), + `apps/backend/internal/office/service/scheduler_checkout_release_test.go` (extended existing test + with `beforePublish` capture + runtime-stamp assertions, updated doc comment). +- Commands and results: + - `go test ./internal/office/service/... -run TestSchedulerTick_AgentFailed -v` — fails before the + fix (stamp assertion), passes after (all subtests green). + - `go test ./internal/office/service/...` — `ok`. + - `golangci-lint run ./internal/office/service/... --new-from-rev=HEAD --timeout=5m` — `0 issues`. + - Plan-level validation (`go test ./internal/backendapp/... ./internal/office/service/... + ./internal/office/repository/sqlite/...`) — all `ok`. +- Blockers/risks: none. Behavior is additive and uses the already-shared, already-nil-safe + `stampRunFinished` helper exactly as planned. diff --git a/docs/specs/office/system-design/agents-03.md b/docs/specs/office/system-design/agents-03.md index dfa87f7357..540436c089 100644 --- a/docs/specs/office/system-design/agents-03.md +++ b/docs/specs/office/system-design/agents-03.md @@ -27,7 +27,7 @@ What survives a kandev backend restart: - **Agent identity** persists in `agent_profiles` (Office rows: `workspace_id != '' AND deleted_at IS NULL`). Name, role, icon, `reports_to`, Office permissions, budget, concurrency/cooldown settings, skills, instructions, executor preference, and failure policy are durable on the stable identity. Startup profile reconciliation must not replace an Office agent's name with a generated model label. - **Execution configuration** is referenced, not copied, for Office launches. The resolved `execution_profile_id` supplies the provider CLI, account environment, model, mode, ACP config options, CLI flags and permissions, passthrough behavior, and MCP configuration. Route attempts and sessions retain that ID for audit and restart recovery. -- **Runtime status** persists in `office_agent_runtime` (PK `agent_id`). On restart a `paused` agent stays `paused`, `pause_reason` (e.g. `"budget"`) is preserved, and `last_run_finished_at` is retained so the cooldown guard works across restarts. +- **Runtime status** persists in `office_agent_runtime` (PK `agent_id`). On restart a `paused` agent stays `paused`, `pause_reason` (e.g. `"budget"`) is preserved, and `last_run_finished_at` is retained so the cooldown guard works across restarts. The heartbeat cooldown gate (`heartbeatAgentRuntime.AllowFire` in `internal/backendapp/cron.go`) reads this `office_agent_runtime.last_run_finished_at` column together with `agent_profiles.cooldown_sec` to decide whether enough time has elapsed since the agent's last run. `agent_profiles` carries its own same-named `last_run_finished_at` column, inherited from the shared kanban agent-settings table — no Office write path stamps it, so it is not the cooldown source of truth and must not be read for gating. Every terminal run for an agent — completed, stopped, taskless-completed, or failed — stamps `office_agent_runtime.last_run_finished_at` via `Service.stampRunFinished`, so `cooldown_sec` paces the next heartbeat-driven fire uniformly regardless of outcome; see [Office Agent Runtime — Error Handling Contract](../requirements/runtime.md) for the failure-path detail. - **Reconciliation at startup**: `infra.Reconciler.ReconcileAll` (called once during boot) drops `office_agent_runtime` rows whose `agent_id` no longer exists in `agent_profiles`, deletes `office_channels` and `office_budget_policies` rows that reference removed agents/projects, and seeds default routine triggers for routines without one. Reconciliation is best-effort: any sub-step that errors is logged but does not block boot. - **Hire requests** persist as `pending_approval` agent rows plus an approval entry in the inbox. A restart mid-hire leaves the approval visible; the user can still approve or reject and the same activation/deletion paths run. - **Instructions** (`AGENTS.md`, `HEARTBEAT.md`, `SOUL.md`, `TOOLS.md` and any custom files) live in the office DB (`office_agent_instructions`) as the source of truth. The exported copy under `~/.kandev/runtime//instructions//` is regenerated from DB on every session preparation — losing or wiping this directory between runs has no observable effect. diff --git a/docs/specs/office/system-design/runtime-01.md b/docs/specs/office/system-design/runtime-01.md index 58737df9f8..2781e05cc5 100644 --- a/docs/specs/office/system-design/runtime-01.md +++ b/docs/specs/office/system-design/runtime-01.md @@ -68,6 +68,7 @@ A follow-up spec can introduce per-adapter classification once we have real usag - No automatic retry. Every adapter error is terminal for the wakeup that produced it. - The wakeup row is stamped with `status = failed` and `error_message`. No follow-up wakeup is queued from the failure path. - Re-runs only happen via explicit user action: **Resume session** in chat, **Mark fixed** on an inbox entry, or task reassignment to a different agent. +- A terminal failure still stamps `office_agent_runtime.last_run_finished_at` — `HandleAgentFailure` calls the same `Service.stampRunFinished` helper the completed/stopped paths use. Cooldown is a run-pacing mechanism, not a success tracker: a below-threshold failing agent is paced by `cooldown_sec` on its next heartbeat-driven fire exactly as it would be after a success, so a flapping provider or a misconfigured agent cannot retry back-to-back with zero pacing and burn cost/tokens before hitting auto-pause. This applies uniformly across every task assigned to the agent, not just the one that just failed - `cooldown_sec` gates the agent's next heartbeat-triggered fire, regardless of which task last failed. It does not gate task assignment or manual resume: those go through the runs scheduler's `ClaimNextRun`/`ProcessRunGuard` path, which does not consult `last_run_finished_at`. The consecutive-failure counter and auto-pause threshold (below) are the separate, existing mechanism for stopping a chronically broken agent altogether; cooldown only paces the failures that happen before that threshold is reached. ### Inbox surfacing @@ -288,6 +289,7 @@ Recovery and runtime-action authorization splits across three actors: human user - **Capability snapshot on the run** (`runs.capabilities`, `runs.input_snapshot`): durable, written by `ContextBuilder.BuildAndPersist`. A re-issued JWT after restart uses the same capability set so the run keeps the permissions it was granted at claim time. - **Agent JWT signing key**: process-local. Defaults to a random 32-byte key when the `KANDEV_AGENT_JWT_KEY` config is empty, in which case all in-flight JWTs are invalidated on restart and agents must mint fresh tokens on the next prompt cycle. Configurable for stable cross-restart JWTs. - **`affected_tasks` snapshot on `agent_paused_after_failures`**: NOT recomputed when listed tasks are reassigned away. The snapshot is intentionally point-in-time so the user resolves the pause entry as a whole. +- **`office_agent_runtime.last_run_finished_at`**: durable. Stamped on every terminal run outcome for the agent, including failure - not just completion/stop - so the heartbeat cooldown gate paces the agent's next fire regardless of why the previous run ended. See [`office/agents.md`](../requirements/agents.md#persistence-guarantees) persistence guarantees for the gate itself. - **`scheduled_retry` runs**: not produced in v1. Every adapter error is terminal; the wakeup is stamped `failed` with no follow-up scheduled. The `scheduled_retry` status is reserved for a future classifier. See also: [Dynamic Agent Routing](../../agents/requirements/dynamic-agent-routing.md) for provider routing and [`office/scheduler.md`](../requirements/scheduler.md) for wakeup queue semantics and the staleness check that cancels superseded wakeups. diff --git a/docs/specs/office/system-design/runtime-02.md b/docs/specs/office/system-design/runtime-02.md index 3199e8d148..1ee99bb279 100644 --- a/docs/specs/office/system-design/runtime-02.md +++ b/docs/specs/office/system-design/runtime-02.md @@ -27,6 +27,7 @@ This design preserves the technical source detail for `REQ-OFFICE-RUNTIME-001` d - **GIVEN** a `FAILED` session, **WHEN** the topbar / chat header re-renders, **THEN** the "Agent working for Xs" timer and spinner are not displayed because `isLiveSession` reads `FAILED` as non-live. - **GIVEN** a failed run, **WHEN** the user opens the per-task chat, **THEN** a structured error entry appears at the failure timestamp with header "The agent stopped with an error.", a `Show details` collapsible revealing the raw adapter payload, and Resume session + Start fresh action buttons. - **GIVEN** an agent whose `consecutive_failures` reaches its effective `failure_threshold`, **WHEN** the failing wakeup is recorded, **THEN** the agent is auto-paused (`pause_reason` set), the threshold-th failure does NOT create its own `agent_run_failed` entry, and any prior `agent_run_failed` entries for that agent are auto-dismissed and replaced with a single `agent_paused_after_failures` entry listing the affected tasks. +- **GIVEN** an agent below its failure threshold with `cooldown_sec > 0`, **WHEN** a run fails and `HandleAgentFailure` marks it terminal, **THEN** `office_agent_runtime.last_run_finished_at` is stamped the same as after a successful run, and the heartbeat gate blocks the agent's next fire (for any task) until `cooldown_sec` has elapsed. - **GIVEN** an auto-paused agent, **WHEN** the scheduler tick attempts to claim one of its wakeups, **THEN** the wakeup is not claimed; behaviour is identical to a manually-paused agent. - **GIVEN** an `agent_run_failed` inbox entry, **WHEN** the user clicks Mark fixed, **THEN** an `inbox_dismissals` row is inserted, the (task, agent) session is cleared from `FAILED` to `IDLE`, and a new wakeup is queued with reason `manual_resume_after_failure`. - **GIVEN** an `agent_paused_after_failures` inbox entry, **WHEN** the user clicks Mark fixed, **THEN** the agent's `pause_reason` clears, `consecutive_failures` resets to zero, and a wakeup with reason `manual_resume_after_failure` is queued for every (task, agent) listed on the entry.