Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
54 changes: 54 additions & 0 deletions .changeset/durability-degradation-log-level.md
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,54 @@
---
"@objectstack/objectql": patch
"@objectstack/service-automation": patch
---

fix(convention): a best-effort degradation that costs DURABILITY logs `error`, not `warn` — and a gate that enforces it (#4632)

#4420: the durable suspended-run store attached to a table that was never
created. Every write failed into a `warn` nobody read, every restart dropped all
in-flight approvals, and the process reported perfect health the entire time —
the symptom surfaced a release after the cause. #4460 raised that **one** site to
`error`. This makes it the rule, because the *class* is what recurs.

**The rule** (AGENTS.md → "Degradation log levels") is a question, not an
adjective, so an agent can apply it while writing the `catch`:

> After the degradation, does the system still look "normal" from the outside,
> while something it claims is persisted has not actually landed?
> Yes → `error`. No → `warn`/`info` is right.

An `error` here owes two things in its first line: the **consequence** (what is
not durable, and that the system will keep looking healthy anyway) and the
**fix** (the composition change that restores durability, or the explicit opt-out
that makes the degradation deliberate). Say it once, not once per failed write.

**Sites raised to `error`** — each was reviewed individually; escalating a
functional degradation is the mirror-image failure and was deliberately avoided:

| Where | What was silently lost |
|:---|:---|
| `objectql` schema sync, per object | DDL never ran — the object stays registered, routed and rendered while its table/columns do not exist |
| `objectql` schema sync, summary | `info: Schema sync complete` printed over a pass with failures; now an `error` naming the count |
| `objectql` reload-time schema sync | a Studio edit adds a field, the UI shows it, the API accepts it, the column was never created |
| `ObjectQL.syncSchemas()` | an **empty** `catch` — marketplace install and template seeding wrote into tables this failure means do not exist, then reported success |
| `service-automation` wait-timer re-arm (4 paths) | runs stay persisted but nothing re-arms them: every approval paused before the restart hangs forever |

**Deliberately left at `warn`** — the rule cuts both ways, and over-applying it
trains everyone to skim `error`: the batch→sequential schema-sync fallback (it
*recovers*), and "no job service is registered" on the re-arm path (a declared
absence in a host that never composed auto-resume — nothing was promised and
then broken).

**It has teeth.** A convention that lives only in AGENTS.md is the same
"declared ≠ enforced" shape this repo keeps paying to fix, so
`pnpm check:durability-log-level` walks the AST for `catch` blocks guarding a
declared vocabulary of durability-critical operations and fails when one
degrades below `error` without rethrowing. It follows same-file helpers (so
extracting a reporter cannot quietly defeat it) and ships its own `--self-test`.
Deliberately narrow: it cannot *discover* a new durability seam, only stop known
ones from regressing — extend `DURABILITY_CRITICAL_CALLEES` in the same PR that
fixes a new one.

No API, schema or behaviour changes — only the level, and the text, of what
already-failing paths report.
16 changes: 16 additions & 0 deletions .github/workflows/lint.yml
Original file line numberDiff line numberDiff line change
Expand Up@@ -188,6 +188,22 @@ jobs:
- name: Init-service declaration guard
run: pnpm check:init-service-contract

# Durability-degradation log-level guard (#4632). #4460 raised ONE
# best-effort degradation from warn to error — the durable suspended-run
# store writing to a table that never existed (#4420), which looked healthy
# while every restart dropped all in-flight approvals. The rule that fix
# implied now lives in AGENTS.md ("Degradation log levels"): a degradation
# that costs only FUNCTIONALITY may warn; one that costs DURABILITY must
# error, naming the consequence and the fix. This gate is what keeps that
# from being one more declared-but-unenforced convention — it walks the AST
# for catch blocks guarding a declared vocabulary of durability-critical
# operations (schema DDL, suspended-run re-arm) and fails when one degrades
# below `error` without rethrowing. Deliberately narrow: it cannot discover
# a new durability seam, only stop known ones from regressing. Runs its own
# --self-test first.
- name: Durability-degradation log-level guard
run: pnpm check:durability-log-level

# Release-notes drift guard: the platform is one version-locked train, so
# every released @objectstack/spec major must have a curated, navigable
# release page at content/docs/releases/v<major>.mdx. Catches the gap that
Expand Down
63 changes: 63 additions & 0 deletions AGENTS.md
Original file line numberDiff line numberDiff line change
Expand Up@@ -538,6 +538,69 @@ composition with its real services, or do not claim an answer.

---

## Degradation log levels — `warn` vs `error`

Nearly every `catch` in this repo is a best-effort degradation, and nearly every
one of them logs `warn`. That default is wrong for a specific, recurring class,
and the cost of getting it wrong is not noise — it is silent data loss. Decide
the level with **one question**, not with an adjective:

> **After the degradation, does the system still look "normal" from the outside,
> while something it claims is persisted has not actually landed?**
> **Yes → `error`. No → `warn`/`info` is right.**

- **Functional degradation → `warn` / `info`.** A screen is missing, a trigger is
not armed, a capability is not enabled, an optional service never showed up.
The system is *visibly* smaller than it should be, and the next person to use
the missing thing finds out. `ScheduleTriggerPlugin: job service not available
— scheduled flows will not run until one is registered` is exactly right at
`warn`.
- **Durability / data-consistency degradation → `error`.** A write that claims
to persist does not, DDL that was supposed to run did not, persisted state and
runtime state disagree. Nothing looks broken; the loss surfaces a release
later, to someone who cannot connect it to this line.

**Why this is a rule and not a preference.** #4420: the durable suspended-run
store attached to a table that was never created, every write failed into a
`warn` nobody read, and every restart dropped all in-flight approvals — the
symptom surfaced a release after the cause. #4460 raised that one site to
`error`; #4632 made it the rule, because the *class* is what recurs. It is the
same failure Prime Directive #10 names — advertising a capability (here:
durability) the runtime does not deliver — and the same instinct as "Absence must
be loud" above: **prefer failing to falling back**, and when you must fall back,
say what was lost.

**An `error` here owes two things**, both, in the first line it prints
(`packages/services/service-automation/src/plugin.ts` `start()` is the reference
text):

1. the **consequence**, concretely — *what* is not durable, and that the system
will keep looking healthy anyway;
2. the **fix** — the composition/config change that restores durability, or the
explicit opt-out that makes the degradation deliberate (`suspendedRunStore:
'memory'`, `OS_SKIP_SCHEMA_SYNC`).

Say it **once**, at the first degradation, not once per failed write.

**Do not over-apply it.** Escalating a functional degradation to `error` is the
mirror-image failure: it trains everyone to skim `error`, which is what made the
#4420 `warn` unreadable in the first place. In particular, an `if (!service)`
composition branch is usually functional and usually belongs at `warn`; a `catch`
around a write, a DDL call, or a store initialization is where this rule bites.

**It has teeth** (a rule this repo only writes down is the very "declared ≠
enforced" shape it keeps paying to fix): `pnpm check:durability-log-level` walks
the AST for `catch` blocks guarding a declared vocabulary of durability-critical
operations and fails when one logs below `error` without rethrowing. It is
deliberately narrow — it cannot *discover* a new durability seam, only stop the
known ones from regressing. Found a new one? Add it to
`DURABILITY_CRITICAL_CALLEES` in `scripts/check-durability-degradation-log-level.mjs`
in the same PR that fixes it. Accepted exceptions live in
`scripts/durability-degradation.baseline.json`, hand-edited with a reason and
shrink-only.

---

## Post-Task Checklist

1. `pnpm test` — verify nothing broke. Touched a type-check-covered package? `pnpm typecheck` too.
Expand Down
1 change: 1 addition & 0 deletions package.json
Original file line numberDiff line numberDiff line change
Expand Up@@ -44,6 +44,7 @@
"check:error-code-casing": "node scripts/check-error-code-casing.mjs --self-test && node scripts/check-error-code-casing.mjs",
"check:wildcard-fallthrough": "node scripts/check-wildcard-fallthrough.mjs --self-test && node scripts/check-wildcard-fallthrough.mjs",
"check:init-service-contract": "node scripts/check-init-service-contract.mjs --self-test && node scripts/check-init-service-contract.mjs",
"check:durability-log-level": "node scripts/check-durability-degradation-log-level.mjs --self-test && node scripts/check-durability-degradation-log-level.mjs",
"check:console-sha": "node scripts/check-console-sha.mjs",
"check:release-notes": "node scripts/check-release-notes.mjs",
"check:node-version": "node scripts/check-node-version.mjs",
Expand Down
20 changes: 18 additions & 2 deletions packages/objectql/src/engine.ts
Original file line numberDiff line numberDiff line change
Expand Up@@ -5337,8 +5337,24 @@ export class ObjectQL implements IObjectQLEngine {
if (typeof (driver as any).syncSchema === 'function') {
try {
await (driver as any).syncSchema(tableName, obj);
} catch {
// best effort — log suppressed to avoid noise on already-synced tables
} catch (e: unknown) {
// #4632 — this catch used to be empty, with the comment "log
// suppressed to avoid noise on already-synced tables". Suppressing an
// already-synced no-op is not what it did: `syncSchema` is required to
// be idempotent (see this method's doc comment), so a driver that
// reaches this catch did NOT sync. The only callers are runtime
// installs — marketplace plugin install, template seeding — which go
// on to INSERT into a table this failure means does not exist, and
// then report the install as successful. Nothing that claims to be
// persisted afterwards is.
this.logger.error(
`Schema sync FAILED for object '${obj.name}' — its table/collection was NOT created or altered, yet the object is ` +
`registered and will be written to: those writes will fail, or drop the columns that were never created. ` +
`Any seeding or install step that continues past this point is not durable. ` +
`Fix the driver error below, then re-run the install/sync.`,
e as Error,
{ object: obj.name, tableName, driver: (driver as any)?.name },
);
}
}
}
Expand Down
83 changes: 66 additions & 17 deletions packages/objectql/src/plugin.ts
Original file line numberDiff line numberDiff line change
Expand Up@@ -402,9 +402,19 @@ export class ObjectQLPlugin implements Plugin {
try {
await this.syncRegisteredSchemas(ctx);
} catch (e: any) {
ctx.logger.warn('[ObjectQLPlugin] reload-time schema sync failed', {
error: e?.message ?? String(e),
});
// #4632 — durability degradation, not a functional one. A
// Studio edit that adds a field lands in metadata (the UI
// shows it, the API accepts it, the author sees a saved
// record) while the column it needs was never created. The
// author is told the value was saved and it was not.
// `Logger.error` is `(message, error?, meta?)` — the second
// slot is the Error, NOT the context bag `warn` takes there.
ctx.logger.error(
'[ObjectQLPlugin] reload-time schema sync FAILED — objects changed by this metadata reload are live in the ' +
'registry, UI and API, but their new/altered columns were NOT created: writes against them are accepted and ' +
'then silently lost or rejected. Fix the driver error below and reload again (or restart) to re-run DDL.',
e instanceof Error ? e : new Error(String(e?.message ?? e)),
);
}
});
await this.reloadSchemaSync;
Expand DownExpand Up@@ -910,6 +920,42 @@ export class ObjectQLPlugin implements Plugin {

let synced = 0;
let skipped = 0;
let failed = 0;

/**
* #4632 — a failed schema sync is a DURABILITY degradation, not a
* functional one, so it is reported at `error`.
*
* The object stays in the registry, keeps its REST routes, keeps rendering
* in the UI — the system looks completely healthy — while its table or its
* newly-declared columns were never created. Writes then fail, or (on
* drivers that accept unknown attributes) succeed while silently dropping
* the un-created column: the thing the system claims it persisted is not
* on disk. That is exactly the #4420 shape one layer up from the durable
* suspended-run store #4460 fixed, so it carries the same obligation —
* name the CONSEQUENCE and the FIX at the first failure.
*/
const reportSyncFailure = (
obj: any,
tableName: string,
driverName: string,
err: unknown,
): void => {
failed++;
// NB `Logger.error` is `(message, error?, meta?)` — the Error goes in the
// SECOND slot, unlike `warn`'s `(message, meta?)`. This call was written
// as a mechanical warn→error swap and the mismatch only surfaced in the
// DTS build, never in a test run.
ctx.logger.error(
`Schema sync FAILED for object '${obj?.name}' — its table/columns were NOT created or altered, but the object stays ` +
`registered and served: writes to it will fail, or silently drop the columns that were never created. ` +
`Nothing that claims to be persisted for this object is guaranteed to be on disk. ` +
`Fix the driver/datasource error below and restart (or trigger a metadata reload) to re-run DDL; ` +
`if this deployment manages DDL out-of-band, set \`skipSchemaSync\` / OS_SKIP_SCHEMA_SYNC so the omission is deliberate.`,
err instanceof Error ? err : new Error(String(err)),
{ object: obj?.name, tableName, driver: driverName },
);
};

// Group objects by driver for potential batch optimization
const driverGroups = new Map<any, Array<{ obj: any; tableName: string }>>();
Expand DownExpand Up@@ -993,18 +1039,15 @@ export class ObjectQLPlugin implements Plugin {
driver: driver.name,
error: e instanceof Error ? e.message : String(e),
});
// Fallback: sequential sync for this driver's objects
// Fallback: sequential sync for this driver's objects. The batch
// warn above is correct at `warn` — it RECOVERS here; only a
// sequential failure actually loses the DDL.
for (const { obj, tableName } of entries) {
try {
await driver.syncSchema(tableName, obj);
synced++;
} catch (seqErr: unknown) {
ctx.logger.warn('Failed to sync schema for object', {
object: obj.name,
tableName,
driver: driver.name,
error: seqErr instanceof Error ? seqErr.message : String(seqErr),
});
reportSyncFailure(obj, tableName, driver.name, seqErr);
}
}
}
Expand All@@ -1015,18 +1058,24 @@ export class ObjectQLPlugin implements Plugin {
await driver.syncSchema(tableName, obj);
synced++;
} catch (e: unknown) {
ctx.logger.warn('Failed to sync schema for object', {
object: obj.name,
tableName,
driver: driver.name,
error: e instanceof Error ? e.message : String(e),
});
reportSyncFailure(obj, tableName, driver.name, e);
}
}
}
}

if (synced > 0 || skipped > 0) {
// #4632 — never claim "complete" over a pass that lost DDL. The old line
// logged `info: Schema sync complete` after any number of failures, which
// is the "looks normal" half of the accident: the only honest summary of a
// pass with failures is an error.
if (failed > 0) {
ctx.logger.error(
`Schema sync finished with ${failed} FAILED object(s) — those objects are registered and served but their storage was ` +
`never created or altered; writes to them are not durable. See the per-object errors above for the driver failure and the fix.`,
undefined,
{ synced, skipped, failed, total: allObjects.length },
);
} else if (synced > 0 || skipped > 0) {
ctx.logger.info('Schema sync complete', { synced, skipped, total: allObjects.length });
}
}
Expand Down
Loading
Loading