Skip to content

Commit c5a5996

Browse files
xuyushun441-sysClaudeclaude
authored
fix(seed-loader): a roll-up summary left stale by a seed is loud and counted (#4998) (#5062)
The ERR_SUMMARY_RECOMPUTE recovery is unchanged (framework#3147: the rows WERE written, re-writing them would duplicate). What changes is the rank of the consequence and its detectability. - `error`, not `warn` (#4632): a roll-up summary is a persisted DERIVED column, so exhausting its recompute retries leaves the detail rows and the column summarizing them disagreeing in the database, with nothing to self-heal it. The line names the seeded object and the stale column, states the consequence (including that the seed still reports success) and the remedy, and carries the original cause. - Counted: `SeedLoadResult.summariesStale` / `summary.totalSummariesStale`, mirroring `referencesDropped` / `totalReferencesDropped`. `success` stays `true` — it answers "did the rows land", and they did. - The guarded write is extracted as `performSeedWrite` and registered in `DURABILITY_CRITICAL_CALLEES`, and the gate no longer excuses a catch that rethrows on one branch while recovering on another — without that, the ledger entry could never have fired. Claude-Session: https://claude.ai/code/session_01NrmBxj8rK2uGCnh9aipjwX Co-authored-by: Claude <sales@objectstack.ai> Co-authored-by: Claude Fable 5 <noreply@anthropic.com>
1 parent da1a64c commit c5a5996

9 files changed

Lines changed: 676 additions & 34 deletions

File tree

Lines changed: 20 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,20 @@
1+
---
2+
---
3+
4+
chore(scripts): the durability log-level gate no longer excuses a catch that only PARTIALLY rethrows
5+
6+
`check:durability-log-level` skipped any guarded `catch` containing a `throw`.
7+
That is right when the catch propagates on every path — the failure reaches the
8+
caller and nothing is being degraded. It is wrong for a catch that **recovers on
9+
one branch and rethrows on the other**: the rethrow says nothing about the
10+
branch that returns a substitute value, and that branch is a degradation like
11+
any other.
12+
13+
Found while closing
14+
[#4998](https://github.com/objectstack-ai/objectstack/issues/4998), whose seam
15+
(`writeRecoveringSummary`: recover `ERR_SUMMARY_RECOMPUTE`, rethrow everything
16+
else) has exactly that shape. Registering its callee in
17+
`DURABILITY_CRITICAL_CALLEES` produced a ledger entry that could never fire —
18+
protection that reads as real and enforces nothing, which is worse than none.
19+
Measured against the repo, the tightened rule changes the verdict on no existing
20+
seam (11 seams, all still loud or rethrowing) and needs no baseline entry.
Lines changed: 46 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,46 @@
1+
---
2+
"@objectstack/spec": minor
3+
"@objectstack/metadata-protocol": patch
4+
---
5+
6+
fix(seed-loader): a roll-up summary left stale by a seed is now loud and counted
7+
8+
The loader recovers a post-write roll-up summary recompute that exhausts its
9+
retries (`ERR_SUMMARY_RECOMPUTE`), and that recovery is correct: the rows WERE
10+
written, so re-writing them would duplicate them (framework#3147). What was
11+
wrong was the rank of the consequence. A roll-up summary is a **persisted
12+
derived column** on the parent record, so after this the database is internally
13+
inconsistent — the detail rows say one thing and the column that summarizes them
14+
says another — and nothing recomputes it until some later write happens to touch
15+
the same parent, which after a seed may never happen.
16+
17+
The entire event used to be one `warn` line reading *"records were written
18+
(summary values may be stale)"*. It named no object, counted nothing, and left
19+
`success: true` with every row counter clean, so no operator could see which
20+
aggregate was wrong and no caller could detect it at all
21+
([#4998](https://github.com/objectstack-ai/objectstack/issues/4998)).
22+
23+
**It now logs at `error`**, naming the seeded object and the exact stale column
24+
(`account.total_billed`), stating the consequence (the summary and its detail
25+
rows disagree, nothing self-heals, and the seed still reports success) and the
26+
remedy (fix the recompute error and re-run the seed, or trigger any write on the
27+
affected parent to force a recompute), with the original cause attached. This is
28+
the AGENTS.md "Degradation log levels" rule (#4632): persisted state and runtime
29+
state disagreeing while everything looks normal is `error`, not `warn`.
30+
31+
**And it is counted**`SeedLoadResult.summariesStale` and
32+
`SeedLoaderResult.summary.totalSummariesStale`, mirroring `referencesDropped` /
33+
`totalReferencesDropped`, which exists for the same shape one layer down ("the
34+
row was written, something derived from it was lost"). A log line is not
35+
something a caller can branch on; these counters are.
36+
37+
`success` deliberately stays `true`. It answers *"did the rows land"*, and they
38+
did — every consumer treats `success: false` as "the write failed", so flipping
39+
it would hand the protocol seed-apply surface a `false` with an **empty** errors
40+
array and fail package/marketplace installs that in fact wrote every row. The
41+
counter carries the signal instead; a caller that wants to treat a stale
42+
aggregate as fatal reads `summary.totalSummariesStale > 0`.
43+
44+
Both counters are additive with a `0` default, so an existing producer or
45+
consumer of `SeedLoaderResult` is unaffected — a payload written before this
46+
release still parses, with `0`.

content/docs/references/data/seed-loader.mdx

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -151,6 +151,7 @@ Result of loading a single dataset
151151
| **referencesResolved** | `integer` || References resolved via externalId |
152152
| **referencesDeferred** | `integer` || References deferred to second pass |
153153
| **referencesDropped** | `integer` || Reference fields dropped from records that were still written |
154+
| **summariesStale** | `integer` || Roll-up summary values left stale by writes for this dataset |
154155
| **errors** | `{ sourceObject: string; field: string; targetObject: string; targetField: string; … }[]` || Reference resolution errors |
155156

156157

packages/metadata-protocol/src/seed-loader-retry.test.ts

Lines changed: 7 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -229,7 +229,13 @@ describe('seed batched path — partial-success engine (framework#3172)', () =>
229229
});
230230
});
231231

232-
describe('seed batched path — summary recompute failure is a warning, not an error (framework#3147)', () => {
232+
// The RECOVERY pinned here is framework#3147's and is unchanged: the rows were
233+
// written, so re-writing them would duplicate. Its loudness is not — a stale
234+
// roll-up column is persisted data disagreeing with its detail rows, so the
235+
// seam logs at `error` and counts into `summariesStale` (framework#4998, pinned
236+
// in seed-loader-summary-stale.test.ts). It is still not a WRITE error, which
237+
// is what `totalErrored: 0` below says.
238+
describe('seed batched path — a recompute failure is recovered, not re-written (framework#3147)', () => {
233239
it('records the rows as inserted (not errored) and does not re-insert on ERR_SUMMARY_RECOMPUTE', async () => {
234240
const { engine, store } = createFaithfulEngine();
235241
const metadata = createMetadata();
Lines changed: 304 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,304 @@
1+
// Copyright (c) 2025 ObjectStack. Licensed under the Apache-2.0 license.
2+
3+
import { describe, it, expect, vi } from 'vitest';
4+
import { SeedLoadResultSchema, SeedLoaderResultSchema } from '@objectstack/spec/data';
5+
import { SeedLoaderService } from './seed-loader';
6+
import type { IDataEngine, IMetadataService } from '@objectstack/spec/contracts';
7+
8+
/**
9+
* framework#4998: a roll-up summary recompute that exhausts its retries must be
10+
* LOUD and COUNTED.
11+
*
12+
* The recovery itself is correct and unchanged (framework#3147): the rows WERE
13+
* written, so re-writing them would duplicate. What was wrong was the
14+
* consequence's rank. A roll-up summary is a persisted DERIVED column on the
15+
* parent record, so after this the database is internally inconsistent — the
16+
* detail rows say one thing and the column summarizing them says another — and
17+
* nothing recomputes it until some later write touches the same parent, which
18+
* after a seed may never happen. The whole event used to be one `warn`: the
19+
* load counted no error, `success` stayed `true`, and no caller could detect it
20+
* programmatically.
21+
*
22+
* So both halves are pinned here, because shipping either alone was the defect:
23+
* the `error` line (with its consequence and its remedy) AND
24+
* `summariesStale` / `summary.totalSummariesStale`.
25+
*/
26+
27+
function createLogger() {
28+
return { info: vi.fn(), warn: vi.fn(), error: vi.fn(), debug: vi.fn() };
29+
}
30+
31+
function createFaithfulEngine(): { engine: IDataEngine; store: Record<string, any[]> } {
32+
const store: Record<string, any[]> = {};
33+
let idCounter = 0;
34+
35+
const engine = {
36+
find: vi.fn(async (objectName: string, query?: any) => {
37+
let records = store[objectName] || [];
38+
if (query?.where) {
39+
records = records.filter((r) =>
40+
Object.entries(query.where).every(([k, v]) => r[k] === v),
41+
);
42+
}
43+
if (typeof query?.limit === 'number') records = records.slice(0, query.limit);
44+
return records;
45+
}),
46+
findOne: vi.fn(async (objectName: string, query?: any) => {
47+
const rows = await (engine.find as any)(objectName, { ...query, limit: 1 });
48+
return rows[0] ?? null;
49+
}),
50+
insert: vi.fn(async (objectName: string, data: any) => {
51+
if (!store[objectName]) store[objectName] = [];
52+
if (Array.isArray(data)) {
53+
const records = data.map((d) => ({ id: `gen-${++idCounter}`, ...d }));
54+
store[objectName].push(...records);
55+
return records;
56+
}
57+
const record = { id: `gen-${++idCounter}`, ...data };
58+
store[objectName].push(record);
59+
return record;
60+
}),
61+
update: vi.fn(async (objectName: string, data: any) => {
62+
const records = store[objectName] || [];
63+
const idx = records.findIndex((r) => r.id === data.id);
64+
if (idx >= 0) { records[idx] = { ...records[idx], ...data }; return records[idx]; }
65+
return data;
66+
}),
67+
delete: vi.fn(async () => ({ deleted: 1 })),
68+
count: vi.fn(async (objectName: string) => (store[objectName] || []).length),
69+
aggregate: vi.fn(async () => []),
70+
} as unknown as IDataEngine;
71+
72+
return { engine, store };
73+
}
74+
75+
/**
76+
* Two independent objects — no references between them, so nothing is deferred
77+
* and each dataset's counters stand on their own.
78+
*/
79+
function createMetadata(): IMetadataService {
80+
const objects: Record<string, any> = {
81+
roll_invoice: { name: 'roll_invoice', fields: { name: { type: 'text' }, total: { type: 'number' } } },
82+
roll_payment: { name: 'roll_payment', fields: { name: { type: 'text' }, amount: { type: 'number' } } },
83+
};
84+
return {
85+
getObject: vi.fn(async (name: string) => objects[name]),
86+
listObjects: vi.fn(async () => Object.values(objects)),
87+
register: vi.fn(async () => {}),
88+
get: vi.fn(async (_t: string, name: string) => objects[name]),
89+
list: vi.fn(async () => []),
90+
unregister: vi.fn(async () => {}),
91+
exists: vi.fn(async () => false),
92+
listNames: vi.fn(async () => []),
93+
} as unknown as IMetadataService;
94+
}
95+
96+
const CONFIG = {
97+
dryRun: false,
98+
haltOnError: false,
99+
multiPass: true,
100+
defaultMode: 'insert',
101+
batchSize: 1000,
102+
transaction: false,
103+
} as any;
104+
105+
const seedFor = (object: string, records: any[]) => ({
106+
object,
107+
externalId: 'name',
108+
mode: 'insert',
109+
env: ['prod', 'dev', 'test'],
110+
records,
111+
});
112+
113+
/**
114+
* Make `object`'s ARRAY insert write its rows and then report a post-write
115+
* roll-up recompute failure — objectql's `SummaryRecomputeError` shape
116+
* (framework#3147), matched across the package boundary by `code`.
117+
*/
118+
function failSummaryRecompute(
119+
engine: IDataEngine,
120+
object: string,
121+
failures: Array<{ childObject: string; parentObject: string; parentId: string; field: string; error: unknown }>,
122+
) {
123+
const realInsert = (engine.insert as any).getMockImplementation();
124+
(engine.insert as any).mockImplementation(async (obj: string, data: any, opts: any) => {
125+
if (obj === object && Array.isArray(data)) {
126+
const written = await realInsert(obj, data, opts);
127+
throw Object.assign(
128+
new Error(
129+
`Roll-up summary recompute failed after retries for ${failures.length} parent record(s); ` +
130+
`the triggering records WERE written (summary values may be stale).`,
131+
),
132+
{ code: 'ERR_SUMMARY_RECOMPUTE', written, failures },
133+
);
134+
}
135+
return realInsert(obj, data, opts);
136+
});
137+
}
138+
139+
const FAILURES = [
140+
{ childObject: 'roll_invoice', parentObject: 'roll_account', parentId: 'acc-1', field: 'total_billed', error: new Error('deadlock detected') },
141+
{ childObject: 'roll_invoice', parentObject: 'roll_account', parentId: 'acc-2', field: 'total_billed', error: new Error('deadlock detected') },
142+
];
143+
144+
describe('a roll-up summary left stale by a seed is loud and counted (framework#4998)', () => {
145+
it('logs at ERROR naming the object, the stale column, the consequence and the remedy', async () => {
146+
const { engine } = createFaithfulEngine();
147+
const logger = createLogger();
148+
failSummaryRecompute(engine, 'roll_invoice', FAILURES);
149+
150+
await new SeedLoaderService(engine, createMetadata(), logger).load({
151+
seeds: [seedFor('roll_invoice', [{ name: 'INV-1', total: 10 }, { name: 'INV-2', total: 20 }])] as any,
152+
config: CONFIG,
153+
});
154+
155+
expect(logger.error).toHaveBeenCalledTimes(1);
156+
const [message, cause, meta] = (logger.error as any).mock.calls[0];
157+
158+
// NAMES the object being seeded and the persisted column that is now wrong.
159+
expect(message).toContain('roll_invoice');
160+
expect(message).toContain('roll_account.total_billed');
161+
162+
// CONSEQUENCE — #4632 requires it in the line that prints, and the specific
163+
// trap here is that everything else still reads healthy.
164+
expect(message).toContain('STALE');
165+
expect(message).toContain('disagree with the detail rows');
166+
expect(message).toContain('success: true');
167+
168+
// REMEDY — both routes back to a correct summary.
169+
expect(message).toContain('re-run the seed');
170+
expect(message).toContain('trigger any write on the affected parent record(s)');
171+
172+
// The original cause travels with it, structurally (not just pasted in).
173+
expect(message).toContain('Cause: Roll-up summary recompute failed after retries');
174+
expect(cause).toBeInstanceOf(Error);
175+
expect((cause as Error).message).toContain('the triggering records WERE written');
176+
expect(meta).toMatchObject({ object: 'roll_invoice', summariesStale: 2 });
177+
expect(meta.summaryColumns).toEqual(['roll_account.total_billed']);
178+
expect(meta.failures.map((f: any) => f.parentId)).toEqual(['acc-1', 'acc-2']);
179+
expect(meta.failures[0].error).toBe('deadlock detected');
180+
181+
// Mutation pin: reverting to the pre-#4998 `warn` must turn this red. The
182+
// AST gate (`pnpm check:durability-log-level`, `performSeedWrite` in its
183+
// DURABILITY_CRITICAL_CALLEES) fails on the same revert in CI.
184+
const warned = (logger.warn as any).mock.calls.map(([m]: [string]) => m).join('\n');
185+
expect(warned).not.toContain('summary');
186+
});
187+
188+
it('counts it in the result — per object and in the summary — so a caller can branch on it', async () => {
189+
const { engine, store } = createFaithfulEngine();
190+
failSummaryRecompute(engine, 'roll_invoice', FAILURES);
191+
192+
const result = await new SeedLoaderService(engine, createMetadata(), createLogger()).load({
193+
seeds: [seedFor('roll_invoice', [{ name: 'INV-1', total: 10 }, { name: 'INV-2', total: 20 }])] as any,
194+
config: CONFIG,
195+
});
196+
197+
// Mutation pin: the pre-#4998 behaviour counted NOTHING anywhere.
198+
expect(result.results[0].summariesStale).toBe(2);
199+
expect(result.summary.totalSummariesStale).toBe(2);
200+
201+
// …while every other counter stays truthful: the rows DID land, exactly
202+
// once, so `errored` must not move and the reconciliation still holds.
203+
expect(result.summary.totalErrored).toBe(0);
204+
expect(result.summary.totalInserted).toBe(2);
205+
expect(store.roll_invoice).toHaveLength(2);
206+
207+
// `success` deliberately stays true — it answers "did the rows land", and
208+
// they did. Flipping it would report `success: false` with an EMPTY errors
209+
// array to the protocol seed-apply surface and fail package/marketplace
210+
// installs that wrote every row; the counter above carries the signal.
211+
expect(result.success).toBe(true);
212+
expect(result.errors).toEqual([]);
213+
});
214+
215+
it('attributes the count to the dataset that caused it, leaving clean datasets at 0', async () => {
216+
const { engine } = createFaithfulEngine();
217+
failSummaryRecompute(engine, 'roll_invoice', FAILURES);
218+
219+
const result = await new SeedLoaderService(engine, createMetadata(), createLogger()).load({
220+
seeds: [
221+
seedFor('roll_invoice', [{ name: 'INV-1', total: 10 }, { name: 'INV-2', total: 20 }]),
222+
seedFor('roll_payment', [{ name: 'PAY-1', amount: 5 }]),
223+
] as any,
224+
config: CONFIG,
225+
});
226+
227+
const byObject = Object.fromEntries(result.results.map((r) => [r.object, r.summariesStale]));
228+
expect(byObject).toEqual({ roll_invoice: 2, roll_payment: 0 });
229+
expect(result.summary.totalSummariesStale).toBe(2);
230+
});
231+
232+
it('stays quiet and counts 0 when every recompute succeeds', async () => {
233+
const { engine } = createFaithfulEngine();
234+
const logger = createLogger();
235+
236+
const result = await new SeedLoaderService(engine, createMetadata(), logger).load({
237+
seeds: [seedFor('roll_invoice', [{ name: 'INV-1', total: 10 }])] as any,
238+
config: CONFIG,
239+
});
240+
241+
expect(logger.error).not.toHaveBeenCalled();
242+
expect(result.results[0].summariesStale).toBe(0);
243+
expect(result.summary.totalSummariesStale).toBe(0);
244+
expect(result.success).toBe(true);
245+
});
246+
247+
it('a load with no datasets reports 0 rather than omitting the counter', async () => {
248+
const { engine } = createFaithfulEngine();
249+
250+
const result = await new SeedLoaderService(engine, createMetadata(), createLogger()).load({
251+
seeds: [] as any,
252+
config: CONFIG,
253+
});
254+
255+
expect(result.summary.totalSummariesStale).toBe(0);
256+
});
257+
});
258+
259+
describe('the counter survives the contract, and the contract survives older payloads', () => {
260+
it('is carried THROUGH SeedLoaderResultSchema.parse — not stripped as an unknown key', async () => {
261+
const { engine } = createFaithfulEngine();
262+
failSummaryRecompute(engine, 'roll_invoice', FAILURES);
263+
264+
const result = await new SeedLoaderService(engine, createMetadata(), createLogger()).load({
265+
seeds: [seedFor('roll_invoice', [{ name: 'INV-1', total: 10 }, { name: 'INV-2', total: 20 }])] as any,
266+
config: CONFIG,
267+
});
268+
269+
// The declared shape is what consumers actually receive over a parse
270+
// boundary. A field the runtime sets but the schema does not declare would
271+
// vanish HERE, silently — which is why #4998 could not be closed inside
272+
// metadata-protocol alone.
273+
const parsed = SeedLoaderResultSchema.parse(result);
274+
expect(parsed.summary.totalSummariesStale).toBe(2);
275+
expect(parsed.results[0].summariesStale).toBe(2);
276+
});
277+
278+
it('defaults to 0 for a payload written before the field existed', () => {
279+
// Proving the `.default(0)` claim rather than asserting it: this is exactly
280+
// a pre-#4998 producer's output, and it must still parse.
281+
const legacyPerObject = {
282+
object: 'roll_invoice',
283+
mode: 'insert',
284+
inserted: 2, updated: 0, skipped: 0, errored: 0, total: 2,
285+
referencesResolved: 0, referencesDeferred: 0,
286+
errors: [],
287+
};
288+
expect(SeedLoadResultSchema.parse(legacyPerObject).summariesStale).toBe(0);
289+
290+
const legacyResult = {
291+
success: true,
292+
dryRun: false,
293+
dependencyGraph: { nodes: [], insertOrder: [], circularDependencies: [] },
294+
results: [legacyPerObject],
295+
errors: [],
296+
summary: {
297+
objectsProcessed: 1, totalRecords: 2, totalInserted: 2, totalUpdated: 0,
298+
totalSkipped: 0, totalErrored: 0, totalReferencesResolved: 0,
299+
totalReferencesDeferred: 0, circularDependencyCount: 0, durationMs: 1,
300+
},
301+
};
302+
expect(SeedLoaderResultSchema.parse(legacyResult).summary.totalSummariesStale).toBe(0);
303+
});
304+
});

0 commit comments

Comments
 (0)