merge: main into the tenancy branch, and move the cron signal to reachability

main's cron regression tests manufactured a failing action by naming an
unregistered namespace. This branch creates a namespace on first use, so
registration stopped being evidence of anything: a cron with a typo in its
namespace now starts a run into a namespace nobody serves, and says nothing.

Report the fault instead of the proxy. A fire is a failure when it does not
reach a worker — either the start errored, or the start succeeded and no
worker is subscribed to (namespace, taskQueue). Same line, same throttle,
same recovery, one reporter (engine.reportFire). It also catches what the
old guard never could: a schedule whose worker died, and a task queue
renamed out from under an entry.

Reachability is asked AFTER the start, because enqueueing prunes
subscriptions whose peer the transport can no longer reach — a worker that
died without unsubscribing is gone from the registry by the time we look.

Anchoring follows the start, not the report: an errored fire stays due and
retries, a started-but-unreached fire re-anchors, because the run exists and
re-firing every tick would spawn a run every 5s.

Co-authored-by: Hanzo Dev <[email protected]>
This commit is contained in:
2026-07-28 20:34:14 -07:00
co-authored by Hanzo Dev
10 changed files with 1704 additions and 13 deletions
+114
View File
@@ -13,10 +13,124 @@ Durable workflow execution engine for AI agent orchestration.
- Old v2.x and v3.x tags (transition era) were deleted on 2026-04-30. Old v1.x tags (`v1.0.0`–`v1.42.0`) are upstream-Temporal-era artifacts and remain in git history for blame.
- New Hanzo-Tasks releases continue from `v1.43.0` and bump minor for features, patch for fixes.
- `v1.51.2` added `Embedded.CancelActivityForOrg`; `v1.51.3` added `Embedded.ActivitiesPageForOrg` — the org-scoped cancel + paginated read cloud's fleet queue surface (hanzoai/cloud `clients/visor`) depends on.
- `v1.52.3` added `View.FailureStreaks(ns)` + the `FailureStreak` type — the durable "what is broken right now" read a host polls instead of hand-decoding SQLite.
## Known gaps
- **Terminal standalone-activity GC is unimplemented.** Completed/failed/canceled standalone activities under the `act/<ns>/` key family (and their `ahist/<ns>/…` history) are never pruned — the namespace `WorkflowExecutionRetentionTtl` (default `720h`) has **no sweeper enforcing it** for standalone activities. The store therefore grows unbounded with volume (one row per job, e.g. every `studio.render` in the `gpu-jobs` namespace), and every `ListActivities` / `ActivitiesForOrg` / `ActivitiesPageForOrg` scans the full set. Consumers can bound the READ (cloud's fleet queue recency-sorts + caps terminal history, and now walks all pages via `ActivitiesPageForOrg`), but the underlying storage + scan cost still grow. **Fix (queued v1.51.4):** a background sweeper alongside `runScheduler` that deletes terminal standalone activities older than the namespace retention TTL, plus their history — idempotent, org-shard-scoped. Surfaced in the hanzoai/cloud per-GPU-queue review.
## Cron sweeper observability (v1.52.2)
The sweeper reports what it cannot return to a caller. Three `slog` messages
off `EmbedConfig.Logger` (`slog.Default()` when unset), all from
`pkg/tasks/engine.go`:
| Message | Level | Meaning |
|---------|-------|---------|
| `tasks: cron schedule action failed` | ERROR | One schedule's fire did not reach a worker. Carries `org`, `namespace`, `scheduleId`, `workflowType`, `taskQueue`, `consecutiveFailures`, `error`. |
| `tasks: cron schedule action recovered` | INFO | A previously failing schedule fired and reached a worker. Carries `afterConsecutiveFailures`. |
| `tasks: schedule sweep failed, no schedule fired this tick` | ERROR | The whole sweep failed — cron is dead for every org at once. |
A fire fails in one of two ways, and both produce the same line because the
operator's question is the same: **the start itself errored**, or **the start
succeeded and no worker is subscribed to `(namespace, taskQueue)`** — the run
exists and nothing will ever execute it. The `error` field says which. The
second half catches a cron naming a namespace nobody serves (namespaces are
created on first use, so a typo is no longer a start error), a schedule whose
worker died, and a task queue renamed out from under an entry. The check is
made AFTER the start, because enqueueing prunes subscriptions whose peer the
transport can no longer reach.
Alert on the first; `consecutiveFailures` is the "how long has this been
dead" number. Per-schedule **isolation is unchanged** — a broken entry is
still skipped and retried next sweep; only the silence is gone.
Anchoring follows the start, not the report: a fire that ERRORED is not
re-anchored (it stays due and retries every tick), a fire that STARTED is
re-anchored even when it went unreached — the run exists, and re-firing on
the strength of a report would spawn one every 5s.
Throttle: first failure, then one line per `failReportThrottle` (60) sweeps.
Unthrottled a broken 5s-tick schedule is ~17k lines/day. The counter clears
on a reached fire and on `DeleteSchedule`, so a relapse alerts immediately.
Why this exists: cloud's `clients/cron` fired a JobWorkflow whose activity
re-read the entry's ConfigMap; the cloud ServiceAccount had no RBAC to read
ConfigMaps, so every fire failed for **11 days** across six nightly backups
while the engine emitted nothing and every dashboard read healthy. It was
found only by hand-reading the engine's durable records.
## Activity / workflow failure observability (v1.52.3)
The sweeper fix above covers the SCHEDULER. It does not cover the incident:
`StartWorkflow` **succeeded** all 4489 times, so the scheduler was healthy
and correctly silent — the fault was one layer down, in the ACTIVITY. That
layer's only output was `e.emit(Event{Kind:"activity.failed"})` into the SSE
broker: ephemeral, dropped when nobody is subscribed, and nobody was.
**Guarantee: durable evidence, plus throttled log lines.** Both, not either.
### Durable — `fail/<ns>/<fingerprint>`, read via `View.FailureStreaks(ns)`
One `FailureStreak` row per failing identity, upserted on every failure and
**deleted on the first success**. It needs no subscriber and survives
restart, so `ConsecutiveFailures` can say `4489` where an in-memory counter
would have said `1`. A non-empty listing IS the list of what is broken; the
keyspace is bounded by how much is broken now, not by how often it failed
(so it does not have the unbounded-growth problem noted under Known gaps).
Identity is the recurring **shape** of the work — `(workflowType,
activityType, taskQueue, scheduleId)` — never the run: every cron fire mints
a fresh runId, so a run-keyed counter can never say "dead for 11 days".
Each row carries `org`, `namespace`, `workflowType`, `activityType`,
`taskQueue`, `scheduleId`, `consecutiveFailures`, `attempt`, `retrying`,
`persistent`, `firstFailureTime`, `lastFailureTime`, `lastError`, and
`lastWorkflowId`/`lastRunId` to go read.
`ActivityType` empty ⇒ the **workflow itself** failed (a decider that faults
before scheduling anything — the hole an activity-only report would leave).
### Log lines — `pkg/tasks/failure.go`
| Message | Level | Meaning |
|---------|-------|---------|
| `tasks: activity failed` | WARN | An activity attempt failed. `retrying` says whether the engine will try again. |
| `tasks: activity failing persistently` | **ERROR** | **Alert on this.** Failing continuously for ≥ `failPersistentAfter` (15 min). |
| `tasks: activity recovered` | INFO | Streak ended. Carries `afterConsecutiveFailures`. |
| `tasks: workflow failed` / `… failing persistently` / `… recovered` | WARN / ERROR / INFO | Same three, for a workflow failing with no activity to blame. |
**WARN vs ERROR is the distinction the incident turned on**: "failed once and
will retry" is normal operation and must not page anyone; "has failed every
attempt for a long time" is the outage. Persistence is measured by **age,
not count** — a nightly backup reaches a count of only 2 in two days yet is
unambiguously broken, while one run burning its 10 default attempts (≈5.5
min of backoff) must not trip it. The persistent **transition** always
reports, whatever the throttle says; waiting for failure #60 would be the
original bug wearing a different hat.
### Throttle
`shouldReport` is the one rule for the whole package (schedules included):
first failure, then every `failReportThrottle` (60). Measured: 180 failures
→ **4 lines**; stubbing the throttle off → 180. The throttle bounds LINES
only — the durable count stays exact.
Two counters on purpose: the in-memory `failTracker` is the throttle
authority (a store that is itself failing cannot starve it into reporting
every occurrence, and a restart makes a still-broken activity re-alert once
after a deploy), while the durable row is the evidence and always supplies
the count on the line.
### Not changed
Retry and isolation **semantics are identical** — which branch is taken,
when, and how many times. `TestFailureReportingPreservesRetrySemantics`
pins the attempt count, terminal status, history events and dispatch count.
The SSE `emit` calls all remain.
Schedule-started runs now carry a `ScheduleId` search attribute (sweeper and
`TriggerSchedule`), which is what lets a failure name the dead cron entry —
and makes `ScheduleId = "nightly-backup"` a queryable filter over executions.
## Quick Start
```bash
go build ./cmd/tasksd/
+1 -1
View File
@@ -21,7 +21,7 @@ import (
"github.com/go-jose/go-jose/v4/jwt"
)
// IAMClaims is the subset of Casdoor/hanzo.id claims tasksd cares about.
// IAMClaims is the subset of the hanzo.id token claims tasksd cares about.
// `owner` is the org slug (X-Org-Id), `sub` is the user id (X-User-Id),
// `email` is the user email (X-User-Email), `project` is the validated
// project slug (X-Project-Id) — the third leg of the org/project/user
+10
View File
@@ -407,6 +407,16 @@ func (e *engine) activityTerminal(ns, activityID, runID, status, eventType, evKi
}
out, _, _ := e.DescribeActivity(ns, activityID, runID)
e.emit(Event{Kind: evKind, Namespace: ns, WorkflowID: activityID, RunID: runID, Data: out})
// Standalone activities reach here from the fleet queue (fn.run,
// studio.render) and from the lease reaper. Same rule as the durable
// path: FAILED is evidence, COMPLETED ends the streak, and CANCELED is
// neither a fault nor a success so it leaves the streak alone.
switch status {
case activityStateFailed:
e.recordFailure(standaloneFailureIdentity(ns, a), false, cause)
case activityStateCompleted:
e.clearFailure(standaloneFailureIdentity(ns, a))
}
return nil
}
+25 -2
View File
@@ -278,8 +278,13 @@ func (e *engine) completeWorkflowActivity(ns, wf, run string, seq int, result, f
if rec.isTerminal() {
return nil // duplicate / already resolved
}
// One read serves two jobs: the terminal guard below, and the failure
// identity — the report has to name the SHAPE of the work (workflow type,
// task queue, originating schedule), because a runId names nothing an
// operator can act on and is freshly minted on every cron fire anyway.
wfe, wfOK, _ := e.DescribeWorkflow(ns, wf, run)
// Never advance a workflow that already reached a terminal state.
if wfe, ok, _ := e.DescribeWorkflow(ns, wf, run); ok && isTerminal(wfe.Status) {
if wfOK && isTerminal(wfe.Status) {
return nil
}
@@ -297,13 +302,28 @@ func (e *engine) completeWorkflowActivity(ns, wf, run string, seq int, result, f
return err
}
e.emit(Event{Kind: "activity.completed", Namespace: ns, WorkflowID: wf, RunID: run, Data: map[string]any{"seq": seq}})
// One success ends the streak: "failed every attempt" is the alertable
// condition, so anything that succeeds is by definition not it.
e.clearFailure(activityFailureIdentity(wfe, ns, wf, run, rec))
return e.scheduleWorkflowTask(ns, wf, run)
}
// Failure — retry per policy, else terminal.
//
// Both branches report. The emit() below reaches an SSE subscriber if one
// happens to be attached and is dropped on the floor otherwise; that was
// the ONLY output this path had while cloud's RunJobActivity failed on
// every fire for 11 days. recordFailure writes a durable row and a
// throttled line instead. Retry semantics are untouched — which branch is
// taken, when, and how many times is decided exactly as before.
failID := activityFailureIdentity(wfe, ns, wf, run, rec)
terr := temporal.Decode(failure)
pol := effectiveRetryPolicy(rec.RetryPolicy)
if pol.ShouldRetry(temporal.Decode(failure), int32(rec.Attempt)) {
if pol.ShouldRetry(terr, int32(rec.Attempt)) {
delay := pol.NextInterval(int32(rec.Attempt))
// retrying=true: "failed once, will try again" — the case that must
// NOT read like the 11-day outage.
e.recordFailure(failID, true, terr.Error())
rec.Attempt++
rec.Status = wfActScheduled
rec.Failure = append(json.RawMessage(nil), failure...) // last failure (observability)
@@ -328,6 +348,9 @@ func (e *engine) completeWorkflowActivity(ns, wf, run string, seq int, result, f
return err
}
e.emit(Event{Kind: "activity.failed", Namespace: ns, WorkflowID: wf, RunID: run, Data: map[string]any{"seq": seq, "attempts": rec.Attempt}})
// retrying=false: this run's activity is dead. In the incident every fire
// ended here, 4489 times, in silence.
e.recordFailure(failID, false, terr.Error())
return e.scheduleWorkflowTask(ns, wf, run)
}
+18
View File
@@ -117,6 +117,9 @@ func Embed(ctx context.Context, cfg EmbedConfig) (*Embedded, error) {
router.SetMembership(routing.NodeID(nodeID), []routing.NodeID{routing.NodeID(nodeID)})
}
en := newEngine(st)
// The background sweepers have no caller to return an error to, so the
// host's logger is the only way their failures reach anyone.
en.log = cfg.Logger
migr := migration.NewCoordinator(st.mgr, repl)
// Bootstrap the root tenant's default namespace so the UI has
@@ -268,6 +271,21 @@ func (v View) DescribeActivity(ns, activityID, runID string) (*StandaloneActivit
return v.en.DescribeActivity(ns, activityID, runID)
}
// FailureStreaks returns what is broken in ns right now, worst first: one
// durable row per activity/workflow identity that has failed every attempt
// since it last succeeded. Empty means nothing is failing.
//
// This is the read that was missing. cloud's clients/cron fired a JobWorkflow
// whose activity failed on every one of 4489 fires across 11 days while the
// engine's only output was an SSE event nobody was subscribed to; the six
// nightly backups it silently skipped were found by hand-reading SQLite. A
// host polls this instead — each row carries org, namespace, workflow and
// activity type, task queue, originating scheduleId, consecutive failures,
// how long it has been failing, the last error, and a run to go read.
func (v View) FailureStreaks(ns string) ([]FailureStreak, error) {
return v.en.FailureStreaks(ns)
}
// nodeSnapshot returns a copy of the current listener set under the lock so the
// server-push loop never races ServeGated appending a gated listener.
func (e *Embedded) nodeSnapshot() []*zap.Node {
+167 -9
View File
@@ -8,10 +8,12 @@ import (
"encoding/hex"
"encoding/json"
"fmt"
"log/slog"
"strings"
"sync"
"time"
"github.com/hanzoai/tasks/pkg/sdk/temporal"
storepkg "github.com/hanzoai/tasks/pkg/tasks/store"
"github.com/robfig/cron/v3"
)
@@ -75,10 +77,21 @@ type engine struct {
workers *workerRegistry
runMu *keyedMutex // serializes advancing a single (org, ns, wf, run)
principal Principal // zero = root tenant (embedded/dev). Its org is stamped on every emitted Event.
// log reports what the background sweepers cannot return to a caller.
// Always non-nil (newEngine defaults it, As carries it, Embed overrides
// it with EmbedConfig.Logger), so no call site needs a guard.
log *slog.Logger
// fails throttles failure reporting — cron schedules here, activities
// and workflows in failure.go, one tracker because there is one throttle
// rule. Shared across tenant views like broker/disp/workers, because the
// root sweeper fires every tenant's schedules through a throwaway view
// and the count must follow the work, not the view; keys are
// principal-qualified for the same reason.
fails *failTracker
}
func newEngine(s *store) *engine {
return &engine{store: s, broker: newBroker(), disp: newDispatcher(), cancelling: newCancelTracker(), workers: newWorkerRegistry(), runMu: newKeyedMutex()}
return &engine{store: s, broker: newBroker(), disp: newDispatcher(), cancelling: newCancelTracker(), workers: newWorkerRegistry(), runMu: newKeyedMutex(), log: slog.Default(), fails: newFailTracker(failReportThrottle)}
}
// As returns an engine view scoped to the tenant p. Reads and writes route
@@ -91,7 +104,7 @@ func (e *engine) As(p Principal) *engine {
if p == e.principal {
return e
}
return &engine{store: e.store.as(p), broker: e.broker, disp: e.disp, cancelling: e.cancelling, workers: e.workers, runMu: e.runMu, principal: p}
return &engine{store: e.store.as(p), broker: e.broker, disp: e.disp, cancelling: e.cancelling, workers: e.workers, runMu: e.runMu, principal: p, log: e.log, fails: e.fails}
}
// emit publishes an event tagged with the engine's org so per-org SSE
@@ -401,9 +414,33 @@ func (e *engine) terminalTransition(ns, workflowId, runId, status, evKind, event
RunID: wf.Execution.RunId,
Data: wf,
})
// The other half of the silent path. An activity-level report cannot see
// a decider that faults before it schedules anything (bad input, a panic
// on episode 0): that workflow fails with no activity record to speak for
// it, which is the same class of bug as the 11-day incident with an even
// thinner trail. CANCELED/TERMINATED are operator actions, not faults, so
// they neither record nor clear.
switch status {
case "WORKFLOW_EXECUTION_STATUS_FAILED":
e.recordFailure(workflowFailureIdentity(ns, wf), false, workflowFailureText(attrs))
case "WORKFLOW_EXECUTION_STATUS_COMPLETED":
e.clearFailure(workflowFailureIdentity(ns, wf))
}
return wf, nil
}
// workflowFailureText renders the failure a terminal transition recorded into
// history. attrs["failure"] carries the encoded envelope the decider sent;
// decoding it yields the message a human reads, and temporal.Decode is
// fail-secure on hostile or absent bytes.
func workflowFailureText(attrs map[string]any) string {
s, _ := attrs["failure"].(string)
if s == "" {
return ""
}
return temporal.Decode([]byte(s)).Error()
}
func isTerminal(status string) bool {
switch status {
case "WORKFLOW_EXECUTION_STATUS_COMPLETED",
@@ -1294,6 +1331,10 @@ func (e *engine) ListSchedules(ns string) ([]Schedule, error) {
}
func (e *engine) DeleteSchedule(ns, id string) error {
// Drop the failure throttle with the row it belongs to. A schedule
// deleted while broken never fires again, so nothing else would ever
// clear its counter.
e.fails.ok(scheduleKey(e.principal, ns, id))
return e.store.del(fmt.Sprintf("sc/%s/%s", ns, id))
}
@@ -1571,6 +1612,88 @@ func (e *engine) ListIdentities(ns string) ([]Identity, error) {
// ── cron sweeper ────────────────────────────────────────────────────
// scheduleKey identifies a schedule across every tenant's shard. Also the
// tracker key, so counts follow the schedule and not the engine view.
func scheduleKey(p Principal, ns, id string) string { return p.String() + "|" + ns + "|" + id }
// sweepAllKey tracks whole-sweep failures under the same throttle as a
// single broken schedule. CreateSchedule rejects an empty namespace and an
// empty scheduleId, so this all-empty triple can never collide with a real
// schedule's key.
var sweepAllKey = scheduleKey(Principal{}, "", "")
// The cron sweeper's report messages. Consts rather than literals so a test
// asserting on them cannot drift from the line the engine actually writes.
const (
msgActionFailed = "tasks: cron schedule action failed"
msgActionRecovered = "tasks: cron schedule action recovered"
msgSweepFailed = "tasks: schedule sweep failed, no schedule fired this tick"
)
// unreached names the fault in a fire that STARTED but has nowhere to go:
// the workflow task is enqueued on (ns, queue) and sits in the dispatcher's
// backlog until some worker subscribes. nil when a live subscriber is there
// to take it.
//
// This is what a cron entry naming a namespace nobody serves looks like now
// that a namespace is created on demand: the start succeeds, the run is
// recorded, and nothing ever executes it. It is also what a schedule whose
// worker died looks like, and a schedule whose task queue was renamed — the
// three shapes of "the nightly backup did not run" that no start-time check
// can see. Ask AFTER the start, because the enqueue prunes subscriptions
// whose peer the transport can no longer reach (deliverWFLocked): a worker
// that died without unsubscribing is gone from the registry by the time we
// look.
func (e *engine) unreached(ns, queue string) error {
if e.disp != nil && e.disp.HasSubscribers(ns, queue, kindWorkflow) {
return nil
}
return fmt.Errorf("%w %q in namespace %q", ErrNoWorkersSubscribed, queue, ns)
}
// reportFire is the ONE place a schedule fire's outcome is reported. A nil
// fault closes any open streak; a non-nil one opens or extends it, throttled.
//
// Isolation must not mean SILENCE. cloud's clients/cron fires a JobWorkflow
// per entry; when its activity could not read the entry's ConfigMap (the
// cloud ServiceAccount was missing the RBAC) every fire failed for 11 days
// while the engine reported nothing and every dashboard read healthy — six
// nightly backups produced nothing and it was caught only by hand-reading
// the engine's durable records. So every field needed to act on it goes on
// the line: which org, which namespace, which schedule, what it was trying
// to start and where, and how long it has been failing.
//
// Throttled because a broken schedule stays broken: at a 5s tick that is
// ~17k identical lines a day, which buries the signal as thoroughly as
// silence did. At failReportThrottle=60 the heartbeat is one line per ≈5
// minutes, so any 15-minute dashboard window still holds at least three.
func (e *engine) reportFire(p Principal, s Schedule, fault error) {
key := scheduleKey(p, s.Namespace, s.ScheduleId)
if fault == nil {
if n := e.fails.ok(key); n > 0 {
// Closes the loop the throttle opens: without a recovery line an
// operator cannot tell a schedule that was fixed from one whose
// next throttled error line simply has not come round yet.
e.log.Info(msgActionRecovered,
"org", p.Org,
"namespace", s.Namespace,
"scheduleId", s.ScheduleId,
"afterConsecutiveFailures", n)
}
return
}
if n, report := e.fails.fail(key); report {
e.log.Error(msgActionFailed,
"org", p.Org,
"namespace", s.Namespace,
"scheduleId", s.ScheduleId,
"workflowType", s.Action.WorkflowType.Name,
"taskQueue", s.Action.TaskQueue,
"consecutiveFailures", n,
"error", fault)
}
}
// runScheduler ticks every 5s and fires due schedules through StartWorkflow.
// Cron specs are parsed via robfig/cron with seconds-optional 5/6-field
// syntax; first invalid spec is skipped without aborting the sweep.
@@ -1582,13 +1705,31 @@ func (e *engine) runScheduler(stop <-chan struct{}) {
case <-stop:
return
case <-t.C:
_ = e.sweepSchedules()
e.sweepCanceling()
e.sweepLeases()
e.sweepOnce()
}
}
}
// sweepOnce runs one scheduler tick. Split out of runScheduler's select so
// tests can drive a tick without waiting on the 5s ticker.
//
// The sweep error used to be dropped on the floor (`_ = e.sweepSchedules()`).
// That made a TOTAL sweep failure — the store refusing the cross-org scan,
// say — indistinguishable from a quiet night: cron stops firing for every
// org at once and nothing anywhere says so.
func (e *engine) sweepOnce() {
if err := e.sweepSchedules(); err != nil {
if n, report := e.fails.fail(sweepAllKey); report {
e.log.Error(msgSweepFailed,
"org", e.principal.Org, "consecutiveFailures", n, "error", err)
}
} else {
e.fails.ok(sweepAllKey)
}
e.sweepCanceling()
e.sweepLeases()
}
// sweepLeases reaps expired activity leases across every namespace the
// (unscoped) engine can see, so a claimed activity stranded by a worker that
// died and never came back is eventually reclaimed even with no fresh claim
@@ -1643,10 +1784,27 @@ func (e *engine) sweepSchedules() error {
for _, d := range dues {
s := d.s
oe := e.As(d.principal)
if _, err := oe.StartWorkflow(s.Namespace, "", "", s.Action.WorkflowType, s.Action.TaskQueue, s.Action.Input); err != nil {
// Per-schedule isolation: a broken action (e.g. unregistered
// namespace) skips this entry and the sweep continues; it is
// re-attempted next sweep.
// Stamp the originating schedule on the run. The 11-day incident's
// fault was one layer below this call — StartWorkflow succeeded 4489
// times while the ACTIVITY it started failed every time — and without
// this attribute the failure report one layer down can only say "some
// JobWorkflow is broken", never "the nightly backup has not run".
wf, startErr := oe.startWorkflowFull(s.Namespace, "", "", s.Action.WorkflowType, s.Action.TaskQueue, s.Action.Input, "",
map[string]any{searchAttrScheduleID: s.ScheduleId}, nil, "")
fault := startErr
if fault == nil {
fault = e.unreached(s.Namespace, wf.TaskQueue)
}
e.reportFire(d.principal, s, fault)
if startErr != nil {
// Per-schedule isolation: a broken action skips this entry and
// the sweep continues; it is re-attempted next sweep.
//
// A failed fire is deliberately NOT re-anchored, so the entry
// stays due and retries on every 5s tick. A fire that STARTED is
// re-anchored even when it went unreached, because the run
// exists: re-firing it every tick would spawn a run every 5s on
// the strength of a report.
continue
}
s.Info.ActionCount++
+4 -1
View File
@@ -32,7 +32,10 @@ func (e *engine) TriggerSchedule(ns, id, requestID string) (*WorkflowExecution,
}
}
}
wf, err := e.StartWorkflow(s.Namespace, "", "", s.Action.WorkflowType, s.Action.TaskQueue, s.Action.Input)
// Same schedule stamp the sweeper applies — a manual trigger produces a
// run of the same schedule and must be traceable to it identically.
wf, err := e.startWorkflowFull(s.Namespace, "", "", s.Action.WorkflowType, s.Action.TaskQueue, s.Action.Input, "",
map[string]any{searchAttrScheduleID: s.ScheduleId}, nil, "")
if err != nil {
return nil, err
}
+414
View File
@@ -0,0 +1,414 @@
// Copyright © 2026 Hanzo AI. MIT License.
package tasks
import (
"crypto/sha256"
"encoding/hex"
"fmt"
"sort"
"strings"
"sync"
"time"
)
// Failure reporting — how the engine says, durably, that work it owns is
// broken.
//
// The incident this exists for: cloud's clients/cron schedules fire a
// JobWorkflow whose RunJobActivity re-reads the entry's ConfigMap at fire
// time. The cloud ServiceAccount had no RBAC to read ConfigMaps, so the
// ACTIVITY failed on every single fire for 11 days. StartWorkflow SUCCEEDED
// every time — the schedule's actionCount reached 4489 — so the scheduler
// was genuinely healthy and silent by correctness; the fault lived one layer
// down. All that layer did with it was e.emit(Event{Kind:"activity.failed"})
// into the SSE broker: ephemeral, no subscriber, nothing written anywhere.
// Six nightly backups produced nothing and every dashboard read green. It
// was found only by hand-reading the engine's SQLite.
//
// So a failure now produces two things, and the split is deliberate:
//
// - a DURABLE row per failing identity, "fail/<ns>/<fingerprint>". It
// needs no subscriber and outlives the process. It is the evidence:
// how many consecutive failures, since when, the last error, and a
// (workflowId, runId) to go read. Callers get it back through
// View.FailureStreaks — nobody has to open SQLite again.
// - a THROTTLED log line off the same event, so an operator or an alert
// that only ever sees stdout still gets paged.
//
// Identity is the recurring SHAPE of the work — (workflowType,
// activityType, taskQueue, scheduleId) — never the run. Every cron fire
// mints a fresh runId, so a run-keyed counter would have read "attempt 1 of
// 10" forty thousand times and never once said "this has been dead for 11
// days". The shape is also what an operator can actually fix.
//
// Nothing here changes retry or isolation semantics. A failure is retried,
// and isolated, exactly as before; it just stops being invisible.
// failReportThrottle is how many consecutive failures of one identity pass
// between log lines after the first. Failures repeat on their own cadence
// (a 5s scheduler tick, a 1s-and-doubling activity backoff), so unthrottled
// a single broken thing writes thousands of identical lines a day and
// buries the signal as thoroughly as silence did. One in 60 keeps any
// realistic dashboard window holding several lines.
const failReportThrottle = 60
// failPersistentAfter is how long an unbroken failure streak must run before
// it counts as PERSISTENT — "this has failed every attempt for a long time",
// the alertable condition that was invisible for 11 days, as opposed to "it
// just failed once and will retry".
//
// Age, not count, on purpose. A nightly backup reaches a count of only 2 in
// two days yet is unambiguously broken, while a single run burning its 10
// default attempts (1s doubling to a 100s cap ≈ 5.5 minutes of backoff)
// must NOT trip it. 15 minutes clears the second and catches the first on
// its second night instead of its eleventh.
const failPersistentAfter = 15 * time.Minute
// shouldReport is the ONE throttle rule in this package: the FIRST failure
// of a streak (the alert), then every `every`-th (the heartbeat, carrying
// whatever the current error text is).
//
// Deliberately NOT "report whenever the error text changes": failure text
// can embed a freshly minted random runId, so a text-change rule would fire
// on every occurrence and restore exactly the flood this exists to prevent.
// A failure mode that shifts instead surfaces on the next heartbeat.
func shouldReport(n, every int) bool { return n == 1 || (every > 0 && n%every == 0) }
// failTracker counts consecutive failures per key in memory so a reporter
// can alert on the first and throttle the rest. Its `every` is fixed at
// construction: the tracker owns its cadence, no call site restates it.
type failTracker struct {
mu sync.Mutex
every int
n map[string]int
}
func newFailTracker(every int) *failTracker {
return &failTracker{every: every, n: map[string]int{}}
}
// fail records a failure for key and reports the consecutive-failure count
// plus whether this one should be reported (see shouldReport).
func (f *failTracker) fail(key string) (int, bool) {
f.mu.Lock()
defer f.mu.Unlock()
f.n[key]++
n := f.n[key]
return n, shouldReport(n, f.every)
}
// ok clears key and reports how many consecutive failures preceded it
// (0 = it was already healthy). Clearing is what makes something that
// breaks again alert immediately instead of waiting out the throttle, and
// it is what keeps the map from growing once the fault is fixed.
func (f *failTracker) ok(key string) int {
f.mu.Lock()
defer f.mu.Unlock()
n := f.n[key]
delete(f.n, key)
return n
}
// ── the durable record ──────────────────────────────────────────────────
// FailureStreak is the durable aggregate for ONE execution identity that is
// currently failing: an activity type (ActivityType set) or a workflow type
// failing on its own (ActivityType empty). One row per broken thing, upserted
// on each failure and DELETED on the first success — so the keyspace is
// bounded by how much is broken right now, not by how often it failed, and a
// non-empty listing is exactly the list of what needs attention.
type FailureStreak struct {
Org string `json:"org,omitempty"` // "" = unscoped (embedded/dev)
Namespace string `json:"namespace"`
WorkflowType string `json:"workflowType,omitempty"`
// ActivityType empty ⇒ the workflow itself failed (a decider fault with
// no activity to blame), not an activity within it.
ActivityType string `json:"activityType,omitempty"`
TaskQueue string `json:"taskQueue,omitempty"`
// ScheduleId is set when the run came from a cron schedule, which is the
// field that turns "some JobWorkflow is broken" into "THIS nightly backup
// has not run". Stamped by the sweeper as a search attribute.
ScheduleId string `json:"scheduleId,omitempty"`
// ConsecutiveFailures is the how-long-has-this-been-dead number: 1 is a
// blip, 4489 is the incident. Survives restart, unlike the in-memory
// throttle counter.
ConsecutiveFailures int64 `json:"consecutiveFailures"`
// Attempt is the per-run retry attempt of the LAST failure — a different
// axis from ConsecutiveFailures, which spans runs.
Attempt int `json:"attempt,omitempty"`
// Retrying distinguishes "failed and the engine will try again" from
// "retries are exhausted and this run is dead".
Retrying bool `json:"retrying,omitempty"`
// Persistent is the alertable condition: failing continuously for at
// least failPersistentAfter.
Persistent bool `json:"persistent,omitempty"`
FirstFailureTime string `json:"firstFailureTime"`
LastFailureTime string `json:"lastFailureTime"`
LastError string `json:"lastError,omitempty"`
// LastWorkflowId / LastRunId point at one concrete run to go read. The
// identity itself is deliberately run-independent.
LastWorkflowId string `json:"lastWorkflowId,omitempty"`
LastRunId string `json:"lastRunId,omitempty"`
}
// failureIdentity is WHAT failed, at the granularity an operator can act on.
// The first four fields form the fingerprint; WorkflowId/RunId/Attempt ride
// along as last-seen detail and are deliberately NOT part of it.
type failureIdentity struct {
Namespace string
WorkflowType string
ActivityType string
TaskQueue string
ScheduleId string
WorkflowId string
RunId string
Attempt int
}
// fingerprint hashes the identity into a fixed-length, key-safe token. A
// hash rather than the joined names because every component is caller-supplied
// (workflow types, queue names) and a '/' in one of them would otherwise
// reshape the store key.
func (id failureIdentity) fingerprint() string {
sum := sha256.Sum256([]byte(strings.Join(
[]string{id.WorkflowType, id.ActivityType, id.TaskQueue, id.ScheduleId}, "\x00")))
return hex.EncodeToString(sum[:16])
}
func failKey(ns, fingerprint string) string { return "fail/" + ns + "/" + fingerprint }
// ── report messages ─────────────────────────────────────────────────────
const (
msgActivityFailed = "tasks: activity failed"
msgActivityPersistent = "tasks: activity failing persistently"
msgActivityRecovered = "tasks: activity recovered"
msgWorkflowFailed = "tasks: workflow failed"
msgWorkflowPersistent = "tasks: workflow failing persistently"
msgWorkflowRecovered = "tasks: workflow recovered"
)
// ── record / clear ──────────────────────────────────────────────────────
// recordFailure upserts the durable streak for id and reports it, throttled.
//
// Best-effort by construction: a store error costs the row but never the log
// line, and no error propagates — observing a failure must never become a
// second failure, and must never change what the caller does about the first.
func (e *engine) recordFailure(id failureIdentity, retrying bool, errText string) {
key := failKey(id.Namespace, id.fingerprint())
// Serialize the read-modify-write per identity, the same way the claim
// path serializes per namespace. Two runs of one broken cron fail
// concurrently all the time; an increment lost there is a streak length
// that reads low exactly when it matters.
unlock := e.runMu.lock(e.principal.String() + "|fail|" + key)
defer unlock()
now := time.Now().UTC()
var rec FailureStreak
if ok, _ := e.store.get(key, &rec); !ok {
rec = FailureStreak{
Org: e.principal.Org,
Namespace: id.Namespace,
WorkflowType: id.WorkflowType,
ActivityType: id.ActivityType,
TaskQueue: id.TaskQueue,
ScheduleId: id.ScheduleId,
FirstFailureTime: now.Format(time.RFC3339),
}
}
rec.ConsecutiveFailures++
rec.Attempt = id.Attempt
rec.Retrying = retrying
rec.LastFailureTime = now.Format(time.RFC3339)
rec.LastError = errText
rec.LastWorkflowId = id.WorkflowId
rec.LastRunId = id.RunId
wasPersistent := rec.Persistent
rec.Persistent = rec.ConsecutiveFailures > 1 &&
now.Sub(parseTime(rec.FirstFailureTime, now)) >= failPersistentAfter
_ = e.store.put(key, rec)
// The in-memory tracker is the THROTTLE authority; the durable row is the
// EVIDENCE. Separate jobs, so: a store that is itself failing cannot
// starve the throttle into reporting every occurrence (a row that never
// loads reads as count 1 forever), and a restart resets the throttle so a
// still-broken activity re-alerts once after a deploy rather than waiting
// out 60 more failures. The COUNT on the line always comes from the row.
_, throttled := e.fails.fail(e.principal.String() + "|" + key)
// The persistent transition always reports, whatever the throttle says.
// It is the whole point of the change and it can happen on failure #2 of
// a nightly cron — a throttle-only rule would swallow it for 58 more
// nights, which is the original bug wearing a different hat.
if !throttled && !(rec.Persistent && !wasPersistent) {
return
}
msg := msgActivityFailed
if rec.Persistent {
msg = msgActivityPersistent
}
if id.ActivityType == "" {
msg = msgWorkflowFailed
if rec.Persistent {
msg = msgWorkflowPersistent
}
}
args := []any{
"org", e.principal.Org,
"namespace", id.Namespace,
"workflowType", id.WorkflowType,
"activityType", id.ActivityType,
"taskQueue", id.TaskQueue,
"scheduleId", id.ScheduleId,
"workflowId", id.WorkflowId,
"runId", id.RunId,
"attempt", id.Attempt,
"retrying", retrying,
"consecutiveFailures", rec.ConsecutiveFailures,
"failingSince", rec.FirstFailureTime,
"error", errText,
}
// ERROR only once it is persistent. A single failure that will be retried
// is normal operation; paging on it trains operators to ignore the level
// that carries the 11-day outage.
if rec.Persistent {
e.log.Error(msg, args...)
return
}
e.log.Warn(msg, args...)
}
// clearFailure ends the streak for id. The durable row is deleted — the
// keyspace answers "what is broken NOW", so a fixed identity must leave
// nothing behind — and if there WAS a streak, a recovery line closes the loop
// the throttle opens: without it an operator cannot tell something that was
// fixed from something whose next throttled line has not come round yet.
func (e *engine) clearFailure(id failureIdentity) {
key := failKey(id.Namespace, id.fingerprint())
unlock := e.runMu.lock(e.principal.String() + "|fail|" + key)
defer unlock()
// Unconditional, so the throttle resets even when the row is already gone.
e.fails.ok(e.principal.String() + "|" + key)
var rec FailureStreak
if ok, _ := e.store.get(key, &rec); !ok {
return
}
_ = e.store.del(key)
msg := msgActivityRecovered
if id.ActivityType == "" {
msg = msgWorkflowRecovered
}
e.log.Info(msg,
"org", e.principal.Org,
"namespace", id.Namespace,
"workflowType", id.WorkflowType,
"activityType", id.ActivityType,
"taskQueue", id.TaskQueue,
"scheduleId", id.ScheduleId,
"afterConsecutiveFailures", rec.ConsecutiveFailures,
"failingSince", rec.FirstFailureTime)
}
// FailureStreaks returns every currently-failing identity in ns, worst first.
// This is the read that replaces hand-decoding the store: one row per broken
// thing, each carrying enough to act — org, namespace, workflow/activity type,
// task queue, originating schedule, how many consecutive failures, since when,
// the last error, and a run to go read.
func (e *engine) FailureStreaks(ns string) ([]FailureStreak, error) {
rows, err := listInto[FailureStreak](e.store, fmt.Sprintf("fail/%s/", ns))
if err != nil {
return nil, err
}
sort.Slice(rows, func(i, j int) bool {
if rows[i].ConsecutiveFailures != rows[j].ConsecutiveFailures {
return rows[i].ConsecutiveFailures > rows[j].ConsecutiveFailures
}
if rows[i].WorkflowType != rows[j].WorkflowType {
return rows[i].WorkflowType < rows[j].WorkflowType
}
return rows[i].ActivityType < rows[j].ActivityType
})
return rows, nil
}
// ── identity constructors ───────────────────────────────────────────────
// searchAttrScheduleID is the visibility attribute the schedule paths stamp
// on every run they start. It is what lets a failure report name the cron
// entry that is dead, and it makes `ScheduleId = "nightly-backup"` a
// queryable filter over executions at the same time.
const searchAttrScheduleID = "ScheduleId"
// scheduleIDOf reads the stamped schedule id off an execution. Empty for runs
// that were not started by a schedule.
func scheduleIDOf(wf *WorkflowExecution) string {
if wf == nil {
return ""
}
s, _ := wf.SearchAttrs[searchAttrScheduleID].(string)
return s
}
// activityFailureIdentity identifies one workflow-driven activity. wf may be
// nil (the execution row vanished); the namespace, activity type and queue
// still name the work.
func activityFailureIdentity(wf *WorkflowExecution, ns, wfID, runID string, rec *workflowActivity) failureIdentity {
id := failureIdentity{
Namespace: ns,
ActivityType: rec.ActivityType,
TaskQueue: rec.TaskQueue,
ScheduleId: scheduleIDOf(wf),
WorkflowId: wfID,
RunId: runID,
Attempt: rec.Attempt,
}
if wf != nil {
id.WorkflowType = wf.Type.Name
if id.TaskQueue == "" {
id.TaskQueue = wf.TaskQueue
}
}
return id
}
// standaloneFailureIdentity identifies a standalone activity, which has no
// enclosing workflow — its type and queue are the whole shape.
func standaloneFailureIdentity(ns string, a *StandaloneActivity) failureIdentity {
return failureIdentity{
Namespace: ns,
ActivityType: a.Type.Name,
TaskQueue: a.TaskQueue,
WorkflowId: a.Execution.WorkflowId,
RunId: a.Execution.RunId,
Attempt: a.Attempt,
}
}
// workflowFailureIdentity identifies a workflow failing on its own account.
// ActivityType stays empty: there is no activity to blame, which is exactly
// the case an activity-only report would miss (a decider that faults on
// episode 0 never schedules anything).
func workflowFailureIdentity(ns string, wf *WorkflowExecution) failureIdentity {
return failureIdentity{
Namespace: ns,
WorkflowType: wf.Type.Name,
TaskQueue: wf.TaskQueue,
ScheduleId: scheduleIDOf(wf),
WorkflowId: wf.Execution.WorkflowId,
RunId: wf.Execution.RunId,
}
}
// parseTime reads an RFC3339 stamp, falling back to def on anything
// unparseable so a corrupt row degrades the report instead of skewing it.
func parseTime(s string, def time.Time) time.Time {
t, err := time.Parse(time.RFC3339, s)
if err != nil {
return def
}
return t
}
+561
View File
@@ -0,0 +1,561 @@
// Copyright © 2026 Hanzo AI. MIT License.
package tasks
import (
"testing"
"time"
"github.com/hanzoai/tasks/pkg/sdk/client"
"github.com/hanzoai/tasks/pkg/sdk/temporal"
)
// These tests pin the ACTIVITY/WORKFLOW half of failure reporting.
// schedule_report_test.go covers the sweeper — the layer that was already
// healthy during the incident.
//
// The incident: cloud's clients/cron schedules fire a JobWorkflow whose
// RunJobActivity re-reads the entry's ConfigMap at fire time. The cloud
// ServiceAccount had no RBAC to read ConfigMaps, so the ACTIVITY failed on
// every single fire for 11 days. StartWorkflow SUCCEEDED every time —
// actionCount reached 4489 — so the scheduler was correct AND silent, and
// the fault lived one layer down where the only output was
// e.emit(Event{Kind:"activity.failed"}) into an SSE broker with nobody
// subscribed. Six nightly backups produced nothing; every dashboard read
// green; it was found by hand-reading SQLite.
//
// Every test here therefore attaches NO SSE subscriber, exactly as
// production had none. Without the fix each one reports the empty evidence
// that is the bug itself.
// failNS registers a namespace and returns a running workflow to hang
// activities off.
func failNS(t *testing.T, en *engine, ns, wfID, wfType, queue string) string {
t.Helper()
if err := en.RegisterNamespace(Namespace{NamespaceInfo: NamespaceInfo{Name: ns}}); err != nil {
t.Fatalf("RegisterNamespace(%s): %v", ns, err)
}
wf, err := en.StartWorkflow(ns, wfID, "", TypeRef{Name: wfType}, queue, []any{})
if err != nil {
t.Fatalf("StartWorkflow: %v", err)
}
return wf.Execution.RunId
}
// schedActivity schedules (ns, run, seq) so it can then be failed.
func schedActivity(t *testing.T, en *engine, ns, wfID, run string, seq int, actType, queue string, rp *client.RetryPolicyJSON) {
t.Helper()
unlock := en.lockRun(ns, wfID, run)
defer unlock()
if err := en.applyScheduleActivity(ns, wfID, run, seq, actType, []byte(`[]`), queue, 0, 0, rp); err != nil {
t.Fatalf("applyScheduleActivity seq=%d: %v", seq, err)
}
}
// rbacDenied is the incident's error verbatim in shape: a permanent,
// non-retryable fault that no amount of retrying can fix.
func rbacDenied(t *testing.T) []byte {
t.Helper()
b, err := temporal.Encode(temporal.NewError(
`configmaps "cron-reconcile" is forbidden: User "system:serviceaccount:hanzo:cloud" cannot get resource "configmaps"`,
temporal.CodeApplication, true))
if err != nil {
t.Fatalf("encode failure: %v", err)
}
return b
}
// onlyStreak returns the single failure streak in ns, failing the test with
// the exact silence the incident produced when there is none.
func onlyStreak(t *testing.T, en *engine, ns string) FailureStreak {
t.Helper()
rows, err := en.FailureStreaks(ns)
if err != nil {
t.Fatalf("FailureStreaks(%s): %v", ns, err)
}
if len(rows) != 1 {
t.Fatalf("durable failure streaks = %d, want 1; rows: %+v", len(rows), rows)
}
return rows[0]
}
// TestActivityFailureIsDurableWithNoSubscriber is the core regression test.
// An activity that fails with nobody watching must leave evidence in the
// store — the guarantee the SSE-only path never provided.
func TestActivityFailureIsDurableWithNoSubscriber(t *testing.T) {
s := newStore()
defer s.close()
en := newEngine(s)
logs := captureLogs(en)
run := failNS(t, en, "default", "job-1", "JobWorkflow", "cron-q")
schedActivity(t, en, "default", "job-1", run, 0, "RunJobActivity", "cron-q", nil)
if err := en.completeWorkflowActivity("default", "job-1", run, 0, nil, rbacDenied(t)); err != nil {
t.Fatalf("completeWorkflowActivity: %v", err)
}
rec := onlyStreak(t, en, "default")
if rec.Namespace != "default" || rec.WorkflowType != "JobWorkflow" ||
rec.ActivityType != "RunJobActivity" || rec.TaskQueue != "cron-q" {
t.Fatalf("streak identity = %+v, want ns=default JobWorkflow/RunJobActivity on cron-q", rec)
}
if rec.ConsecutiveFailures != 1 {
t.Fatalf("consecutiveFailures = %d, want 1", rec.ConsecutiveFailures)
}
if rec.Retrying {
t.Fatal("retrying = true, want false: a non-retryable failure is terminal for this run")
}
if rec.LastRunId != run || rec.LastWorkflowId != "job-1" {
t.Fatalf("streak points at %s/%s, want job-1/%s — a row you cannot trace to a run is not evidence",
rec.LastWorkflowId, rec.LastRunId, run)
}
if rec.LastError == "" || rec.FirstFailureTime == "" {
t.Fatalf("streak carries no error/time: %+v", rec)
}
// The log floor: an operator who only ever sees stdout still gets it.
fails := withMsg(logs(), msgActivityFailed)
if len(fails) != 1 {
t.Fatalf("log lines = %d, want 1; records: %v", len(fails), logs())
}
wantFields(t, fails[0], map[string]any{
"namespace": "default",
"workflowType": "JobWorkflow",
"activityType": "RunJobActivity",
"taskQueue": "cron-q",
"consecutiveFailures": 1,
"retrying": false,
})
}
// TestActivityFailureStreakOutlivesProcessRestart is the "outlives process
// restart" half of the guarantee. An 11-day outage spans deploys; a counter
// that resets on boot can never say "this has been dead for 11 days", which
// is the one number that would have ended the incident on day one.
func TestActivityFailureStreakOutlivesProcessRestart(t *testing.T) {
s := newStore()
defer s.close()
// Engine A: three failed fires, each a fresh run — the incident's shape,
// where a run-keyed counter would read "1" three times.
enA := newEngine(s)
captureLogs(enA)
for i, wfID := range []string{"fire-1", "fire-2", "fire-3"} {
if i == 0 {
failNS(t, enA, "default", wfID, "JobWorkflow", "cron-q")
} else if _, err := enA.StartWorkflow("default", wfID, "", TypeRef{Name: "JobWorkflow"}, "cron-q", []any{}); err != nil {
t.Fatalf("StartWorkflow(%s): %v", wfID, err)
}
wf, _, _ := enA.DescribeWorkflow("default", wfID, "")
schedActivity(t, enA, "default", wfID, wf.Execution.RunId, 0, "RunJobActivity", "cron-q", nil)
if err := enA.completeWorkflowActivity("default", wfID, wf.Execution.RunId, 0, nil, rbacDenied(t)); err != nil {
t.Fatalf("fail %s: %v", wfID, err)
}
}
if got := onlyStreak(t, enA, "default").ConsecutiveFailures; got != 3 {
t.Fatalf("consecutiveFailures before restart = %d, want 3 — the count must span RUNS, not reset per run", got)
}
// Crash: a fresh engine (empty in-memory state) over the SAME store.
enB := newEngine(s)
captureLogs(enB)
rec := onlyStreak(t, enB, "default")
if rec.ConsecutiveFailures != 3 {
t.Fatalf("consecutiveFailures after restart = %d, want 3", rec.ConsecutiveFailures)
}
if rec.ActivityType != "RunJobActivity" {
t.Fatalf("streak identity lost across restart: %+v", rec)
}
// And it keeps counting from where it was, rather than starting over.
if _, err := enB.StartWorkflow("default", "fire-4", "", TypeRef{Name: "JobWorkflow"}, "cron-q", []any{}); err != nil {
t.Fatalf("StartWorkflow(fire-4): %v", err)
}
wf, _, _ := enB.DescribeWorkflow("default", "fire-4", "")
schedActivity(t, enB, "default", "fire-4", wf.Execution.RunId, 0, "RunJobActivity", "cron-q", nil)
if err := enB.completeWorkflowActivity("default", "fire-4", wf.Execution.RunId, 0, nil, rbacDenied(t)); err != nil {
t.Fatalf("fail fire-4: %v", err)
}
if got := onlyStreak(t, enB, "default").ConsecutiveFailures; got != 4 {
t.Fatalf("consecutiveFailures after restart+failure = %d, want 4", got)
}
}
// TestScheduleFiredActivityFailureNamesTheSchedule is the incident end to
// end: a cron schedule fires, its activity fails, and the evidence must name
// the SCHEDULE. Without it a report can only say "some JobWorkflow is
// broken" — never "the nightly backup has not run", which is the question
// eleven days of missing backups actually asked.
func TestScheduleFiredActivityFailureNamesTheSchedule(t *testing.T) {
s := newStore()
defer s.close()
en := newEngine(s)
captureLogs(en)
if err := en.RegisterNamespace(Namespace{NamespaceInfo: NamespaceInfo{Name: "default"}}); err != nil {
t.Fatalf("RegisterNamespace: %v", err)
}
if err := en.CreateSchedule(Schedule{
ScheduleId: "nightly-backup",
Namespace: "default",
Spec: ScheduleSpec{CronString: []string{"* * * * *"}},
Action: ScheduleAction{WorkflowType: TypeRef{Name: "JobWorkflow"}, TaskQueue: "cron-q"},
}); err != nil {
t.Fatalf("CreateSchedule: %v", err)
}
backdate(t, en, "default", "nightly-backup", 5*time.Minute)
if err := en.sweepSchedules(); err != nil {
t.Fatalf("sweepSchedules: %v", err)
}
// The fire succeeded — exactly as it did 4489 times in production.
runs, err := en.ListWorkflows("default")
if err != nil || len(runs) != 1 {
t.Fatalf("workflows after sweep = %d (err=%v), want 1", len(runs), err)
}
wfID, run := runs[0].Execution.WorkflowId, runs[0].Execution.RunId
// Now break the layer below, where the real fault lived.
schedActivity(t, en, "default", wfID, run, 0, "RunJobActivity", "cron-q", nil)
if err := en.completeWorkflowActivity("default", wfID, run, 0, nil, rbacDenied(t)); err != nil {
t.Fatalf("completeWorkflowActivity: %v", err)
}
if got := onlyStreak(t, en, "default").ScheduleId; got != "nightly-backup" {
t.Fatalf("streak scheduleId = %q, want %q — the failure must name the cron entry that is dead", got, "nightly-backup")
}
}
// TestActivityFailureIsThrottled proves the report does not become the new
// flood. A broken cron re-fires forever; unthrottled that is thousands of
// identical lines a day, which buries the signal as thoroughly as silence
// did. The DURABLE count stays exact — throttling is about lines, never
// about evidence.
func TestActivityFailureIsThrottled(t *testing.T) {
s := newStore()
defer s.close()
en := newEngine(s)
logs := captureLogs(en)
run := failNS(t, en, "default", "job-loud", "JobWorkflow", "cron-q")
const fires = 3 * failReportThrottle
for i := 0; i < fires; i++ {
schedActivity(t, en, "default", "job-loud", run, i, "RunJobActivity", "cron-q", nil)
if err := en.completeWorkflowActivity("default", "job-loud", run, i, nil, rbacDenied(t)); err != nil {
t.Fatalf("fail #%d: %v", i+1, err)
}
}
lines := len(withMsg(logs(), msgActivityFailed)) + len(withMsg(logs(), msgActivityPersistent))
if lines > fires/10 {
t.Fatalf("log lines after %d failures = %d, want the throttle to hold it near %d",
fires, lines, fires/failReportThrottle)
}
if lines == 0 {
t.Fatal("log lines = 0: throttling must not mean silence")
}
if got := onlyStreak(t, en, "default").ConsecutiveFailures; got != fires {
t.Fatalf("durable consecutiveFailures = %d, want %d — the throttle bounds LINES, not evidence", got, fires)
}
}
// TestActivityFailurePersistentIsAlertable is the distinction the incident
// turned on: "failed once and will retry" (normal, WARN) versus "has failed
// every attempt for a long time" (the outage, ERROR). Both were equally
// invisible before; reporting them at the same volume would be almost as
// useless.
func TestActivityFailurePersistentIsAlertable(t *testing.T) {
s := newStore()
defer s.close()
en := newEngine(s)
logs := captureLogs(en)
run := failNS(t, en, "default", "job-p", "JobWorkflow", "cron-q")
// A retryable failure with attempts left: the benign case.
schedActivity(t, en, "default", "job-p", run, 0, "RunJobActivity", "cron-q",
&client.RetryPolicyJSON{InitialIntervalMs: 1, MaximumAttempts: 5})
transient, err := temporal.Encode(temporal.NewError("connection reset", temporal.CodeApplication, false))
if err != nil {
t.Fatalf("encode: %v", err)
}
if err := en.completeWorkflowActivity("default", "job-p", run, 0, nil, transient); err != nil {
t.Fatalf("transient failure: %v", err)
}
warns := withMsg(logs(), msgActivityFailed)
if len(warns) != 1 {
t.Fatalf("lines for a first, retryable failure = %d, want 1; records: %v", len(warns), logs())
}
wantFields(t, warns[0], map[string]any{"level": "WARN", "retrying": true, "attempt": 1})
if n := len(withMsg(logs(), msgActivityPersistent)); n != 0 {
t.Fatalf("persistent lines after ONE failure = %d, want 0 — a blip must not page anyone", n)
}
// Age the streak into the incident's shape: still failing, long enough
// that no single run's retry budget explains it.
id := failureIdentity{Namespace: "default", WorkflowType: "JobWorkflow", ActivityType: "RunJobActivity", TaskQueue: "cron-q"}
key := failKey("default", id.fingerprint())
var rec FailureStreak
if ok, _ := en.store.get(key, &rec); !ok {
t.Fatal("no streak row to age; the test's premise is gone")
}
rec.FirstFailureTime = time.Now().UTC().Add(-11 * 24 * time.Hour).Format(time.RFC3339)
if err := en.store.put(key, rec); err != nil {
t.Fatalf("age streak: %v", err)
}
schedActivity(t, en, "default", "job-p", run, 1, "RunJobActivity", "cron-q", nil)
if err := en.completeWorkflowActivity("default", "job-p", run, 1, nil, rbacDenied(t)); err != nil {
t.Fatalf("persistent failure: %v", err)
}
// Reports on the TRANSITION, not on the throttle's next tick: a nightly
// cron reaches only its second failure in two days, and waiting for #60
// would be the original bug wearing a different hat.
persistent := withMsg(logs(), msgActivityPersistent)
if len(persistent) != 1 {
t.Fatalf("persistent lines = %d, want 1 (reported at the crossing); records: %v", len(persistent), logs())
}
wantFields(t, persistent[0], map[string]any{
"level": "ERROR",
"activityType": "RunJobActivity",
"consecutiveFailures": 2,
})
if !onlyStreak(t, en, "default").Persistent {
t.Fatal("durable streak not marked persistent")
}
}
// TestActivityRecoveryClearsStreak closes the loop the throttle opens: with
// no recovery line an operator cannot tell a fixed activity from one whose
// next throttled line has not come round yet. The durable row must go too —
// the keyspace answers "what is broken NOW".
func TestActivityRecoveryClearsStreak(t *testing.T) {
s := newStore()
defer s.close()
en := newEngine(s)
logs := captureLogs(en)
run := failNS(t, en, "default", "job-r", "JobWorkflow", "cron-q")
schedActivity(t, en, "default", "job-r", run, 0, "RunJobActivity", "cron-q", nil)
if err := en.completeWorkflowActivity("default", "job-r", run, 0, nil, rbacDenied(t)); err != nil {
t.Fatalf("fail: %v", err)
}
onlyStreak(t, en, "default") // must exist before we fix it
schedActivity(t, en, "default", "job-r", run, 1, "RunJobActivity", "cron-q", nil)
if err := en.completeWorkflowActivity("default", "job-r", run, 1, []byte(`"ok"`), nil); err != nil {
t.Fatalf("succeed: %v", err)
}
rows, err := en.FailureStreaks("default")
if err != nil {
t.Fatalf("FailureStreaks: %v", err)
}
if len(rows) != 0 {
t.Fatalf("streaks after recovery = %d, want 0; rows: %+v", len(rows), rows)
}
recovered := withMsg(logs(), msgActivityRecovered)
if len(recovered) != 1 {
t.Fatalf("recovery lines = %d, want 1; records: %v", len(recovered), logs())
}
wantFields(t, recovered[0], map[string]any{
"level": "INFO",
"activityType": "RunJobActivity",
"afterConsecutiveFailures": 1,
})
}
// TestStandaloneActivityFailureRecorded covers the other activity family —
// the fleet queue's fn.run / studio.render jobs, which never touch the
// workflow path and had exactly the same SSE-only output.
func TestStandaloneActivityFailureRecorded(t *testing.T) {
s := newStore()
defer s.close()
en := newEngine(s)
logs := captureLogs(en)
if err := en.RegisterNamespace(Namespace{NamespaceInfo: NamespaceInfo{Name: "gpu-jobs"}}); err != nil {
t.Fatalf("RegisterNamespace: %v", err)
}
start := func(id string) *StandaloneActivity {
t.Helper()
a, err := en.StartActivity("gpu-jobs", id, "", TypeRef{Name: "studio.render"}, "gpu-q",
nil, nil, "", "", "", "", "worker-1", "")
if err != nil {
t.Fatalf("StartActivity(%s): %v", id, err)
}
return a
}
a := start("render-1")
if err := en.FailActivity("gpu-jobs", "render-1", a.Execution.RunId, "CUDA out of memory", "worker-1"); err != nil {
t.Fatalf("FailActivity: %v", err)
}
rec := onlyStreak(t, en, "gpu-jobs")
if rec.ActivityType != "studio.render" || rec.TaskQueue != "gpu-q" || rec.LastError != "CUDA out of memory" {
t.Fatalf("standalone streak = %+v, want studio.render on gpu-q with the cause", rec)
}
if rec.WorkflowType != "" {
t.Fatalf("standalone streak claims workflowType %q; there is no enclosing workflow", rec.WorkflowType)
}
if n := len(withMsg(logs(), msgActivityFailed)); n != 1 {
t.Fatalf("log lines = %d, want 1; records: %v", n, logs())
}
// One success proves the fault is not systematic, so the streak ends.
b := start("render-2")
if err := en.CompleteActivity("gpu-jobs", "render-2", b.Execution.RunId, "frame.png", "worker-1"); err != nil {
t.Fatalf("CompleteActivity: %v", err)
}
rows, err := en.FailureStreaks("gpu-jobs")
if err != nil {
t.Fatalf("FailureStreaks: %v", err)
}
if len(rows) != 0 {
t.Fatalf("streaks after a successful render = %d, want 0; rows: %+v", len(rows), rows)
}
}
// TestWorkflowFailureRecorded covers the hole an activity-only report would
// leave: a decider that faults before scheduling anything (bad input, a
// panic on episode 0) fails a workflow with no activity record to speak for
// it — the same class of bug with an even thinner trail.
func TestWorkflowFailureRecorded(t *testing.T) {
s := newStore()
defer s.close()
en := newEngine(s)
logs := captureLogs(en)
failNS(t, en, "default", "job-w", "JobWorkflow", "cron-q")
boom, err := temporal.Encode(temporal.NewError("unmarshal job spec: unexpected end of JSON input", temporal.CodeApplication, true))
if err != nil {
t.Fatalf("encode: %v", err)
}
if _, err := en.terminalTransition("default", "job-w", "", "WORKFLOW_EXECUTION_STATUS_FAILED",
"workflow.failed", "WORKFLOW_EXECUTION_FAILED", map[string]any{"failure": string(boom)}); err != nil {
t.Fatalf("terminalTransition: %v", err)
}
rec := onlyStreak(t, en, "default")
if rec.WorkflowType != "JobWorkflow" || rec.TaskQueue != "cron-q" {
t.Fatalf("workflow streak = %+v, want JobWorkflow on cron-q", rec)
}
if rec.ActivityType != "" {
t.Fatalf("workflow streak names activityType %q; nothing was scheduled", rec.ActivityType)
}
if rec.LastError == "" {
t.Fatal("workflow streak carries no error: the decoded failure is the actionable part")
}
fails := withMsg(logs(), msgWorkflowFailed)
if len(fails) != 1 {
t.Fatalf("workflow failure lines = %d, want 1; records: %v", len(fails), logs())
}
wantFields(t, fails[0], map[string]any{"workflowType": "JobWorkflow", "consecutiveFailures": 1})
}
// TestFailureReportingPreservesRetrySemantics is the guard on the promise
// that this change only OBSERVES. The activity must still be retried exactly
// MaximumAttempts times, still end FAILED, and still leave the history it
// left before — reporting rides alongside, it does not steer.
func TestFailureReportingPreservesRetrySemantics(t *testing.T) {
s := newStore()
defer s.close()
en := newEngine(s)
captureLogs(en)
cap := &captureSend{}
en.disp.send = cap.fn
run := failNS(t, en, "default", "job-s", "JobWorkflow", "tq")
if _, err := en.disp.Subscribe("actPeer", "default", "tq", kindActivity); err != nil {
t.Fatalf("subscribe: %v", err)
}
const maxAttempts = 3
schedActivity(t, en, "default", "job-s", run, 0, "RunJobActivity", "tq",
&client.RetryPolicyJSON{InitialIntervalMs: 1, BackoffCoefficient: 1, MaximumAttempts: maxAttempts})
retryable, err := temporal.Encode(temporal.NewError("timeout", temporal.CodeApplication, false))
if err != nil {
t.Fatalf("encode: %v", err)
}
for i := 0; i < maxAttempts; i++ {
if err := en.completeWorkflowActivity("default", "job-s", run, 0, nil, retryable); err != nil {
t.Fatalf("attempt %d: %v", i+1, err)
}
// The retry is armed on a timer; wait for the re-dispatch so the next
// completion lands on the attempt this one scheduled.
if i < maxAttempts-1 {
waitFor(t, func() bool {
rec, ok, _ := en.getWorkflowActivity("default", "job-s", run, 0)
return ok && rec.Attempt == i+2 && rec.Status == wfActStarted
}, "re-dispatch of attempt %d", i+2)
}
}
rec, ok, _ := en.getWorkflowActivity("default", "job-s", run, 0)
if !ok || rec.Status != wfActFailed {
t.Fatalf("activity status = %v (ok=%v), want %s after exhausting retries", rec, ok, wfActFailed)
}
if rec.Attempt != maxAttempts {
t.Fatalf("attempts = %d, want %d — reporting must not change the retry budget", rec.Attempt, maxAttempts)
}
if got := countEventType(t, en, "job-s", run, evtActivityFailed); got != 1 {
t.Fatalf("ACTIVITY_TASK_FAILED events = %d, want 1 (terminal only)", got)
}
if got := countDeliveries(cap, OpcodeDeliverActivityTask); got != maxAttempts {
t.Fatalf("activity dispatches = %d, want %d", got, maxAttempts)
}
// One streak spanning all three attempts, not three streaks: identity is
// the shape of the work, not the attempt.
if got := onlyStreak(t, en, "default").ConsecutiveFailures; got != maxAttempts {
t.Fatalf("consecutiveFailures = %d, want %d", got, maxAttempts)
}
}
// waitFor polls cond until it holds or the deadline passes.
func waitFor(t *testing.T, cond func() bool, what string, args ...any) {
t.Helper()
deadline := time.Now().Add(3 * time.Second)
for time.Now().Before(deadline) {
if cond() {
return
}
time.Sleep(2 * time.Millisecond)
}
t.Fatalf("timed out waiting for "+what, args...)
}
// TestFailureStreaksAreOrgScoped: two orgs breaking the same activity type
// must not share a row or a count. Multi-tenancy is not observability's to
// blur — "whose nightly backup is dead" is the first question asked.
func TestFailureStreaksAreOrgScoped(t *testing.T) {
s := newStore()
defer s.close()
root := newEngine(s)
captureLogs(root)
for _, org := range []string{"acme", "globex"} {
en := root.As(Org(org))
run := failNS(t, en, "default", "job-"+org, "JobWorkflow", "cron-q")
schedActivity(t, en, "default", "job-"+org, run, 0, "RunJobActivity", "cron-q", nil)
if err := en.completeWorkflowActivity("default", "job-"+org, run, 0, nil, rbacDenied(t)); err != nil {
t.Fatalf("fail %s: %v", org, err)
}
}
// Break acme a second time; globex must not move.
acme := root.As(Org("acme"))
if _, err := acme.StartWorkflow("default", "job-acme-2", "", TypeRef{Name: "JobWorkflow"}, "cron-q", []any{}); err != nil {
t.Fatalf("StartWorkflow: %v", err)
}
wf, _, _ := acme.DescribeWorkflow("default", "job-acme-2", "")
schedActivity(t, acme, "default", "job-acme-2", wf.Execution.RunId, 0, "RunJobActivity", "cron-q", nil)
if err := acme.completeWorkflowActivity("default", "job-acme-2", wf.Execution.RunId, 0, nil, rbacDenied(t)); err != nil {
t.Fatalf("fail acme again: %v", err)
}
acmeRec := onlyStreak(t, acme, "default")
globexRec := onlyStreak(t, root.As(Org("globex")), "default")
if acmeRec.Org != "acme" || globexRec.Org != "globex" {
t.Fatalf("streak orgs = %q / %q, want acme / globex", acmeRec.Org, globexRec.Org)
}
if acmeRec.ConsecutiveFailures != 2 || globexRec.ConsecutiveFailures != 1 {
t.Fatalf("counts = acme %d / globex %d, want 2 / 1 — one org's fault must not inflate another's",
acmeRec.ConsecutiveFailures, globexRec.ConsecutiveFailures)
}
}
+390
View File
@@ -0,0 +1,390 @@
// Copyright © 2026 Hanzo AI. MIT License.
package tasks
import (
"bytes"
"encoding/json"
"log/slog"
"strings"
"testing"
"time"
)
// These tests pin the OBSERVABILITY half of the cron sweeper. The firing
// half is covered by schedule_fire_test.go; what is covered here is that a
// fire which does not reach a worker says so.
//
// The motivating incident: cloud's clients/cron schedules fire a
// JobWorkflow whose activity re-reads the entry's ConfigMap at fire time.
// The cloud ServiceAccount had no RBAC to read ConfigMaps, so the activity
// failed on every fire — for 11 days, across six nightly backups, while the
// engine emitted NOTHING and every dashboard read healthy. The engine's own
// durable records were the only witness. Isolation (one broken schedule
// must not stop the sweep) is correct and stays; silence is the bug.
//
// The property asserted is "the fire REACHED A WORKER", not "the namespace
// was registered". A namespace is an addressing fact created on first use,
// so its absence was never the fault — it was a proxy for one, and a proxy
// that misses the three shapes an operator actually hits: a cron naming a
// namespace nobody serves, a schedule whose worker died, a task queue that
// was renamed out from under it. All three start the run and then execute
// nothing, which is exactly the silence this file exists to break.
// captureLogs points the engine's logger at a buffer and returns a reader
// over the structured records it captured. JSON so assertions are on
// FIELDS, not on substrings of a formatted line.
func captureLogs(en *engine) func() []map[string]any {
buf := &bytes.Buffer{}
en.log = slog.New(slog.NewJSONHandler(buf, &slog.HandlerOptions{Level: slog.LevelDebug}))
return func() []map[string]any {
var out []map[string]any
for _, line := range strings.Split(buf.String(), "\n") {
if strings.TrimSpace(line) == "" {
continue
}
var m map[string]any
if err := json.Unmarshal([]byte(line), &m); err != nil {
continue
}
out = append(out, m)
}
return out
}
}
// withMsg filters captured records down to one log message.
func withMsg(recs []map[string]any, msg string) []map[string]any {
var out []map[string]any
for _, r := range recs {
if s, _ := r["msg"].(string); s == msg {
out = append(out, r)
}
}
return out
}
// wantFields asserts every key/value pair is present on the record.
// Numbers arrive as float64 through JSON, so ints are compared numerically.
func wantFields(t *testing.T, rec map[string]any, want map[string]any) {
t.Helper()
for k, v := range want {
got, ok := rec[k]
if !ok {
t.Fatalf("log record missing field %q; got %v", k, rec)
}
if n, isInt := v.(int); isInt {
f, isNum := got.(float64)
if !isNum || int(f) != n {
t.Fatalf("log field %q = %v, want %d", k, got, n)
}
continue
}
if got != v {
t.Fatalf("log field %q = %v, want %v", k, got, v)
}
}
}
// dueSchedule creates a schedule and backdates it so the next sweep fires
// it. Whether that fire reaches anything is decided separately, by whether
// a worker is subscribed — the two are orthogonal, so the tests compose
// them instead of each minting its own flavour of broken.
func dueSchedule(t *testing.T, en *engine, ns, id, wfType, queue string) {
t.Helper()
if err := en.CreateSchedule(Schedule{
ScheduleId: id,
Namespace: ns,
Spec: ScheduleSpec{CronString: []string{"* * * * *"}},
Action: ScheduleAction{WorkflowType: TypeRef{Name: wfType}, TaskQueue: queue},
}); err != nil {
t.Fatalf("CreateSchedule(%s): %v", id, err)
}
backdate(t, en, ns, id, 5*time.Minute)
}
// subscribe puts a worker on (ns, queue) and returns its subscription id,
// so a test can take the worker away again. The dispatcher is shared across
// every tenant view, which is why an org's schedule is served by a worker
// subscribed through the root engine.
func subscribe(t *testing.T, en *engine, ns, queue string) string {
t.Helper()
id, err := en.disp.Subscribe(newRandID(), ns, queue, kindWorkflow)
if err != nil {
t.Fatalf("Subscribe(%s/%s): %v", ns, queue, err)
}
return id
}
// TestScheduleSweepReportsBrokenAction is the regression test for the
// silent-cron defect: a fire that reaches no worker must produce a log line
// carrying everything an operator needs to act — and the sweep must still
// fire everyone else.
//
// "ghost" is a namespace nobody serves. It is created by the fire, the run
// is recorded, and then NOTHING executes it — the exact shape of a cron
// entry with a typo in its namespace, and the reason "is the namespace
// registered?" is not the question worth asking.
func TestScheduleSweepReportsBrokenAction(t *testing.T) {
en := newEngine(newStore())
logs := captureLogs(en)
// Sorts before the healthy entry so the test also proves iteration
// continues past the failure.
dueSchedule(t, en, "ghost", "a-broken", "GhostProbe", "ghost-q")
dueSchedule(t, en, "default", "b-healthy", "HealthyProbe", "ok-q")
subscribe(t, en, "default", "ok-q")
if err := en.sweepSchedules(); err != nil {
t.Fatalf("sweepSchedules: %v", err)
}
fails := withMsg(logs(), msgActionFailed)
if len(fails) != 1 {
t.Fatalf("failure log lines = %d, want 1; records: %v", len(fails), logs())
}
wantFields(t, fails[0], map[string]any{
"level": "ERROR",
"org": "",
"namespace": "ghost",
"scheduleId": "a-broken",
"workflowType": "GhostProbe",
"taskQueue": "ghost-q",
"consecutiveFailures": 1,
})
if errText, _ := fails[0]["error"].(string); !strings.Contains(errText, ErrNoWorkersSubscribed.Error()) {
t.Fatalf("error field = %q, want it to name the cause", errText)
}
// The run EXISTS. That is what makes the old proxy insufficient and
// this assertion the point: a start that succeeded is not a fire that
// ran, and only the report tells them apart.
if got := countByType(t, en, "ghost", "GhostProbe"); got != 1 {
t.Fatalf("GhostProbe executions = %d, want 1 — the run is started, just unreachable", got)
}
// Isolation is the behaviour we are NOT changing: the healthy sibling
// still fired despite the broken one being swept first.
if got := countByType(t, en, "default", "HealthyProbe"); got != 1 {
t.Fatalf("HealthyProbe executions = %d, want 1 (reporting must not break isolation)", got)
}
}
// TestScheduleSweepReportsOrgOnBrokenAction proves the org reaches the log
// line. The root sweeper fires other tenants' schedules through a throwaway
// view; without the org a cloud operator cannot tell WHOSE nightly backup
// is dead, which is exactly the question the 11-day incident asked.
func TestScheduleSweepReportsOrgOnBrokenAction(t *testing.T) {
root := newEngine(newStore())
logs := captureLogs(root)
org := root.As(Org("acme"))
dueSchedule(t, org, "acme-ns", "org-broken", "OrgProbe", "org-q")
if err := root.sweepSchedules(); err != nil {
t.Fatalf("sweepSchedules: %v", err)
}
fails := withMsg(logs(), msgActionFailed)
if len(fails) != 1 {
t.Fatalf("failure log lines = %d, want 1; records: %v", len(fails), logs())
}
wantFields(t, fails[0], map[string]any{
"org": "acme",
"namespace": "acme-ns",
"scheduleId": "org-broken",
})
}
// TestScheduleSweepThrottlesRepeatFailures proves the report does not
// flood. A schedule firing into a queue nobody serves keeps firing on its
// own cadence and keeps reaching nobody — unthrottled that is a line every
// tick forever, which hides the signal just as well as silence.
// First failure alerts, then one line per failReportThrottle sweeps.
func TestScheduleSweepThrottlesRepeatFailures(t *testing.T) {
en := newEngine(newStore())
logs := captureLogs(en)
dueSchedule(t, en, "ghost", "loud", "GhostProbe", "q")
for i := 0; i < failReportThrottle; i++ {
// A fire that STARTED re-anchors, so make it due again rather than
// leaning on a failed start leaving it due.
backdate(t, en, "ghost", "loud", 5*time.Minute)
if err := en.sweepSchedules(); err != nil {
t.Fatalf("sweepSchedules #%d: %v", i+1, err)
}
}
fails := withMsg(logs(), msgActionFailed)
if len(fails) != 2 {
t.Fatalf("log lines after %d failing sweeps = %d, want 2 (first + one throttled heartbeat)",
failReportThrottle, len(fails))
}
wantFields(t, fails[0], map[string]any{"consecutiveFailures": 1})
wantFields(t, fails[1], map[string]any{"consecutiveFailures": failReportThrottle})
}
// TestScheduleSweepReportsRecoveryAndRelapse walks the whole tracker
// lifecycle: fail (alert) → fail quietly (throttled) → succeed (recovery
// line naming how long it was broken) → fail again (alerts IMMEDIATELY,
// not on the old throttle cadence). Without the recovery line an operator
// cannot distinguish a fixed schedule from one whose next throttled line
// simply has not come round yet.
func TestScheduleSweepReportsRecoveryAndRelapse(t *testing.T) {
en := newEngine(newStore())
logs := captureLogs(en)
// A worker IS subscribed, so recovery means what it says: the action
// started AND reached somebody.
subscribe(t, en, "default", "flappy-q")
// Broken by an EMPTY workflow type, so the fault can be introduced and
// repaired in place by rewriting the row.
if err := en.CreateSchedule(Schedule{
ScheduleId: "flappy",
Namespace: "default",
Spec: ScheduleSpec{CronString: []string{"* * * * *"}},
Action: ScheduleAction{TaskQueue: "flappy-q"},
}); err != nil {
t.Fatalf("CreateSchedule: %v", err)
}
// Three failing sweeps → exactly one line (first alert, rest throttled).
for i := 0; i < 3; i++ {
backdate(t, en, "default", "flappy", 5*time.Minute)
if err := en.sweepSchedules(); err != nil {
t.Fatalf("failing sweep #%d: %v", i+1, err)
}
}
if n := len(withMsg(logs(), msgActionFailed)); n != 1 {
t.Fatalf("failure lines after 3 failing sweeps = %d, want 1", n)
}
// Repair the action, then sweep: recovery must be reported, and must
// carry how many consecutive failures preceded it.
setWorkflowType(t, en, "default", "flappy", "FlappyProbe")
backdate(t, en, "default", "flappy", 5*time.Minute)
if err := en.sweepSchedules(); err != nil {
t.Fatalf("recovery sweep: %v", err)
}
recovered := withMsg(logs(), msgActionRecovered)
if len(recovered) != 1 {
t.Fatalf("recovery lines = %d, want 1; records: %v", len(recovered), logs())
}
wantFields(t, recovered[0], map[string]any{
"level": "INFO",
"namespace": "default",
"scheduleId": "flappy",
"afterConsecutiveFailures": 3,
})
if got := countByType(t, en, "default", "FlappyProbe"); got != 1 {
t.Fatalf("FlappyProbe executions = %d, want 1", got)
}
// Break it again: the counter was cleared, so this alerts at once
// instead of waiting out the throttle.
setWorkflowType(t, en, "default", "flappy", "")
backdate(t, en, "default", "flappy", 5*time.Minute)
if err := en.sweepSchedules(); err != nil {
t.Fatalf("relapse sweep: %v", err)
}
fails := withMsg(logs(), msgActionFailed)
if len(fails) != 2 {
t.Fatalf("failure lines after relapse = %d, want 2", len(fails))
}
wantFields(t, fails[1], map[string]any{"consecutiveFailures": 1})
}
// TestScheduleSweepReportsWorkerGone covers what the old
// namespace-registration proxy could never see: a schedule that is
// perfectly configured, in a namespace that exists, whose WORKER went away.
// Nothing about the entry changed; it simply stopped running. The report
// must open when the worker leaves and close when one comes back.
func TestScheduleSweepReportsWorkerGone(t *testing.T) {
en := newEngine(newStore())
logs := captureLogs(en)
sub := subscribe(t, en, "default", "nightly-q")
dueSchedule(t, en, "default", "nightly", "BackupWorkflow", "nightly-q")
if err := en.sweepSchedules(); err != nil {
t.Fatalf("healthy sweep: %v", err)
}
if n := len(withMsg(logs(), msgActionFailed)); n != 0 {
t.Fatalf("failure lines while a worker is subscribed = %d, want 0; records: %v", n, logs())
}
// The worker goes away. The schedule is untouched.
en.disp.Unsubscribe(sub)
backdate(t, en, "default", "nightly", 5*time.Minute)
if err := en.sweepSchedules(); err != nil {
t.Fatalf("orphaned sweep: %v", err)
}
fails := withMsg(logs(), msgActionFailed)
if len(fails) != 1 {
t.Fatalf("failure lines after the worker left = %d, want 1; records: %v", len(fails), logs())
}
wantFields(t, fails[0], map[string]any{
"namespace": "default",
"scheduleId": "nightly",
"taskQueue": "nightly-q",
"consecutiveFailures": 1,
})
// A worker comes back: the streak closes.
subscribe(t, en, "default", "nightly-q")
backdate(t, en, "default", "nightly", 5*time.Minute)
if err := en.sweepSchedules(); err != nil {
t.Fatalf("recovery sweep: %v", err)
}
recovered := withMsg(logs(), msgActionRecovered)
if len(recovered) != 1 {
t.Fatalf("recovery lines = %d, want 1; records: %v", len(recovered), logs())
}
wantFields(t, recovered[0], map[string]any{"afterConsecutiveFailures": 1})
}
// setWorkflowType rewrites a stored schedule's action type in place,
// breaking ("") or repairing it without touching anything else.
func setWorkflowType(t *testing.T, en *engine, ns, id, wfType string) {
t.Helper()
s, ok, err := en.DescribeSchedule(ns, id)
if err != nil || !ok {
t.Fatalf("DescribeSchedule(%s/%s): ok=%v err=%v", ns, id, ok, err)
}
s.Action.WorkflowType.Name = wfType
if err := en.store.put("sc/"+ns+"/"+id, *s); err != nil {
t.Fatalf("setWorkflowType: %v", err)
}
}
// TestSweepOnceReportsSweepError covers the other half of the defect: the
// scheduler tick used to discard the sweep error outright (`_ =
// e.sweepSchedules()`). A sweep that fails WHOLESALE stops cron for every
// org at once, and used to do it without a word.
func TestSweepOnceReportsSweepError(t *testing.T) {
en := newEngine(newStore())
logs := captureLogs(en)
if err := en.RegisterNamespace(Namespace{NamespaceInfo: NamespaceInfo{Name: "default"}}); err != nil {
t.Fatalf("RegisterNamespace: %v", err)
}
// Closing the store makes every shard read fail, so the cross-org scan
// that opens the sweep cannot complete.
if err := en.store.close(); err != nil {
t.Fatalf("close store: %v", err)
}
if err := en.sweepSchedules(); err == nil {
t.Fatal("sweepSchedules on a closed store returned nil; the test's premise is gone")
}
// The same throttle applies: a permanently unhappy store must not log
// on every one of the 5s ticks either.
for i := 0; i < failReportThrottle; i++ {
en.sweepOnce()
}
sweeps := withMsg(logs(), msgSweepFailed)
if len(sweeps) != 2 {
t.Fatalf("sweep-failure lines after %d failing ticks = %d, want 2 (first + one throttled heartbeat); records: %v",
failReportThrottle, len(sweeps), logs())
}
wantFields(t, sweeps[0], map[string]any{"level": "ERROR", "consecutiveFailures": 1})
if errText, _ := sweeps[0]["error"].(string); errText == "" {
t.Fatal("sweep-failure line carries no error field")
}
}