diff --git a/src/device-sync/__tests__/engine/contacts-flow.test.ts b/src/device-sync/__tests__/engine/contacts-flow.test.ts index 54c7dfa2..35db0a97 100644 --- a/src/device-sync/__tests__/engine/contacts-flow.test.ts +++ b/src/device-sync/__tests__/engine/contacts-flow.test.ts @@ -2,7 +2,7 @@ // server: first sync, incremental /changes, uploads, echoes, selection // changes and groups (docs/device-sync.md, "A sync run"). -import { describe, expect, it, vi } from 'vitest'; +import { describe, expect, it } from 'vitest'; import { Data, MimeType } from '../../android-columns'; import { runDeviceSync } from '../../engine/run'; import { @@ -295,21 +295,22 @@ describe('device sync engine: contacts', () => { expect(h.server.requests.length).toBe(requests); }); - it("keeps the last run's status (its conflicts and item errors) when an upload-only sync finds nothing to do", async () => { + it("keeps the last run's status when an upload-only sync finds nothing to do, moving only its time on", async () => { const h = createHarness(); addServerCards(h, ['Ada']); await h.run(); - const recordStatus = vi.mocked(h.deps.recordStatus); - const recorded = recordStatus.mock.calls.length; + const status = h.lastStatus()!; + expect(status).toMatchObject({ outcome: 'ok', stats: { downloaded: { created: 1 } } }); // The upload sync Android starts right after a manual one: nothing waits on the device. + h.clock.now += 1_000; expect((await h.run(CONTACTS_AUTHORITY, { upload: true })).outcome).toBe('ok'); - expect(recordStatus.mock.calls.length).toBe(recorded); + expect(h.lastStatus()).toEqual({ ...status, at: h.clock.now }); // One that has something to upload is a run like any other. renameDeviceContact(h, h.contactNamed('Ada')!.id, 'Ada King'); await h.run(CONTACTS_AUTHORITY, { upload: true }); - expect(recordStatus.mock.calls.length).toBe(recorded + 1); + expect(h.lastStatus()).toMatchObject({ stats: { downloaded: { created: 0 }, uploaded: { updated: 1 } } }); }); it('reports disabled, unsupported and rows of another owner without touching anything', async () => { diff --git a/src/device-sync/__tests__/engine/harness.ts b/src/device-sync/__tests__/engine/harness.ts index dc13849e..c86135c2 100644 --- a/src/device-sync/__tests__/engine/harness.ts +++ b/src/device-sync/__tests__/engine/harness.ts @@ -19,6 +19,7 @@ import { type ProviderPort, type RunExtras, type RunReport, + type RunStatus, type Row, } from '../../types'; import { FakeDeviceProviders } from '../fakes/fake-provider'; @@ -67,6 +68,8 @@ export interface Harness { nameDataRow(rawContactId: number): Row | undefined; events(): Row[]; serverNames(accountId?: string): string[]; + /** The status the runs recorded last for the settings (what `deps.lastStatus` answers). */ + lastStatus(authority?: Authority): RunStatus | undefined; } export function createHarness(options: { tuning?: Partial; accounts?: 'personal' | 'withShared'; rebuild?: boolean } = {}): Harness { @@ -84,6 +87,7 @@ export function createHarness(options: { tuning?: Partial; accounts?: 'p const prefs: AccountSyncPrefs = { contactsSelection: {}, calendarSelection: {}, reminderOwner: 'device' }; const checkpoints: Harness['checkpoints'] = { count: 0, crashAt: null }; const batches: Harness['batches'] = { applied: 0, crashAfter: null, log: [] }; + const statuses = new Map(); const wrap = (port: ProviderPort): ProviderPort => ({ accountName: port.accountName, @@ -119,7 +123,10 @@ export function createHarness(options: { tuning?: Partial; accounts?: 'p subscriptionCalendars: async () => [], isSyncEnabled: async () => true, deviceZone: () => 'Europe/Berlin', - recordStatus: vi.fn(), + recordStatus: vi.fn((_registryId: string, authority: Authority, status: RunStatus) => { + statuses.set(authority, status); + }), + lastStatus: (_registryId, authority) => statuses.get(authority), recordKnownState: vi.fn(), notifyAuthProblem: vi.fn(), yieldThread: async () => undefined, @@ -168,6 +175,7 @@ export function createHarness(options: { tuning?: Partial; accounts?: 'p .filter((c) => c.kind !== 'group') .map((c) => String((c.name as { full?: string } | undefined)?.full ?? '')) .sort(), + lastStatus: (authority = CONTACTS_AUTHORITY) => statuses.get(authority), }; return harness; } diff --git a/src/device-sync/__tests__/engine/internals.test.ts b/src/device-sync/__tests__/engine/internals.test.ts index 33323444..32c20531 100644 --- a/src/device-sync/__tests__/engine/internals.test.ts +++ b/src/device-sync/__tests__/engine/internals.test.ts @@ -7,13 +7,14 @@ import { BatchWriter, buildBatch, estimateBatchBytes, MAX_OPS_PER_YIELD, prepend import { classifyFailure, RunAbort, StateMismatch, StopRun } from '../../engine/errors'; import { acquireLock } from '../../engine/mutex'; import { isBackedOff, nextMarker } from '../../engine/poison'; +import { emptyStats, isQuietRun, statusToRecord } from '../../engine/report'; import { collectionDefaultOn, isCollectionSelected } from '../../engine/selection'; import { accountOf, emptySyncState, parseSyncState, serializeSyncState, StateStore, type SyncState } from '../../engine/sync-state'; import { classifySetError, existingIdFromUidError, JmapCaller } from '../../jmap/caller'; import { openWithAuthRebuild } from '../../jmap/connection'; import { JMAPMethodError } from '../../jmap/errors'; import { accountsWithCapability, calendarAddresses } from '../../jmap/session'; -import { JMAP_CALENDARS, JMAP_CONTACTS, type BatchResult, type ProviderOp, type ProviderPort } from '../../types'; +import { JMAP_CALENDARS, JMAP_CONTACTS, type BatchResult, type ProviderOp, type ProviderPort, type RunStats, type RunStatus } from '../../types'; import { FakeJmapServer } from '../fakes/fake-jmap-server'; function port(apply: (ops: ProviderOp[]) => BatchResult | Promise): ProviderPort & { sent: ProviderOp[][] } { @@ -459,3 +460,47 @@ describe('outcomes', () => { expect(classifyFailure(new TypeError('x is undefined'), 0)).toMatchObject({ outcome: 'internal' }); }); }); + +describe('the status a run leaves for the settings', () => { + const status = (over: Partial = {}): RunStatus => ({ at: 2_000, outcome: 'ok', durationMs: 50, conflicts: 0, itemErrors: 0, stats: emptyStats(), ...over }); + const withStats = (edit: (stats: RunStats) => void) => { + const stats = emptyStats(); + edit(stats); + return status({ stats }); + }; + const reported = status({ at: 1_000, durationMs: 900, conflicts: 1, itemErrors: 2, message: 'invitations not sent', stats: { ...emptyStats(), skipped: 2 } }); + + it('keeps what the run before reported through a run that did nothing, moving the time on', () => { + expect(isQuietRun(status())).toBe(true); + expect(statusToRecord(status(), reported)).toEqual({ ...reported, at: 2_000 }); + expect(statusToRecord(status(), undefined)).toEqual(status()); + }); + + it('shows a failure followed by a run that did nothing as recovered, with what the failed run reported', () => { + const failed = { ...reported, outcome: 'io' as const, message: 'Could not reach the server' }; + const recorded = statusToRecord(status(), failed); + + expect(recorded).toEqual({ at: 2_000, outcome: 'ok', durationMs: 900, conflicts: 1, itemErrors: 2, stats: reported.stats }); + }); + + it('replaces it with a run that wrote, skipped or reported anything, or failed', () => { + const busy = [ + withStats((s) => (s.downloaded.created = 1)), + withStats((s) => (s.downloaded.deleted = 1)), + withStats((s) => (s.uploaded.updated = 1)), + withStats((s) => (s.skipped = 1)), + status({ conflicts: 1 }), + status({ itemErrors: 1 }), + status({ message: 'invitations not sent' }), + status({ outcome: 'io', message: 'Could not reach the server' }), + status({ outcome: 'cancelled' }), + status({ outcome: 'disabled', message: 'Sync is off for this account' }), + ]; + for (const run of busy) { + expect(isQuietRun(run)).toBe(false); + expect(statusToRecord(run, reported)).toBe(run); + } + // Items only looked at are no work. + expect(isQuietRun(withStats((s) => (s.entries = 3)))).toBe(true); + }); +}); diff --git a/src/device-sync/__tests__/engine/real-planners.test.ts b/src/device-sync/__tests__/engine/real-planners.test.ts index 1f466ac9..0652f345 100644 --- a/src/device-sync/__tests__/engine/real-planners.test.ts +++ b/src/device-sync/__tests__/engine/real-planners.test.ts @@ -452,6 +452,71 @@ describe('device sync engine with the real planners', () => { }); }); + describe('the last run status the settings show', () => { + /** A run that puts back an edit the server refuses: reported once, nothing waits afterwards. */ + async function refusedEdit() { + const h = real(); + const [ada] = addServerCards(h, ['Ada Lovelace', 'Grace Hopper']); + await h.run(); + renameDeviceContact(h, h.contactNamed('Ada Lovelace')!.id, 'Ada King'); + h.server.setErrorFor('ContactCard', 'a', ada, { type: 'forbidden' }); + h.clock.now += 60_000; + expect((await h.run()).itemErrors).toEqual([expect.objectContaining({ type: 'forbidden' })]); + const status = h.lastStatus()!; + expect(status).toMatchObject({ outcome: 'ok', itemErrors: 1 }); + return { h, status }; + } + + it('keeps what a run reported through an upload sync after it that finds nothing to do', async () => { + const { h, status } = await refusedEdit(); + h.clock.now += 2_000; + + await h.run(CONTACTS_AUTHORITY, { upload: true }); + + expect(h.lastStatus()).toEqual({ ...status, at: expect.any(Number) }); + expect(h.lastStatus()!.at).toBeGreaterThan(status.at); + }); + + it('keeps what a run reported through a follow-up sync that finds nothing new on the server', async () => { + const { h, status } = await refusedEdit(); + h.clock.now += 2_000; + + expect((await h.run()).itemErrors).toEqual([]); + + expect(h.lastStatus()).toEqual({ ...status, at: expect.any(Number) }); + expect(h.lastStatus()!.at).toBeGreaterThan(status.at); + }); + + it('replaces it with a run that did something', async () => { + const { h } = await refusedEdit(); + addServerCards(h, ['Linus Torvalds']); + + await h.run(); + + expect(h.lastStatus()).toMatchObject({ outcome: 'ok', itemErrors: 0, stats: { downloaded: { created: 1 } } }); + }); + + it('shows a sync that finds nothing to do after a failed one as recovered', async () => { + const h = real(); + addServerCards(h, ['Ada Lovelace']); + await h.run(); + renameDeviceContact(h, h.contactNamed('Ada Lovelace')!.id, 'Ada King'); + h.server.failNextRequest('network', { match: 'ContactCard/set' }); + expect((await h.run()).outcome).toBe('io'); + expect(h.lastStatus()).toMatchObject({ outcome: 'io' }); + // Uploaded by the next sync; the one after it finds nothing to do. + expect((await h.run()).outcome).toBe('ok'); + h.clock.now += 2_000; + h.server.failNextRequest('network', { match: 'ContactCard/changes' }); + expect((await h.run()).outcome).toBe('io'); + + expect((await h.run()).outcome).toBe('ok'); + + expect(h.lastStatus()).toMatchObject({ outcome: 'ok', itemErrors: 0, conflicts: 0 }); + expect(h.lastStatus()).not.toHaveProperty('message'); + }); + }); + describe('a create whose target the server deleted after the claim', () => { it('claims a new contact again for a book that exists', async () => { const h = real(); diff --git a/src/device-sync/__tests__/engine/task.test.ts b/src/device-sync/__tests__/engine/task.test.ts index 384fc21c..5bc8adaa 100644 --- a/src/device-sync/__tests__/engine/task.test.ts +++ b/src/device-sync/__tests__/engine/task.test.ts @@ -15,7 +15,8 @@ vi.mock('../../native', () => ({ })); import * as native from '../../native'; -import { runDeviceSyncTask, teardownAuthority } from '../../task'; +import { emptyStats } from '../../engine/report'; +import { createTaskDeps, runDeviceSyncTask, teardownAuthority } from '../../task'; import { useDeviceSyncStore } from '../../../stores/device-sync-store'; import type { RunPayload } from '../../types'; @@ -42,6 +43,17 @@ describe('device sync task', () => { }); }); + it('reads back the status it records, for a run that did nothing to keep', async () => { + const deps = createTaskDeps(); + const status = { at: 5, outcome: 'ok' as const, durationMs: 3, conflicts: 1, itemErrors: 2, stats: emptyStats() }; + + await deps.recordStatus('bob@mail.example.com', 'com.android.calendar', status); + + await expect(deps.lastStatus('bob@mail.example.com', 'com.android.calendar')).resolves.toEqual(status); + await expect(deps.lastStatus('bob@mail.example.com', 'com.android.contacts')).resolves.toBeUndefined(); + await expect(deps.lastStatus('nobody@mail.example.com', 'com.android.calendar')).resolves.toBeUndefined(); + }); + it('reports a failure instead of throwing, and survives a refused finishRun', async () => { vi.mocked(native.getSyncSettings).mockRejectedValueOnce(new Error('module gone')); vi.mocked(native.finishRun).mockRejectedValueOnce(new Error('bridge down')); diff --git a/src/device-sync/engine/deps.ts b/src/device-sync/engine/deps.ts index 8f5bb227..28c9b98d 100644 --- a/src/device-sync/engine/deps.ts +++ b/src/device-sync/engine/deps.ts @@ -39,6 +39,8 @@ export interface EngineDeps { deviceZone(): string; /** The last run's status for the settings UI. */ recordStatus(registryId: string, authority: Authority, status: RunStatus): void | Promise; + /** The status `recordStatus` stored last, if any (a run that did nothing keeps its details). */ + lastStatus(registryId: string, authority: Authority): RunStatus | undefined | Promise; /** The latest state the engine synced for a JMAP account and type, so the app skips the echo of our own writes. */ recordKnownState(registryId: string, jmapAccountId: string, type: string, state: string): void | Promise; /** One notification that deep-links to sign-in, after an auth failure the rebuild did not fix. */ diff --git a/src/device-sync/engine/report.ts b/src/device-sync/engine/report.ts index 6f810607..b324e652 100644 --- a/src/device-sync/engine/report.ts +++ b/src/device-sync/engine/report.ts @@ -93,3 +93,37 @@ export function statusOf(report: RunReport, itemErrorCount = report.itemErrors.l if (report.message) status.message = report.message; return status; } + +const wrote =(counts: RunStats['downloaded']) => counts.created + counts.updated + counts.deleted > 0; + +/** A run that wrote nothing either way and had nothing to report: no conflict, item error, note or failure. */ +export function isQuietRun(status: RunStatus): boolean { + const { stats } = status; + return ( + status.outcome === 'ok' && + !status.conflicts && + !status.itemErrors && + !status.message && + !stats.skipped && + !wrote(stats.downloaded) && + !wrote(stats.uploaded) + ); +} + +/** + * The status the settings keep after a run. A quiet run (`isQuietRun`: the + * upload sync Android starts after a manual one, the follow-up sync the + * adapter asks for when changes arrived during a run, a manual sync right + * after an automatic one) keeps what the run before it reported, its + * conflicts, item errors and counts, and moves only the time on: otherwise + * a put-back edit or a conflict is reported for a second and gone. Its + * outcome is its own, so a failure before it shows as recovered, without the + * failure's message. Any other run replaces the status, so a problem stays + * only until the next run that does something. + */ +export function statusToRecord(status: RunStatus, previous: RunStatus | undefined): RunStatus { + if (!previous || !isQuietRun(status)) return status; + const kept: RunStatus = { ...previous, at: status.at, outcome: status.outcome }; + if (previous.outcome !== 'ok') delete kept.message; + return kept; +} diff --git a/src/device-sync/engine/run.ts b/src/device-sync/engine/run.ts index 4fb8c348..238d0aaa 100644 --- a/src/device-sync/engine/run.ts +++ b/src/device-sync/engine/run.ts @@ -16,6 +16,7 @@ import { type RunExtras, type RunPayload, type RunReport, + type RunStatus, } from '../types'; import { BatchWriter } from './batch'; import { CalendarSync } from './calendar-sync'; @@ -26,7 +27,7 @@ import { DEFAULT_TUNING, type EngineDeps, type Tuning } from './deps'; import { classifyFailure, RunAbort } from './errors'; import { acquireLock, lockKey, stopRequested } from './mutex'; import { ProviderReader, str } from './provider'; -import { ReportBuilder, statusOf } from './report'; +import { isQuietRun, ReportBuilder, statusOf, statusToRecord } from './report'; import { emptySyncState, parseSyncState, StateStore, type SyncState } from './sync-state'; import type { ItemSync } from './item-sync'; @@ -156,36 +157,36 @@ export async function runDeviceSync(payload: RunPayload, deps: EngineDeps): Prom const report = new ReportBuilder(payload.runId, payload.authority, deps.now(), tuning.maxItemErrors); const key = lockKey(payload.registryId, payload.authority); const release = await acquireLock(key, Math.max(0, payload.deadline - deps.now() - tuning.deadlineMarginMs)); - let result: RunReport; - const run = { idle: false }; if (!release) { - result = report.build('cancelled', deps.now(), { message: 'Another sync of this account is still running', moreRecordsToGet: true }); - } else { - try { - result = await runLocked(payload, deps, tuning, report, key, run); - } finally { - release(); - } + const result = report.build('cancelled', deps.now(), { message: 'Another sync of this account is still running', moreRecordsToGet: true }); + await recordStatus(payload, deps, statusOf(result, report.itemErrorCount)); + return result; } - // An upload sync with nothing to upload (Android starts one right after a manual sync) did nothing: - // the last run's status, with its conflicts and item errors, stays what the settings show. - if (run.idle) return result; try { - await deps.recordStatus(payload.registryId, payload.authority, statusOf(result, report.itemErrorCount)); + const result = await runLocked(payload, deps, tuning, report, key); + // Still under the lock: no other run of the account and authority records between the read and the write. + await recordStatus(payload, deps, statusOf(result, report.itemErrorCount)); + return result; + } finally { + release(); + } +} + +/** + * Stores the status the settings show. A run that did nothing (the upload + * sync Android starts after a manual one, the follow-up of a run during which + * changes arrived) keeps the details of the run before it (`statusToRecord`). + */ +async function recordStatus(payload: RunPayload, deps: EngineDeps, status: RunStatus): Promise { + try { + const previous = isQuietRun(status) ? await deps.lastStatus(payload.registryId, payload.authority) : undefined; + await deps.recordStatus(payload.registryId, payload.authority, statusToRecord(status, previous)); } catch (error) { deps.log?.('recording the run status failed', error); } - return result; } -async function runLocked( - payload: RunPayload, - deps: EngineDeps, - tuning: Tuning, - report: ReportBuilder, - key: string, - run: { idle: boolean }, -): Promise { +async function runLocked(payload: RunPayload, deps: EngineDeps, tuning: Tuning, report: ReportBuilder, key: string): Promise { const finish = (outcome: RunReport['outcome'], extra: Parameters[2] = {}) => report.build(outcome, deps.now(), extra); const extras = payload.extras ?? {}; @@ -200,10 +201,7 @@ async function runLocked( return finish('internal', { message: 'The rows on this device were written for another account' }); } // Providers schedule an upload sync for every account 30 s after any app write. - if (extras.upload && !(await hasLocalWork(reader, payload.authority, stored))) { - run.idle = true; - return finish('ok'); - } + if (extras.upload && !(await hasLocalWork(reader, payload.authority, stored))) return finish('ok'); const connection = await deps.jmap(payload.registryId); if (stored.owner && stored.owner.origin !== connection.origin) { diff --git a/src/device-sync/task.ts b/src/device-sync/task.ts index 4500875b..cb0f1009 100644 --- a/src/device-sync/task.ts +++ b/src/device-sync/task.ts @@ -16,7 +16,7 @@ import AsyncStorage from '@react-native-async-storage/async-storage'; import { detectDeviceLocale, isSupportedLocale, translate, type LocaleCode } from '../i18n'; import { randomBytes } from '../lib/random'; -import { accountSyncPrefs, useDeviceSyncStore, waitForDeviceSyncHydration } from '../stores/device-sync-store'; +import { accountDeviceSync, accountSyncPrefs, useDeviceSyncStore, waitForDeviceSyncHydration } from '../stores/device-sync-store'; import type { RandomSource } from './common/ids'; import { runDeviceSync, @@ -124,6 +124,10 @@ export function createTaskDeps(): EngineDeps { await waitForDeviceSyncHydration(); useDeviceSyncStore.getState().recordRunStatus(registryId, authority, status); }, + lastStatus: async (registryId, authority) => { + await waitForDeviceSyncHydration(); + return accountDeviceSync(registryId).lastRun[authority]; + }, recordKnownState: async (registryId, jmapAccountId, type, state) => { await waitForDeviceSyncHydration(); useDeviceSyncStore.getState().recordKnownState(registryId, jmapAccountId, type, state);