Skip to content

Commit 2ea08ee

Browse files
os-zhuangclaude
andauthored
fix(automation): kill the four-layer silence around record-change flows that never fire (#3099)
2026-07-17 third-party eval: an auto-launched flow that failed to fire produced ZERO output at every layer. Root causes were two-fold: 1. serve's boot-quiet window swallows stdout entirely, and ObjectLogger routes debug/info/warn to stdout — so every flow-registration/binding log (success AND failure) vanished in `os dev`/`os start`. Only error/fatal (stderr) survive. 2. Each "didn't happen" path was itself silent: a trigger-fired execute() failure lived only in the run-history row; a flow whose objectName matches nothing armed a hook that never fires; a stack whose requires lacked automation/triggers just never bound anything. Fixes, layer by layer: - Startup banner `Flows:` section (post-restore, immune to the quiet window): counts + trigger types + ⚠ lines for engine-not-enabled, unbound triggered flows, and dead bindings (unknown object). - Trigger-fired run failures now log at ERROR (stderr): the engine no longer drops the AutomationResult of a trigger-fired execution. Condition-not-met skips stay at debug (high-frequency by design). - RecordChangeTrigger probes object existence at bind time and warns on an objectName that matches no registered object (exact-name match). - kernel:bootstrapped binding audit in the automation plugin: warn per enabled-but-unbound triggered flow with the actionable reason; new AutomationEngine.getTriggerBindingAudit() + extended getFlowRuntimeStates() (status/triggerType/object). - os validate: new lint rule validateFlowTriggerReadiness — warns when a record-triggered flow targets an object the stack does not define, and when an auto-triggered flow's status is draft (authored or defaulted; draft flows still fire — declare active/obsolete). Showcase flows now declare status: 'active' explicitly. - Removed the leftover boot-debug stderr writes (registerApp/AppPlugin/ StandaloneStack/AuditPlugin) that earlier debugging of this same silence left behind. Verified end-to-end on a real create-objectstack project (published- package layout): correct flows fire on REST PATCH across os start / os dev / restart; each mistake variant now produces its explicit signal. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
1 parent 89467f5 commit 2ea08ee

19 files changed

Lines changed: 929 additions & 35 deletions

File tree

Lines changed: 20 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,20 @@
1+
---
2+
'@objectstack/service-automation': minor
3+
'@objectstack/trigger-record-change': minor
4+
'@objectstack/lint': minor
5+
'@objectstack/cli': minor
6+
'@objectstack/objectql': patch
7+
'@objectstack/runtime': patch
8+
'@objectstack/plugin-audit': patch
9+
---
10+
11+
Flow trigger observability — kill the four-layer silence around record-change flows that never fire (2026-07-17 third-party eval).
12+
13+
A misauthored auto-launched flow (wrong `objectName`, missing `requires: ['automation','triggers']`, failing start condition) produced ZERO output at every layer: the engine's own registration/binding logs land inside the CLI's boot-quiet stdout window (which swallows debug/info/warn — only error/fatal reach stderr), and each "didn't happen" path was itself silent. Fixes:
14+
15+
- **Startup banner `Flows:` section** (`os serve`/`os dev`/`os start`): flow count, bound-to-trigger count, registered trigger types, draft count — plus loud `` lines for flows declared with no automation engine enabled (`requires` missing), flows whose trigger type has no registered trigger, and bound record-change flows targeting an unknown object (dead binding). Printed after stdout is restored, so it is immune to the boot-quiet window.
16+
- **Trigger-fired run failures now log at ERROR** (stderr — always visible): the automation engine no longer drops the AutomationResult of a trigger-fired execution; condition-evaluation faults and node failures surface with the flow name. Condition-not-met skips stay at debug (high-frequency, intentional).
17+
- **`RecordChangeTrigger` probes object existence at bind time** and warns when a flow's `objectName` matches no registered object (exact-name matching), instead of silently arming a hook that can never fire.
18+
- **`kernel:bootstrapped` binding audit** in the automation plugin: warns per enabled-but-unbound triggered flow with the reason, and reports registered/bound/draft counts (`AutomationEngine.getTriggerBindingAudit()`, extended `getFlowRuntimeStates()` with `status`/`triggerType`/`object`).
19+
- **`os validate` flow-wiring advisories** (`@objectstack/lint` `validateFlowTriggerReadiness`): warns when a record-triggered flow targets an object the stack does not define, and when an auto-triggered flow's status is `draft` (authored or defaulted — draft flows still fire; declare `active` or `obsolete`).
20+
- Removed leftover boot-debug writes (`registerApp`/`AppPlugin`/`StandaloneStack`/`AuditPlugin` stderr noise) that previous debugging of this same silence had left behind.

examples/app-showcase/src/automation/flows/index.ts

Lines changed: 16 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,7 @@ export const TaskCompletedFlow = defineFlow({
1111
label: 'Notify on Task Completed',
1212
description: 'Emails the project owner when a task is marked Done.',
1313
type: 'autolaunched',
14+
status: 'active',
1415
nodes: [
1516
{
1617
id: 'start',
@@ -106,6 +107,7 @@ export const TaskAssignedNotifyFlow = defineFlow({
106107
label: 'Notify Assignee on Task Assignment',
107108
description: 'Notifies the new assignee (inbox channel) when a task is reassigned.',
108109
type: 'autolaunched',
110+
status: 'active',
109111
nodes: [
110112
{
111113
id: 'start',
@@ -160,6 +162,7 @@ export const BudgetApprovalFlow = defineFlow({
160162
label: 'Project Budget Approval',
161163
description: 'Two-step approval for projects above budget thresholds.',
162164
type: 'autolaunched',
165+
status: 'active',
163166
nodes: [
164167
{
165168
id: 'start',
@@ -257,6 +260,7 @@ export const TaskCompletedSlackFlow = defineFlow({
257260
label: 'Post to Slack on Task Completed',
258261
description: 'Posts to a Slack channel via the slack connector when a task is marked Done.',
259262
type: 'autolaunched',
263+
status: 'active',
260264
nodes: [
261265
{
262266
id: 'start',
@@ -307,6 +311,7 @@ export const ScheduledDigestFlow = defineFlow({
307311
label: 'Scheduled Project Digest (interval)',
308312
description: 'Fires on a fixed interval and posts a digest to an inbox — demonstrates the schedule trigger.',
309313
type: 'schedule',
314+
status: 'active',
310315
nodes: [
311316
{
312317
id: 'start',
@@ -362,6 +367,7 @@ export const TaskCompletedRestPingFlow = defineFlow({
362367
label: 'REST Ping on Task Completed',
363368
description: 'Calls the local server health endpoint via the rest connector when a task is marked Done.',
364369
type: 'autolaunched',
370+
status: 'active',
365371
nodes: [
366372
{
367373
id: 'start',
@@ -414,6 +420,7 @@ export const ShowcaseDeclarativeConnectorPingFlow = defineFlow({
414420
description:
415421
'Dispatches GET /api/v1/health through showcase_status_api — a provider-bound connector instance materialized from pure metadata at boot.',
416422
type: 'autolaunched',
423+
status: 'active',
417424
nodes: [
418425
{
419426
id: 'start',
@@ -463,6 +470,7 @@ export const ShowcaseMcpConnectorEchoFlow = defineFlow({
463470
'Dispatches the echo_upper tool of showcase_mcp_tools — a declarative MCP connector instance materialized ' +
464471
'at boot from the in-repo stdio fixture (scripts/mcp-fixture.mjs).',
465472
type: 'autolaunched',
473+
status: 'active',
466474
// Surface the tool result on the run output, so the flow run view (and the
467475
// dogfood proof) can assert the MCP round-trip observably.
468476
variables: [{ name: 'echo.structuredContent', type: 'json', isOutput: true }],
@@ -514,6 +522,7 @@ export const TaskFollowUpFlow = defineFlow({
514522
label: 'Task Follow-up Reminder (wait)',
515523
description: 'Waits a fixed delay after a task is created, then reminds the assignee — demonstrates the durable wait node.',
516524
type: 'autolaunched',
525+
status: 'active',
517526
nodes: [
518527
{
519528
id: 'start',
@@ -604,6 +613,7 @@ export const TaskDoneNotifyOwnerFlow = defineFlow({
604613
label: 'Task Done → Notify Owner (subflow)',
605614
description: 'On task completion, invokes the reusable notify-owner subflow — demonstrates subflow reuse.',
606615
type: 'autolaunched',
616+
status: 'active',
607617
nodes: [
608618
{
609619
id: 'start',
@@ -713,6 +723,7 @@ export const ProjectClosureFlow = defineFlow({
713723
label: 'Project Closure with Sign-off (nested pause)',
714724
description: 'On project completion, requests sign-off via an approval-inside-subflow, then notifies the owner — demonstrates nested durable pause.',
715725
type: 'autolaunched',
726+
status: 'active',
716727
nodes: [
717728
{
718729
id: 'start',
@@ -830,6 +841,7 @@ export const FanOutNotifyFlow = defineFlow({
830841
label: 'Fan-out Notify (Parallel)',
831842
description: 'Notifies owner and watchers concurrently via a parallel block, joining before completion (ADR-0031).',
832843
type: 'autolaunched',
844+
status: 'active',
833845
nodes: [
834846
{
835847
id: 'start',
@@ -902,6 +914,7 @@ export const ResilientSyncFlow = defineFlow({
902914
label: 'Resilient Sync (Try/Catch/Retry)',
903915
description: 'Pushes a task to an external system, retrying on failure and recording errors via try/catch (ADR-0031).',
904916
type: 'autolaunched',
917+
status: 'active',
905918
nodes: [
906919
{
907920
id: 'start',
@@ -983,6 +996,7 @@ export const InvoiceDualSignoffFlow = defineFlow({
983996
label: 'Invoice Dual Sign-off (parallel approval)',
984997
description: 'On send, requires finance AND legal to both approve via one aggregating approval node — demonstrates parallel approvals without a token tree (ADR-0039 Track A).',
985998
type: 'autolaunched',
999+
status: 'active',
9861000
// The revert-on-reject write is an approval-process outcome, not an act of the
9871001
// submitter — run it as the system principal so it lands regardless of whether
9881002
// the submitter still has edit rights on a "sent" invoice (#1888 runAs enforced).
@@ -1070,6 +1084,7 @@ export const ProjectEscalationFlow = defineFlow({
10701084
label: 'Project Escalation (composite)',
10711085
description: 'On health → red, branches on severity then alerts in parallel and pushes to an incident system with try/catch — demonstrates nested construct composition.',
10721086
type: 'autolaunched',
1087+
status: 'active',
10731088
nodes: [
10741089
{
10751090
id: 'start',
@@ -1264,6 +1279,7 @@ export const InboundTaskWebhookFlow = defineFlow({
12641279
label: 'Inbound Task Webhook',
12651280
description: 'Creates a task from an external system via the HMAC-verified inbound hook.',
12661281
type: 'api',
1282+
status: 'active',
12671283
// An inbound webhook has no authenticated user, so the create must run as the
12681284
// system principal (#1888 runAs is now enforced). Without this it relies on the
12691285
// "no identity → security-skipped" fall-through, which breaks the moment the
Lines changed: 100 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,100 @@
1+
// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license.
2+
//
3+
// Startup-banner automation summary (2026-07-17 third-party eval).
4+
//
5+
// Flow registration and trigger binding happen entirely inside serve's
6+
// boot-quiet stdout window, so the automation engine's own logs never reach
7+
// the terminal — a project whose flows silently failed to arm looked exactly
8+
// like one whose flows armed fine. `collectAutomationSummary` gathers the
9+
// live binding facts after stdout is restored so the banner can answer
10+
// "did my flows actually arm?" — including the three silent author mistakes:
11+
// engine not enabled, trigger not registered, and objectName mismatch.
12+
13+
import { describe, it, expect } from 'vitest';
14+
import { collectAutomationSummary } from './serve.js';
15+
16+
type FlowState = {
17+
name: string;
18+
enabled: boolean;
19+
bound: boolean;
20+
status?: string;
21+
triggerType?: string;
22+
object?: string;
23+
};
24+
25+
function fakeKernel(services: Record<string, unknown>) {
26+
return {
27+
getService(name: string) {
28+
if (!(name in services)) throw new Error(`Service '${name}' not found`);
29+
return services[name];
30+
},
31+
};
32+
}
33+
34+
function fakeAutomation(states: FlowState[], triggerTypes: string[] = ['record_change']) {
35+
return {
36+
getFlowRuntimeStates: () => states,
37+
getRegisteredTriggerTypes: () => triggerTypes,
38+
getTriggerBindingAudit: () =>
39+
states
40+
.filter((s) => s.enabled && !s.bound && s.triggerType)
41+
.map((s) => ({
42+
flowName: s.name,
43+
triggerType: s.triggerType!,
44+
reason: `no '${s.triggerType}' trigger is registered`,
45+
})),
46+
};
47+
}
48+
49+
describe('collectAutomationSummary', () => {
50+
it('flags declared flows when the automation engine is not enabled at all', () => {
51+
const summary = collectAutomationSummary(fakeKernel({}), 2);
52+
expect(summary).toMatchObject({ enabled: false, declaredFlowCount: 2 });
53+
});
54+
55+
it('returns undefined when there is nothing automation-related to show', () => {
56+
expect(collectAutomationSummary(fakeKernel({}), 0)).toBeUndefined();
57+
});
58+
59+
it('reports bound/unbound counts and surfaces the unbound audit', () => {
60+
const automation = fakeAutomation([
61+
{ name: 'wired', enabled: true, bound: true, status: 'active', triggerType: 'record_change', object: 'task' },
62+
{ name: 'orphan', enabled: true, bound: false, status: 'active', triggerType: 'record_change', object: 'task' },
63+
]);
64+
const summary = collectAutomationSummary(fakeKernel({ automation }), 2)!;
65+
expect(summary.enabled).toBe(true);
66+
expect(summary.flowCount).toBe(2);
67+
expect(summary.boundCount).toBe(1);
68+
expect(summary.unbound).toHaveLength(1);
69+
expect(summary.unbound[0].flowName).toBe('orphan');
70+
});
71+
72+
it('flags a bound record-change flow whose target object is unknown (dead binding)', () => {
73+
const automation = fakeAutomation([
74+
{ name: 'dead', enabled: true, bound: true, status: 'active', triggerType: 'record_change', object: 'candidate' },
75+
{ name: 'alive', enabled: true, bound: true, status: 'active', triggerType: 'record_change', object: 'eval_app_candidate' },
76+
]);
77+
const ql = { getObject: (n: string) => (n === 'eval_app_candidate' ? { name: n } : undefined) };
78+
const summary = collectAutomationSummary(fakeKernel({ automation, objectql: ql }), 2)!;
79+
expect(summary.unknownObject).toEqual([{ flowName: 'dead', object: 'candidate' }]);
80+
});
81+
82+
it('counts enabled draft flows (draft still fires — make it visible)', () => {
83+
const automation = fakeAutomation([
84+
{ name: 'd1', enabled: true, bound: true, status: 'draft', triggerType: 'record_change', object: 'task' },
85+
{ name: 'implicit', enabled: true, bound: true, status: undefined, triggerType: 'record_change', object: 'task' },
86+
{ name: 'a1', enabled: true, bound: true, status: 'active', triggerType: 'record_change', object: 'task' },
87+
]);
88+
const summary = collectAutomationSummary(fakeKernel({ automation }), 3)!;
89+
expect(summary.draftCount).toBe(2);
90+
});
91+
92+
it('degrades gracefully on an older engine without the audit APIs', () => {
93+
const automation = { getFlowRuntimeStates: () => [{ name: 'x', enabled: true, bound: true }] };
94+
const summary = collectAutomationSummary(fakeKernel({ automation }), 1)!;
95+
expect(summary.enabled).toBe(true);
96+
expect(summary.flowCount).toBe(1);
97+
expect(summary.unbound).toEqual([]);
98+
expect(summary.triggerTypes).toEqual([]);
99+
});
100+
});

packages/cli/src/commands/serve.ts

Lines changed: 81 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -19,6 +19,7 @@ import {
1919
printStep,
2020
printInfo,
2121
printServerReady,
22+
type AutomationReadySummary,
2223
} from '../utils/format.js';
2324
import {
2425
CONSOLE_PATH,
@@ -2296,6 +2297,17 @@ export default class Serve extends Command {
22962297
if (authSvc?.devSeedResult?.email) seededAdmin = authSvc.devSeedResult;
22972298
} catch { /* auth service not present — nothing to show */ }
22982299

2300+
// ── Automation wiring summary (2026-07-17 third-party eval) ─────
2301+
// Flow registration + trigger binding happen entirely inside the
2302+
// boot-quiet stdout window above, so the engine's own info/warn logs
2303+
// never reach the terminal. Collect the live binding state here (after
2304+
// restore) and surface it in the banner: declared-but-engine-missing,
2305+
// unbound triggered flows, and bound-but-dead (unknown object) flows.
2306+
const automationSummary = collectAutomationSummary(
2307+
kernel,
2308+
Array.isArray((config as any)?.flows) ? (config as any).flows.length : 0,
2309+
);
2310+
22992311
// ── Clean startup summary ──────────────────────────────────────
23002312
printServerReady({
23012313
port,
@@ -2309,6 +2321,7 @@ export default class Serve extends Command {
23092321
databaseUrl: redactDbUrl(resolvedDatabaseUrl),
23102322
multiTenant: resolveMultiOrgEnabled(),
23112323
seededAdmin,
2324+
automation: automationSummary,
23122325
});
23132326

23142327
// ── Publish the actually-bound port ────────────────────────────
@@ -2408,3 +2421,71 @@ function describeRegisteredDriver(kernel: any): { label: string; url: string } |
24082421
}
24092422
return null;
24102423
}
2424+
2425+
/**
2426+
* Collect the automation wiring facts for the startup banner (2026-07-17
2427+
* third-party eval: flow registration/binding logs fall inside the boot-quiet
2428+
* stdout window, so the banner is the one channel a developer reliably sees).
2429+
*
2430+
* Every probe is feature-detected so an older `@objectstack/service-automation`
2431+
* (without `getTriggerBindingAudit` / extended runtime states) degrades to the
2432+
* plain count line instead of crashing the banner. Returns `undefined` when
2433+
* there is nothing automation-related to show at all.
2434+
*/
2435+
export function collectAutomationSummary(
2436+
kernel: any,
2437+
declaredFlowCount: number,
2438+
): AutomationReadySummary | undefined {
2439+
let automation: any;
2440+
try { automation = kernel?.getService?.('automation'); } catch { /* not registered */ }
2441+
2442+
if (!automation) {
2443+
return declaredFlowCount > 0
2444+
? {
2445+
enabled: false,
2446+
declaredFlowCount,
2447+
flowCount: 0,
2448+
boundCount: 0,
2449+
triggerTypes: [],
2450+
unbound: [],
2451+
unknownObject: [],
2452+
draftCount: 0,
2453+
}
2454+
: undefined;
2455+
}
2456+
2457+
let states: Array<{ name: string; enabled: boolean; bound: boolean; status?: string; triggerType?: string; object?: string }> = [];
2458+
try { states = automation.getFlowRuntimeStates?.() ?? []; } catch { /* older engine */ }
2459+
if (states.length === 0 && declaredFlowCount === 0) return undefined;
2460+
2461+
let triggerTypes: string[] = [];
2462+
try { triggerTypes = automation.getRegisteredTriggerTypes?.() ?? []; } catch { /* older engine */ }
2463+
2464+
let unbound: Array<{ flowName: string; triggerType: string; reason: string }> = [];
2465+
try { unbound = automation.getTriggerBindingAudit?.() ?? []; } catch { /* older engine */ }
2466+
2467+
// Dead bindings: a bound record-change flow whose target object nobody
2468+
// registered — the hook is filtered to a name that never writes.
2469+
const unknownObject: Array<{ flowName: string; object: string }> = [];
2470+
let ql: any;
2471+
try { ql = kernel?.getService?.('objectql'); } catch { /* absent */ }
2472+
if (ql && typeof ql.getObject === 'function') {
2473+
for (const s of states) {
2474+
if (!s.bound || !s.object || s.triggerType !== 'record_change') continue;
2475+
let known: unknown;
2476+
try { known = ql.getObject(s.object); } catch { known = undefined; }
2477+
if (!known) unknownObject.push({ flowName: s.name, object: s.object });
2478+
}
2479+
}
2480+
2481+
return {
2482+
enabled: true,
2483+
declaredFlowCount,
2484+
flowCount: states.length,
2485+
boundCount: states.filter((s) => s.bound).length,
2486+
triggerTypes,
2487+
unbound,
2488+
unknownObject,
2489+
draftCount: states.filter((s) => s.enabled && (s.status ?? 'draft') === 'draft').length,
2490+
};
2491+
}

packages/cli/src/commands/validate.ts

Lines changed: 18 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -17,6 +17,7 @@ import { validateJsxPages, validateReactPages, validateReactPageProps, validateP
1717
import { validateCapabilityReferences } from '@objectstack/lint';
1818
import { validateVisibilityPredicates } from '@objectstack/lint';
1919
import { validateSecurityPosture } from '@objectstack/lint';
20+
import { validateFlowTriggerReadiness } from '@objectstack/lint';
2021
import {
2122
printHeader,
2223
printKV,
@@ -371,6 +372,22 @@ export default class Validate extends Command {
371372
}
372373
}
373374

375+
// 3g. Auto-launched flow trigger wiring (2026-07-17 third-party eval):
376+
// a record-change flow whose start-node objectName matches nothing
377+
// never fires — silently. Also nudges auto-triggered flows to declare
378+
// an explicit deployment status (the schema default is 'draft', and
379+
// draft flows DO still fire — ambiguous intent). Advisory: objects
380+
// may come from other installed packages.
381+
if (!flags.json) printStep('Checking flow trigger wiring...');
382+
const flowReadinessFindings = validateFlowTriggerReadiness(normalized as Record<string, unknown>);
383+
const flowReadinessWarnings = flowReadinessFindings.filter((f) => f.severity === 'warning');
384+
if (!flags.json) {
385+
for (const w of flowReadinessWarnings.slice(0, 50)) {
386+
console.log(chalk.yellow(` ⚠ ${w.where}: ${w.message}`));
387+
console.log(chalk.dim(` ${w.hint}`));
388+
}
389+
}
390+
374391
// 3f. [ADR-0090 D7] Security posture — the same gate `os compile`/`os build`
375392
// run. Without it here, `os validate` passed a stack (e.g. a custom
376393
// object with no explicit sharingModel) that the build then rejected,
@@ -417,7 +434,7 @@ export default class Validate extends Command {
417434
valid: true,
418435
manifest: config.manifest,
419436
stats,
420-
warnings: [...exprWarnings, ...widgetWarnings, ...styleWarnings, ...jsxWarnings, ...capWarnings, ...securityAdvisories],
437+
warnings: [...exprWarnings, ...widgetWarnings, ...styleWarnings, ...jsxWarnings, ...capWarnings, ...flowReadinessWarnings, ...securityAdvisories],
421438
conversions: conversionNotices,
422439
specVersionGap: specGap,
423440
duration: timer.elapsed(),

0 commit comments

Comments
 (0)