diff --git a/apps/desktop/main/sync.test.ts b/apps/desktop/main/sync.test.ts index f5ee9c66..3364e5c2 100644 --- a/apps/desktop/main/sync.test.ts +++ b/apps/desktop/main/sync.test.ts @@ -414,6 +414,10 @@ describe('Sync progress log — sync:progress emission and the bounded ring buff // every call, not just the first — the grouping tests below need many // items to fail, not one. itemPushFailureFor?: (bodyText: string) => string | undefined; + // Overrides the HTTP status used for an itemPushFailureFor failure — + // defaults to 500 (transient) when omitted. Lets a test drive a 4xx + // (permanent, per isPermanentPushFailure()) failure through the same stub. + itemPushStatusFor?: (bodyText: string) => number; } = {}) { const desktopDir = fs.mkdtempSync(path.join(os.tmpdir(), `peek-desktop-progresslog-${name}-`)); datastore.initDatabase(path.join(desktopDir, 'datastore.sqlite')); @@ -435,7 +439,8 @@ describe('Sync progress log — sync:progress emission and the bounded ring buff if (opts.itemPushFailureFor && method === 'POST' && reqPath.startsWith('/items')) { const failMessage = opts.itemPushFailureFor(bodyText); if (failMessage !== undefined) { - return new Response(failMessage, { status: 500 }); + const status = opts.itemPushStatusFor ? opts.itemPushStatusFor(bodyText) : 500; + return new Response(failMessage, { status }); } } @@ -559,6 +564,130 @@ describe('Sync progress log — sync:progress emission and the bounded ring buff ); }); + it('six item pushes failing with the SAME error list all six ids — the raised PUSH_FAILURE_IDS_MAX', async () => { + const { apiKey } = setup('item-fail-six-ids', { + itemPushFailureFor: () => 'simulated identical push failure', + }); + + // Past the old cap of 5, within the current cap of 20 — the six ids + // must all be listed, which the old cap would have suppressed entirely. + const ITEM_COUNT = 6; + const db = datastore.getDb(); + const now = Date.now(); + const CONTENT_MARKER = 'item-content-must-not-leak-into-the-log'; + const insert = db.prepare(` + INSERT INTO items (id, type, content, metadata, syncId, syncedAt, createdAt, updatedAt, deletedAt) + VALUES (?, 'text', ?, '{}', '', 0, ?, ?, 0) + `); + for (let i = 0; i < ITEM_COUNT; i++) { + insert.run(`local-fail-six-${i}`, `${CONTENT_MARKER}-${i}`, now, now); + } + + await assert.doesNotReject(() => sync.syncAll(FAKE_SERVER_URL, apiKey)); + + const log = sync.getSyncLog(); + const failureEntries = log.filter((e) => e.stage === 'push-items' && e.phase === 'error'); + + assert.strictEqual( + failureEntries.length, + 1, + `expected exactly one grouped entry for identical failures, got ${failureEntries.length}: ` + + JSON.stringify(failureEntries.map((e) => e.message)) + ); + for (let i = 0; i < ITEM_COUNT; i++) { + assert.ok( + failureEntries[0].message.includes(`local-fail-six-${i}`), + `expected the grouped entry to name item local-fail-six-${i} (6 failures, within the raised cap), got: ${failureEntries[0].message}` + ); + } + assert.ok( + !log.some((e) => e.message.includes(CONTENT_MARKER)), + 'expected no log entry to contain item content' + ); + }); + + it('a 4xx item failure logs as permanent and a 5xx item failure logs as retryable in the same run', async () => { + const PERMANENT_MARKER = 'permanent-marker'; + const TRANSIENT_MARKER = 'transient-marker'; + const { apiKey } = setup('item-fail-mixed-permanence', { + itemPushFailureFor: (bodyText) => + bodyText.includes(PERMANENT_MARKER) + ? `content is required for type 'text'` + : 'simulated server outage', + itemPushStatusFor: (bodyText) => (bodyText.includes(PERMANENT_MARKER) ? 400 : 500), + }); + + const db = datastore.getDb(); + const now = Date.now(); + db.prepare(` + INSERT INTO items (id, type, content, metadata, syncId, syncedAt, createdAt, updatedAt, deletedAt) + VALUES (?, 'text', ?, '{}', '', 0, ?, ?, 0) + `).run('local-permanent-item', PERMANENT_MARKER, now, now); + db.prepare(` + INSERT INTO items (id, type, content, metadata, syncId, syncedAt, createdAt, updatedAt, deletedAt) + VALUES (?, 'text', ?, '{}', '', 0, ?, ?, 0) + `).run('local-transient-item', TRANSIENT_MARKER, now, now); + + await assert.doesNotReject(() => sync.syncAll(FAKE_SERVER_URL, apiKey)); + + const log = sync.getSyncLog(); + const failureEntries = log.filter((e) => e.stage === 'push-items' && e.phase === 'error'); + + const permanentEntry = failureEntries.find((e) => e.message.includes('local-permanent-item')); + assert.ok(permanentEntry, `expected an entry naming the 4xx item, got: ${JSON.stringify(failureEntries.map((e) => e.message))}`); + assert.ok( + permanentEntry!.message.includes('will not succeed until the item changes'), + `expected the 4xx failure to be worded as permanent, got: ${permanentEntry!.message}` + ); + + const transientEntry = failureEntries.find((e) => e.message.includes('local-transient-item')); + assert.ok(transientEntry, `expected an entry naming the 5xx item, got: ${JSON.stringify(failureEntries.map((e) => e.message))}`); + assert.ok( + transientEntry!.message.includes('will retry next run'), + `expected the 5xx failure to be worded as retryable, got: ${transientEntry!.message}` + ); + + assert.ok( + !log.some((e) => e.message.includes(PERMANENT_MARKER) || e.message.includes(TRANSIENT_MARKER)), + 'expected no log entry to contain item content' + ); + }); + + it('a 4xx event chunk rejection is logged as permanent, not retryable', async () => { + const { apiKey } = setup('event-chunk-permanent', { failFirstEventPushOnce: true }); + + const createRes = await serverApp.request('/items', { + method: 'POST', + headers: authHeaders(apiKey), + body: JSON.stringify({ type: 'series', metadata: { title: 'Event chunk permanence series' } }), + }); + const { id: serverItemId } = (await createRes.json()) as { id: string }; + + const db = datastore.getDb(); + const now = Date.now(); + const localItemId = 'local-event-chunk-permanent-item'; + db.prepare(` + INSERT INTO items (id, type, content, metadata, syncId, syncedAt, createdAt, updatedAt, deletedAt) + VALUES (?, 'series', NULL, '{}', ?, ?, ?, ?, 0) + `).run(localItemId, serverItemId, now, now, now); + db.prepare(` + INSERT INTO item_events (id, itemId, content, value, occurredAt, metadata, createdAt) + VALUES (?, ?, NULL, ?, ?, '{}', ?) + `).run('evt-chunk-permanent', localItemId, 1, now, now); + + // setup()'s failFirstEventPushOnce rejects the chunk with a 400 — + // exercises isPermanentPushFailure()'s 4xx branch for an event chunk. + await assert.doesNotReject(() => sync.syncAll(FAKE_SERVER_URL, apiKey)); + + const log = sync.getSyncLog(); + const chunkFailure = log.find((e) => e.stage === 'push-events' && e.phase === 'error'); + assert.ok(chunkFailure, 'expected a log entry for the rejected chunk'); + assert.ok( + chunkFailure!.message.includes('will not succeed until the events change'), + `expected the 4xx chunk rejection to be worded as permanent, got: ${chunkFailure!.message}` + ); + }); + it('item pushes failing with DIFFERENT errors produce one entry per distinct reason, capped with a rolled-up tail', async () => { let counter = 0; const { apiKey } = setup('item-fail-different-reasons', { diff --git a/apps/desktop/main/sync.ts b/apps/desktop/main/sync.ts index 86552b04..d7061af0 100644 --- a/apps/desktop/main/sync.ts +++ b/apps/desktop/main/sync.ts @@ -676,9 +676,12 @@ const ITEM_PUSH_PROGRESS_INTERVAL_MS = 3000; const PUSH_FAILURE_REASONS_MAX = 20; // Ids are listed only for a small group — past this, the id list is as // unreadable as one line per failure would have been, and the log's job here is -// to say WHY a class of failure happened, not to enumerate every row (failed -// rows are retried automatically on the next run regardless). -const PUSH_FAILURE_IDS_MAX = 5; +// to say WHY a class of failure happened, not to enumerate every row. A full +// re-push can still fail thousands of items with the same reason, so the cap +// has to hold even then — but a handful of failures (the case a user actually +// chases down, e.g. one malformed item blocking every future run) is exactly +// where the ids matter most, and 20 of them is still a readable log entry. +const PUSH_FAILURE_IDS_MAX = 20; /** * Turn a reason -> ids map into one summary line per distinct reason, most @@ -701,6 +704,38 @@ function groupFailuresByReason(idsByReason: Map, noun: string) return lines; } +/** + * A message shaped `Server error : ` (serverFetch's own error + * throw, above) with a 4xx status means the server looked at this exact row + * and rejected it — resending the same body next run cannot change that + * outcome. Anything else (a timeout, a network error, a 5xx) means the + * server or the link was unavailable, which is exactly the kind of failure + * an unchanged retry can clear on its own. + */ +function isPermanentPushFailure(message: string): boolean { + const match = message.match(/^Server error (\d)\d\d:/); + return match !== null && match[1] === '4'; +} + +/** + * Split a reason -> ids map into the permanent (isPermanentPushFailure() + * above) and transient reasons within it, so pushToServer() and + * pushEventsToServer() can log the two classes as separate lines — same + * grouping, different wording — without duplicating the accumulation loop + * per class. + */ +function partitionByPermanence(idsByReason: Map): { + permanent: Map; + transient: Map; +} { + const permanent = new Map(); + const transient = new Map(); + for (const [reason, ids] of idsByReason) { + (isPermanentPushFailure(reason) ? permanent : transient).set(reason, ids); + } + return { permanent, transient }; +} + /** * Push unsynced local items to server * @@ -806,10 +841,17 @@ export async function pushToServer( // Surfaced in the Settings sync log — "Pushed N item(s), M failed" (logged // by syncAll() from this function's return value) says HOW MANY, not why; // these lines say why, grouped so a systemic failure (every item hitting - // the same server error) reads as one line, not thousands. + // the same server error) reads as one line, not thousands. Split by + // isPermanentPushFailure() so a 400 (this item, as-sent, will never be + // accepted — retrying it every run is wasted work) reads differently from + // a timeout/5xx (the next run can simply succeed). if (failuresByReason.size > 0) { - for (const line of groupFailuresByReason(failuresByReason, 'item')) { - logSyncProgress('push-items', 'error', `Item push failed — ${line}`); + const { permanent, transient } = partitionByPermanence(failuresByReason); + for (const line of groupFailuresByReason(permanent, 'item')) { + logSyncProgress('push-items', 'error', `Item push rejected, will not succeed until the item changes — ${line}`); + } + for (const line of groupFailuresByReason(transient, 'item')) { + logSyncProgress('push-items', 'error', `Item push failed, will retry next run — ${line}`); } } @@ -1192,9 +1234,15 @@ export async function pushEventsToServer( // message so N chunks failing for the SAME reason (e.g. the server down for // the whole run) collapse into one line instead of one per chunk. Events in // a failed chunk are not lost — they stay eligible for the next run via - // notDeliveredMinCreatedAt above. + // notDeliveredMinCreatedAt above, and are retried unchanged regardless of + // which class this is (see isPermanentPushFailure()); only the wording + // below tells the two apart, so a 400 doesn't read as if next run will help. if (chunkFailuresByReason.size > 0) { - for (const line of groupFailuresByReason(chunkFailuresByReason, 'event')) { + const { permanent, transient } = partitionByPermanence(chunkFailuresByReason); + for (const line of groupFailuresByReason(permanent, 'event')) { + logSyncProgress('push-events', 'error', `Event chunk(s) rejected, will not succeed until the events change — ${line}`); + } + for (const line of groupFailuresByReason(transient, 'event')) { logSyncProgress('push-events', 'error', `Event chunk(s) rejected, will retry next run — ${line}`); } }