fix(op-log): lock snapshot save to prevent lost-update window (#8308) (#8439)

* fix(op-log): lock snapshot save to prevent lost-update window

saveCurrentStateAsSnapshot() read NgRx state then lastSeq without
holding OPERATION_LOG lock. An op appended between the two reads would
get seq <= lastAppliedOpSeq but its effect would be absent from the
snapshot. On next hydration the tail replay would start after that seq,
silently skipping the op forever.

Fix: wrap in lockService.request(LOCK_NAMES.OPERATION_LOG, ...) and
read lastSeq BEFORE state snapshot so the worst interleaving degrades
to harmless re-replay (idempotent) rather than a missed op.

Fixes #8308

* fix(op-log): address review feedback on snapshot lock PR

- Amend JSDoc idempotency claim: syncTimeSpent is additive on re-replay
- Add inline note about compaction's opposite read order and worse failure mode
- Add lock regression tests (#8308): lock acquired, read order, error handling

Co-Authored-By: Claude <noreply@anthropic.com>

* docs(op-log): expand re-replay note to full op set + link #8469

* docs(op-log): generalize re-replay note, point to #8469

---------

Co-authored-by: Claude <noreply@anthropic.com>
Co-authored-by: Johannes Millan <johannes.millan@gmail.com>
This commit is contained in:
Harbinger 2026-06-18 19:35:43 +08:00 committed by GitHub
parent ce41a27e0a
commit ccad1f9bae
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
2 changed files with 135 additions and 38 deletions

View file

@ -10,6 +10,8 @@ import { VectorClockService } from '../sync/vector-clock.service';
import { StateSnapshotService } from '../backup/state-snapshot.service';
import { CLIENT_ID_PROVIDER, ClientIdProvider } from '../util/client-id.provider';
import { ValidateStateService } from '../validation/validate-state.service';
import { LockService } from '../sync/lock.service';
import { LOCK_NAMES } from '../core/operation-log.const';
import { MAX_VECTOR_CLOCK_SIZE } from '@sp/sync-core';
// Meaningful state (contains a task) so saveCurrentStateAsSnapshot proceeds past
@ -28,6 +30,7 @@ describe('OperationLogSnapshotService', () => {
let mockSchemaMigrationService: jasmine.SpyObj<SchemaMigrationService>;
let mockClientIdProvider: jasmine.SpyObj<ClientIdProvider>;
let mockValidateStateService: jasmine.SpyObj<ValidateStateService>;
let mockLockService: jasmine.SpyObj<LockService>;
beforeEach(() => {
mockOpLogStore = jasmine.createSpyObj('OperationLogStoreService', [
@ -55,6 +58,11 @@ describe('OperationLogSnapshotService', () => {
isValid: true,
typiaErrors: [],
});
mockLockService = jasmine.createSpyObj('LockService', ['request']);
// Default: execute the callback inline (mirrors real Web Locks behavior in Chrome)
mockLockService.request.and.callFake(async <T>(_name: string, fn: () => Promise<T>) =>
fn(),
);
TestBed.configureTestingModule({
providers: [
@ -65,6 +73,7 @@ describe('OperationLogSnapshotService', () => {
{ provide: SchemaMigrationService, useValue: mockSchemaMigrationService },
{ provide: CLIENT_ID_PROVIDER, useValue: mockClientIdProvider },
{ provide: ValidateStateService, useValue: mockValidateStateService },
{ provide: LockService, useValue: mockLockService },
],
});
service = TestBed.inject(OperationLogSnapshotService);
@ -318,6 +327,72 @@ describe('OperationLogSnapshotService', () => {
});
});
describe('saveCurrentStateAsSnapshot — lock regression', () => {
it('should acquire OPERATION_LOG lock before saving (#8308)', async () => {
mockStateSnapshotService.getStateSnapshot.and.returnValue(
MEANINGFUL_SNAPSHOT_STATE as any,
);
mockVectorClockService.getCurrentVectorClock.and.resolveTo({});
mockOpLogStore.getLastSeq.and.resolveTo(1);
mockOpLogStore.saveStateCache.and.resolveTo(undefined);
await service.saveCurrentStateAsSnapshot();
expect(mockLockService.request).toHaveBeenCalledWith(
LOCK_NAMES.OPERATION_LOG,
jasmine.any(Function),
);
});
it('should read lastSeq BEFORE getStateSnapshot inside the lock', async () => {
const callOrder: string[] = [];
mockLockService.request.and.callFake(
async <T>(_name: string, fn: () => Promise<T>) => {
callOrder.push('lock-start');
const r = await fn();
callOrder.push('lock-end');
return r;
},
);
mockOpLogStore.getLastSeq.and.callFake(async () => {
callOrder.push('getLastSeq');
return 1;
});
mockStateSnapshotService.getStateSnapshot.and.callFake((() => {
callOrder.push('getStateSnapshot');
return MEANINGFUL_SNAPSHOT_STATE;
}) as any);
mockVectorClockService.getCurrentVectorClock.and.resolveTo({});
mockOpLogStore.saveStateCache.and.resolveTo(undefined);
await service.saveCurrentStateAsSnapshot();
// All operations should happen between lock-start and lock-end
const lockStartIndex = callOrder.indexOf('lock-start');
const lockEndIndex = callOrder.indexOf('lock-end');
expect(callOrder.indexOf('getLastSeq')).toBeGreaterThan(lockStartIndex);
expect(callOrder.indexOf('getLastSeq')).toBeLessThan(lockEndIndex);
expect(callOrder.indexOf('getStateSnapshot')).toBeGreaterThan(lockStartIndex);
expect(callOrder.indexOf('getStateSnapshot')).toBeLessThan(lockEndIndex);
// Key invariant: lastSeq is read BEFORE state snapshot
expect(callOrder.indexOf('getLastSeq')).toBeLessThan(
callOrder.indexOf('getStateSnapshot'),
);
});
it('should catch lock errors without throwing (hydration must not fail)', async () => {
mockLockService.request.and.rejectWith(new Error('Lock timeout'));
// Should not throw — errors are caught internally
await expectAsync(service.saveCurrentStateAsSnapshot()).toBeResolved();
});
});
describe('migrateSnapshotWithBackup', () => {
const createSnapshot = (): MigratableStateCache => ({
state: { task: {}, project: {}, globalConfig: {} },

View file

@ -13,6 +13,8 @@ import { CLIENT_ID_PROVIDER, ClientIdProvider } from '../util/client-id.provider
import { limitVectorClockSize } from '../../core/util/vector-clock';
import { ValidateStateService } from '../validation/validate-state.service';
import { hasMeaningfulStateData } from '../validation/has-meaningful-state-data.util';
import { LockService } from '../sync/lock.service';
import { LOCK_NAMES } from '../core/operation-log.const';
type StateCache = MigratableStateCache;
@ -35,6 +37,7 @@ export class OperationLogSnapshotService {
private schemaMigrationService = inject(SchemaMigrationService);
private validateStateService = inject(ValidateStateService);
private clientIdProvider: ClientIdProvider = inject(CLIENT_ID_PROVIDER);
private lockService = inject(LockService);
/**
* Validates that a snapshot has the expected structure and data.
@ -78,53 +81,72 @@ export class OperationLogSnapshotService {
/**
* Saves the current NgRx state as a snapshot for faster future loads.
* Called after replaying many operations to optimize next startup.
*
* Wrapped in OPERATION_LOG lock to prevent a lost-update window: without
* the lock, an op appended between reading NgRx state and reading lastSeq
* would get a seq <= lastAppliedOpSeq but its effect would be absent from
* the snapshot. On next hydration the tail replay would start after that
* seq, silently skipping the op forever.
*
* Additionally, lastSeq is read BEFORE the state snapshot so the worst
* interleaving degrades to re-replay rather than a missed op. Most op types
* are idempotent on re-replay (entity-adapter CRUD/move/reorder), but some
* persistent ops accumulate onto current state and double-apply on re-replay
* (e.g. time-tracking/counter deltas and the plain-append branches of project
* task moves). This edge is unlikely (the save runs only during hydration) and
* strictly better than op-loss. The audited op list and a truly-lossless
* capture (quiesce the op-write queue before reading) are tracked in #8469.
*/
async saveCurrentStateAsSnapshot(): Promise<void> {
try {
// Get current state from NgRx
const currentState = this.stateSnapshotService.getStateSnapshot();
await this.lockService.request(LOCK_NAMES.OPERATION_LOG, async () => {
// Read lastSeq BEFORE state snapshot — see JSDoc above.
// NOTE: compaction reads in the opposite order (state, then lastSeq);
// its failure mode if the lock is bypassed is missed-op data loss.
const lastSeq = await this.opLogStore.getLastSeq();
const currentState = this.stateSnapshotService.getStateSnapshot();
// GUARD (#7892): never cache an empty/degraded state over a good one.
// The snapshot is only a load-time cache — the op-log is the source of
// truth. If the live NgRx state has no user data (e.g. a transient
// hydration glitch left the store in its initial empty state), caching it
// would make the next boot trust empty data. Skipping the save is always
// safe for correctness: replaying the op-log reconstructs the true state
// (including legitimate full-wipe deletes), at most costing a slower boot.
if (!hasMeaningfulStateData(currentState)) {
OpLog.warn(
'OperationLogSnapshotService: Skipping snapshot save — current state has no ' +
'meaningful data (refusing to overwrite cache with empty state)',
);
return;
}
// GUARD (#7892): never cache an empty/degraded state over a good one.
// The snapshot is only a load-time cache — the op-log is the source of
// truth. If the live NgRx state has no user data (e.g. a transient
// hydration glitch left the store in its initial empty state), caching it
// would make the next boot trust empty data. Skipping the save is always
// safe for correctness: replaying the op-log reconstructs the true state
// (including legitimate full-wipe deletes), at most costing a slower boot.
if (!hasMeaningfulStateData(currentState)) {
OpLog.warn(
'OperationLogSnapshotService: Skipping snapshot save — current state has no ' +
'meaningful data (refusing to overwrite cache with empty state)',
);
return;
}
// Get current vector clock and last seq
const vectorClock = await this.vectorClockService.getCurrentVectorClock();
const lastSeq = await this.opLogStore.getLastSeq();
// Get current vector clock
const vectorClock = await this.vectorClockService.getCurrentVectorClock();
// Prune vector clock before persisting to prevent bloat (max 20 entries).
// Without this, clocks can grow unbounded across sync cycles and cause
// repeated conflict dialogs on every sync.
const clientId = await this.clientIdProvider.loadClientId();
const prunedClock = clientId
? limitVectorClockSize(vectorClock, clientId)
: vectorClock;
// Prune vector clock before persisting to prevent bloat (max 20 entries).
// Without this, clocks can grow unbounded across sync cycles and cause
// repeated conflict dialogs on every sync.
const clientId = await this.clientIdProvider.loadClientId();
const prunedClock = clientId
? limitVectorClockSize(vectorClock, clientId)
: vectorClock;
// Extract entity keys for conflict detection after compaction
const snapshotEntityKeys = extractEntityKeysFromState(currentState);
// Extract entity keys for conflict detection after compaction
const snapshotEntityKeys = extractEntityKeysFromState(currentState);
// Save snapshot
await this.opLogStore.saveStateCache({
state: currentState,
lastAppliedOpSeq: lastSeq,
vectorClock: prunedClock,
compactedAt: Date.now(),
schemaVersion: CURRENT_SCHEMA_VERSION,
snapshotEntityKeys,
// Save snapshot
await this.opLogStore.saveStateCache({
state: currentState,
lastAppliedOpSeq: lastSeq,
vectorClock: prunedClock,
compactedAt: Date.now(),
schemaVersion: CURRENT_SCHEMA_VERSION,
snapshotEntityKeys,
});
OpLog.normal('OperationLogSnapshotService: Saved new snapshot');
});
OpLog.normal('OperationLogSnapshotService: Saved new snapshot');
} catch (e) {
// Don't fail hydration if snapshot save fails
OpLog.warn('OperationLogSnapshotService: Failed to save snapshot', e);