Skip to content

Commit defc7f7

Browse files
fix(service-automation): a flow switched off in the activation ledger stays unbound after a restart, and a trigger-fired refusal logs no run-history claim (#20677) (#20702)
Fixes #20677 Clause-②: no ## What was wrong A packaged flow switched off through the ADR-0126 activation ledger came back armed after a cold restart. At boot `AutomationServicePlugin.start()` pulls the flows and runs `hydrateFlowActivations()`, which leaves a switched-off flow unbound. The trigger plugins register later, at `kernel:ready`, and `AutomationEngine.registerTrigger` armed every registered, unbound flow of the matching type through `activateFlowTrigger` without asking whether the flow may run. So `GET /api/v1/automation/_status` reported `enabled: false, bound: true`. Every matching event then fired a run that `execute()` refused with `FLOW_DISABLED`, and the trigger-fired callback logged it at ERROR as a failed run whose failure "is recorded in the flow's run history". No row was written. **The card's reproduction, reached on current `main` at the engine level** (`14f80e23`, the pins in commit `1a7ce83b7` run against the unfixed engine): a boot replay over one activation store, in `plugin.ts`'s order (pull, hydrate, `kernel:ready` protocol sync, trigger registration, seal), reads on the first restart: ```text AssertionError: restart 1: expected { enabled: false, bound: true } to deeply equal { enabled: false, bound: false } ``` That is the card's `/_status` shape. On the unfixed code 10 of the 11 new cases are red, and the one control (a run that dispatched and failed) is green. ## What changes (`packages/services/service-automation/src/engine.ts` only) - **One enablement gate, in `activateFlowTrigger` itself.** It refuses to arm a flow `isFlowEnabled` answers `false` for, before the scheduled-work policy gate and before the trigger lookup. `registerFlow`, `registerTrigger`, the enable half of `toggleFlow`, and any arming path added later inherit it. `registerFlow`'s own caller-side `if (this.isFlowEnabled(name))` is folded into the gate, so there is one check, not two. `registerTrigger`'s loop is unchanged; only its comment now names the gate. - **The trigger-fired line states only what happened.** - A `FLOW_DISABLED` answer that still reaches the callback (an event in flight at the switch-off, or a trigger whose `stop()` failed) is logged at `info`: the flow is disabled, the run was refused before it started, nothing ran, and no run-history row records it. It is no longer logged at `error`. - Every other failure keeps the existing `error` line. That line says "the terminal failure is recorded in the flow's run history" only when the result carries `status: 'failed'`, the verdict `execute()`'s ran-and-failed exit and `retryExecution`'s exit set after writing their failed row. A never-dispatched answer (no `status`) gets the same line with "it was refused before it dispatched" in place of the history claim. - Same logging shape as before, with the envelope in the structured slot. No new log dialect. ## The dispatch's mechanism assumptions, measured - **A1: confirmed.** `registerTrigger` (was about :3368) called `activateFlowTrigger(name)` for every unbound flow of the matching type. Neither method consulted `isFlowEnabled`. `registerFlow`'s only ledger check was the caller-side guard around `activateFlowTrigger` (was :4271). The one at :4257 guards the node-type warning, not arming. The ordering is in `plugin.ts`: hydrate runs in `start()`, and the protocol sync and trigger plugins run at `kernel:ready`. - **A2: callers of `activateFlowTrigger`.** There are three: `registerTrigger`, `registerFlow` and `toggleFlow`'s enable branch. The only refused-flow bookkeeping is `policyDisabledFlows` (the scheduled-work refusal record). A disabled flow now returns before the policy gate, so it records no policy refusal. `describeUnboundReason` already answered `undefined` for a disabled flow, so neither the `/_status` `reason` nor `getTriggerBindingAudit()` changes. `/_status`'s `bound` reads `boundFlowTriggers`, which is now `false` for the flow. - **One behaviour change beyond the card's path:** `toggleFlow(name, true)` on a flow whose `status` is `obsolete` or `invalid` no longer arms it. Before, it was armed and every event it fired was refused with `FLOW_DISABLED` (the status dimension) and logged at ERROR, the same defect through the toggle. A status-disabled flow registered before its trigger was re-armed by `registerTrigger` too. Both are pinned. - The enable path for a ledger-disabled flow still arms, and that is pinned as well. - **A3: when `FLOW_DISABLED` reaches the log.** `execute()`'s disabled exit returns before a run id is minted and before any `recordLog`, so no row is ever written for it. Before the fix, it reached the ERROR line on every matching event of a re-armed flow. With the gate, it is reached only by the residue named above. - The run-row fact is `status: 'failed'`. The four `status`-less failure exits are flow not found, `FLOW_DISABLED`, `FLOW_NO_START_NODE` and `FLOW_INPUT_SCHEMA_INVALID`. The last one does write a failed row but carries no `status`, so the line makes no history claim for it: true, if less informative. **PR #20551's arm-time `api` secret refusal is untouched.** The gate sits before `trigger.start`. `validateApiTriggerSecret` at registration and `ApiTrigger.start()`'s throw (into the existing Failed-to-bind `warn`) are unchanged, and `api-trigger-secret-registration.test.ts` is green. ## Tests (all read at `758967616`, the last commit) - New `src/flow-activation-late-trigger.test.ts`, 11 cases: - A trigger registered after `hydrateFlowActivations()`, for each of `record_change`, `schedule`, `time_relative` and `api`: the switched-off flow stays `{ enabled: false, bound: false }`, and its enabled sibling of the same kind arms (the control). - The status dimension through the same path. - The enable path re-arms a hydrated-disabled flow, and the store row reads `active: true`. - Re-enabling the ledger bit of an `obsolete` flow does not arm it. - A cold restart over one store, twice: `enabled: false, bound: false` on both boots, the sibling bound, and the binding audit empty. - The three log-line cases: `FLOW_DISABLED` is logged at `info` with no history claim and `listRuns` is empty. A dispatched failure is logged at `error` with the claim and one `failed` row. A never-dispatched failure is logged at `error` with no claim and no row. - `pnpm --filter @objectstack/service-automation test`: `Test Files 155 passed (155)`, `Tests 1924 passed (1924)`. - `pnpm --filter @objectstack/service-automation typecheck`: exit 0 (`tsc --noEmit`, then `check:test-typecheck: OK`). `tsc -p tsconfig.test.json --listFiles` lists the new test file (1 hit). - **Ablation**, via `scripts/ablation-replace.mjs` in wrap mode (anchor must hit once, the restore is armed on EXIT/INT/TERM, and a shell trap `git checkout HEAD --` sits behind it). The subject resolves from `src/` through the relative `./engine.js` import, so no `dist/` leg applies. - **Gate deleted** (`if (!this.isFlowEnabled(flowName)) return;`, anchor x1 then x0, blob `566ed4d67921` then `d09694f76678`): `Tests 8 failed | 3 passed (11)`. The 8 are every arming pin. For example, `restart 1: expected { enabled: false, bound: true } to deeply equal { enabled: false, bound: false }`. The 3 log-line cases do not depend on the gate and stay green. - **`FLOW_DISABLED` branch disabled:** `Tests 1 failed | 10 passed`. The failing case is the `info` pin: `expected [ Array(1) ] to deeply equal []`, where the array holds an error line. - **History condition forced true:** `Tests 1 failed | 10 passed`. The failing case is the never-dispatched pin, which now claims a run-history row. - **Every restore proven:** `ok restored: blob == HEAD (566ed4d) and git diff HEAD is empty`. `git status --porcelain` is empty afterwards. ## Gates - `node scripts/pm/dispatch-gates.mjs --commands` re-derived against the real diff gives the same 62 commands as the dispatch list, byte-for-byte after sort. - Every exit code was captured before any pipe. 60 exit 0. - 2 are **NOT MEASURED**: `pnpm check:dual-build-cjs-loads` and `pnpm check:type-check-debt` both exit 3 (PREREQUISITE NOT MET: they read the whole workspace's built `dist/`, and this worktree built only this package's dependency closure). CI builds that and runs both. - `--ran`: `62 derived famil(ies) accounted for — 60 run, 2 NOT-MEASURED (2 DERIVED from a recorded exit 3)`. - The roster families printed outside the runnable list all exit 0: `node scripts/check-changeset-fixed.mjs`, `pnpm check:authz-resolver`, `pnpm check:error-code-casing` and `pnpm check:filter-alias-parity`. Added for the log-level and arming edit, also exit 0: `pnpm check:durability-log-level` and `pnpm check:startup-registry-verdict`. - **Lint, a declared narrowing** (`pnpm lint` over the whole repo is CI's): - Run: `eslint --no-inline-config --format json` on `engine.ts` and the new test file. - Result: 2 files, 0 errors, 0 warnings. - The changeset `.md` has no matching config (`--print-config` answers `undefined`, and the JSON says "File ignored because no matching configuration was supplied"), so it is outside eslint's population. - `eslint.config.mjs` never enables type-aware linting (no `parserOptions.project` or `projectService`), so this diff cannot move a verdict on any untouched file. - `pnpm check:nul-bytes`: exit 0. A control-byte self-scan of the three changed files finds nothing. ## Changeset `.changeset/20677-ledger-disabled-stays-unbound.md` is a `patch` on `@objectstack/service-automation`. No export, option, route or response shape moves. ## Acceptance notes - The cold-restart pin is engine-level: it replays `plugin.ts`'s boot order over one shared `InMemoryFlowActivationStore`. A LiteKernel boot of the real plugin was not built. The plugin attaches the durable ledger only through an `objectql` data engine with find/insert/update, so it would need a new data-engine double under `check:engine-double-contract`. The defect lives in the engine's arming path. - A test comment in `api-trigger-secret-registration.test.ts` says "an `obsolete` flow is re-enabled by a toggle". Under ADR-0126 the toggle moves only the ledger bit, so it never re-enables a status-disabled flow. This is comment drift, outside this card's file surface. Carrier: none. - A pre-existing edge, not filed: when `recordLog` itself throws on `execute()`'s failure arm, the result still carries `status: 'failed'`. The trigger-fired line then says the failure is recorded, while the separate ERROR line from that catch says the row never landed. The result has no channel for "the write failed", and the bookkeeping line is itself loud. Carrier: none. - `origin/main` has moved 3 commits since the base (`3b47a693c`, `0be898499`, `f379f57f4`). None touches `packages/services/service-automation` or `packages/spec/src/contracts`, so the branch is not merged forward. CI and the merge queue validate the merge ref. --- _Generated by [Claude Code](https://claude.ai/code/session_01XY5uCwTjZj7884yYtyur4H)_ --------- Co-authored-by: Claude <noreply@anthropic.com>
1 parent ed54768 commit defc7f7

3 files changed

Lines changed: 403 additions & 17 deletions

File tree

Lines changed: 39 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,39 @@
1+
---
2+
'@objectstack/service-automation': patch
3+
---
4+
5+
fix(service-automation): a flow switched off in the activation ledger stays unbound after a restart, and a trigger-fired refusal no longer logs an ERROR claiming a run-history row (#20677)
6+
7+
Clause-②: no
8+
9+
**What was wrong.** A packaged flow switched off through the ADR-0126 activation
10+
ledger (`POST /api/v1/automation/:name/toggle` with `enabled: false`) came back
11+
`bound: true` after every cold restart. Its runs were still refused, so the switch
12+
itself held, but its trigger was armed again. At boot the automation service pulls
13+
the flows and applies the ledger, which leaves a switched-off flow unbound. The
14+
trigger plugins register later, at `kernel:ready`, and registering a trigger armed
15+
every matching flow without asking whether it may run. So `GET
16+
/api/v1/automation/_status` reported the flow `enabled: false, bound: true`. Each
17+
matching event also logged `ERROR Trigger-fired run of flow '…' failed`, saying the
18+
failure "is recorded in the flow's run history", while no run row was written.
19+
20+
**What changed.**
21+
22+
- The engine checks whether a flow may run in one place: at the step that arms a
23+
trigger. Every arming path goes through it: flow registration (boot pull,
24+
publish, hot reload), trigger registration, and the enable toggle. A flow that
25+
either disable dimension switches off (the activation ledger, or an `obsolete` /
26+
`invalid` status) is never armed, whenever its trigger registers.
27+
- Re-enabling a flow arms it on its trigger as before. Re-enabling the ledger bit
28+
of a flow whose `status` is still `obsolete` or `invalid` no longer arms it, since
29+
every run it fired would be refused.
30+
- A trigger-fired run refused because the flow is disabled (for example, an event
31+
already in flight when the flow was switched off) is logged at `info`, saying
32+
nothing ran and no run-history row records it. It is no longer an `ERROR`.
33+
- The `ERROR` line for any other trigger-fired failure says the failure is
34+
recorded in the run history only for a run that dispatched and failed. A run
35+
refused before it dispatched gets the same line without that claim.
36+
37+
**What is not affected.** The runtime refusal (`FLOW_DISABLED`) and its message are
38+
unchanged. The enabled flows beside a disabled one arm exactly as before. No export,
39+
option, route or response shape changes.

‎packages/services/service-automation/src/engine.ts‎

Lines changed: 74 additions & 17 deletions
Original file line numberDiff line numberDiff line change
@@ -3371,6 +3371,10 @@ export class AutomationEngine implements IAutomationService {
33713371
// A trigger may be registered *after* its flows (e.g. AutomationServicePlugin
33723372
// pulls flows at start(); a trigger plugin wires up on kernel:ready, which
33733373
// fires later). Activate any already-registered flow that maps to this type.
3374+
// [ADR-0126 §7.2] A flow that may not run is skipped by
3375+
// `activateFlowTrigger`'s own enablement gate, so the flows the ledger
3376+
// hydration left unbound stay unbound here — ⛔ no second check in this
3377+
// loop: the gate is shared so no arming path can go without it.
33743378
for (const name of this.flows.keys()) {
33753379
if (this.boundFlowTriggers.has(name)) continue;
33763380
const resolved = this.resolveTriggerBinding(name);
@@ -3584,11 +3588,34 @@ export class AutomationEngine implements IAutomationService {
35843588

35853589
/**
35863590
* Bind a flow to its matching registered trigger (idempotent). No-op when
3587-
* the flow has no trigger binding or no trigger is registered for its type
3588-
* yet — {@link registerTrigger} re-attempts activation when one arrives.
3591+
* the flow may not run ({@link isFlowEnabled}), when it has no trigger
3592+
* binding, or when no trigger is registered for its type yet —
3593+
* {@link registerTrigger} re-attempts activation when one arrives.
35893594
*/
35903595
private activateFlowTrigger(flowName: string): void {
35913596
if (this.boundFlowTriggers.has(flowName)) return;
3597+
// [ADR-0126 §7.2] THE enablement gate for arming — here, at the one
3598+
// point every arming path crosses, and not in its callers. A flow
3599+
// either disable dimension switches off (the activation ledger, or an
3600+
// `obsolete` / `invalid` status) is never handed to a trigger, whichever
3601+
// path asks: {@link registerFlow} (boot pull, publish, hot reload),
3602+
// {@link registerTrigger}, the enable half of {@link toggleFlow}, and
3603+
// any path added later.
3604+
//
3605+
// Why it cannot live in the callers: `registerTrigger` runs when a
3606+
// trigger plugin registers at `kernel:ready`, AFTER `start()` pulled
3607+
// the flows and {@link hydrateFlowActivations} unbound the switched-off
3608+
// ones. While only `registerFlow` asked, that later registration
3609+
// re-armed every one of them on every cold boot — `/_status` reported a
3610+
// disabled flow `bound: true`, and each matching event fired a run
3611+
// `execute()` then refused.
3612+
//
3613+
// Silent on purpose: an unarmed disabled flow is the state the switch
3614+
// exists to produce, the host's hydration line already named it, and
3615+
// `getFlowRuntimeStates()` reports it `enabled: false`. Ahead of the
3616+
// scheduled-work policy gate below for the same reason — a flow that
3617+
// may not run has no policy refusal to record.
3618+
if (!this.isFlowEnabled(flowName)) return;
35923619
const resolved = this.resolveTriggerBinding(flowName);
35933620
if (!resolved) return;
35943621
// [#17396] The deployment gate, read HERE rather than only inside the
@@ -3661,18 +3688,44 @@ export class AutomationEngine implements IAutomationService {
36613688
// landed; the only other trace is the passive run-history row.
36623689
// That stderr also survives the CLI's boot-quiet stdout window is
36633690
// stream mechanics, not the verdict.
3691+
//
3692+
// [ADR-0126 §7.2] The line states only what happened. Two kinds of
3693+
// `execute()` answer are not a failed run:
3694+
// - `FLOW_DISABLED`: the flow was switched off after the trigger
3695+
// took the event — an event in flight at the switch-off, or a
3696+
// trigger whose `stop()` failed. The refusal IS the switch
3697+
// working, so it is said at `info`, never as an `error` that
3698+
// reads as a production failure. The enablement gate above
3699+
// keeps a disabled flow from being armed at all, so this is the
3700+
// residue, not the steady state.
3701+
// - every other never-dispatched exit (a `code` or a missing
3702+
// flow, and no `status`): no node ran, so the line claims no
3703+
// run-history row. Only a run that dispatched and failed
3704+
// carries `status: 'failed'` — the verdict that exit also wrote
3705+
// to the run history.
36643706
trigger.start(resolved.binding, (ctx: AutomationContext) =>
36653707
this.execute(flowName, ctx).then((result) => {
3666-
if (!result.success) {
3667-
this.logger.error(
3668-
`Trigger-fired run of flow '${flowName}' failed (trigger '${resolved.triggerType}') — ` +
3669-
`no caller holds this result and nothing retries the run; the terminal failure ` +
3670-
`is recorded in the flow's run history, and the run's failure envelope is in ` +
3671-
`this record's meta.`,
3672-
undefined,
3673-
{ error: result.error ?? 'unknown error' },
3708+
if (result.success) return;
3709+
if (result.code === 'FLOW_DISABLED') {
3710+
this.logger.info(
3711+
`Trigger '${resolved.triggerType}' fired flow '${flowName}', which is disabled — the ` +
3712+
`run was refused before it started, nothing ran, and no run-history row records ` +
3713+
`it. The refusal is in this record's meta.`,
3714+
{ error: result.error },
36743715
);
3716+
return;
36753717
}
3718+
this.logger.error(
3719+
`Trigger-fired run of flow '${flowName}' failed (trigger '${resolved.triggerType}') — ` +
3720+
`no caller holds this result and nothing retries the run; ` +
3721+
(result.status === 'failed'
3722+
? `the terminal failure is recorded in the flow's run history, and the run's ` +
3723+
`failure envelope is in this record's meta.`
3724+
: `it was refused before it dispatched, and the refusal envelope is in this ` +
3725+
`record's meta.`),
3726+
undefined,
3727+
{ error: result.error ?? 'unknown error' },
3728+
);
36763729
}),
36773730
);
36783731
this.boundFlowTriggers.set(flowName, resolved.triggerType);
@@ -4263,14 +4316,15 @@ export class AutomationEngine implements IAutomationService {
42634316
}
42644317

42654318
// Re-bind in case the definition changed its trigger, then (re)activate.
4266-
// [ADR-0126 §7.2] A ledger-disabled flow is NOT re-armed here, which is
4267-
// what makes the unbind survive a republish and a restart: the boot
4268-
// pull re-registers every flow, so a hydrated ledger row has to be
4269-
// able to keep a trigger unbound through exactly this path.
4319+
// [ADR-0126 §7.2] A disabled flow — ledger or status — is NOT re-armed
4320+
// here, which is what makes the unbind survive a republish and a
4321+
// restart: the boot pull re-registers every flow, so a hydrated ledger
4322+
// row has to be able to keep a trigger unbound through exactly this
4323+
// path. The refusal is `activateFlowTrigger`'s own enablement gate,
4324+
// the one every arming path shares — ⛔ not re-asked here, where a
4325+
// caller-side check once stood alone and `registerTrigger` had none.
42704326
this.deactivateFlowTrigger(name);
4271-
if (this.isFlowEnabled(name)) {
4272-
this.activateFlowTrigger(name);
4273-
}
4327+
this.activateFlowTrigger(name);
42744328

42754329
// #12206 (Option A) — hand the caller the canonicalized flow this
42764330
// registration stored: the same object `this.flows` now holds and
@@ -4657,6 +4711,9 @@ export class AutomationEngine implements IAutomationService {
46574711
// A disabled flow should stop receiving trigger events; a re-enabled one
46584712
// should resume. execute() also guards disabled flows, but unbinding
46594713
// avoids firing the trigger (and its event-source subscription) at all.
4714+
// Re-enabling moves only the LEDGER bit: a flow whose `status` still
4715+
// disables it stays unarmed, by `activateFlowTrigger`'s enablement gate
4716+
// — armed, it would only fire runs `execute()` refuses.
46604717
if (enabled) {
46614718
this.activateFlowTrigger(name);
46624719
} else {

0 commit comments

Comments
 (0)