Background
This comes out of a PowerSync support case: a customer running Service 1.22.0 with a MySQL source and MongoDB bucket storage reported replication lag on a quiet test instance that never recovered on its own. Waiting did nothing, compaction did nothing, and only restarting the service cleared it. We root-caused it from their logs, then reproduced it in our support workbench against the pinned journeyapps/powersync-service:1.22.0 image, and verified the code is unchanged on current main.
Symptom
On an idle server (no writes arriving), the service logs this every ~30 seconds, indefinitely:
INF [powersync_1_429d] Waiting before creating checkpoint, currently at
0000000039489899|2e35321d-...:39489899|mysql-bin.000027|565835613 / 0.
Current state: {"snapshot_done":true,
"last_checkpoint_lsn":"0000000039489899|2e35321d-...:39489899|mysql-bin.000027|565836177", ...}
Note the signature: the current LSN and last_checkpoint_lsn share the same padded transaction id (39489899), but the current binlog offset (565835613) is behind the checkpoint offset (565836177).
Root cause
MySQL LSNs are strings compared lexicographically (for example canCheckpointState in modules/module-mongodb-storage/src/storage/implementation/CheckpointState.ts, which requires lastCheckpointLsn <= lsn). In modules/module-mysql/src/replication/zongji/BinLogListener.ts:
- The GTID event handler builds
currentGTID with the position of the GTID event, i.e. the start of the transaction.
- The Xid handler builds the commit LSN from
evt.nextPosition, i.e. the end of the transaction. That LSN becomes last_checkpoint_lsn.
- Heartbeat keepalives re-send
currentGTID.comparable, the stale start-of-transaction LSN.
So the moment the last transaction commits on a quiet server, every subsequent heartbeat presents an LSN that sorts below the stored checkpoint, and checkpoint creation is blocked until the next real transaction arrives. The same applies to the DDL auto-commit and non-transactional query commit paths in processQueryEvent.
Reproduction
Fully scripted in our workbench; the minimal manual version:
- Start the service (1.22.0 or main) with a MySQL source, let the snapshot complete
- Commit one transaction, then leave the server idle
- From the first heartbeat (~30s,
KEEPALIVE_INACTIVITY_THRESHOLD = 30) onward, the service logs Waiting before creating checkpoint with the same transaction id and a smaller binlog offset than last_checkpoint_lsn
- A single new write unblocks it immediately
In our repro the commit stored offset 607 while every idle keepalive re-sent offset 276 for the same transaction, matching the customer's log pattern digit-for-digit at their offsets.
Impact
- Blocked (empty) checkpoints and log spam on idle instances
- Confusing for operators: it presents as stuck replication lag on quiet instances, and in this customer's case led to an unnecessary bucket storage volume deletion
- The replication lag metric itself stays at 0 in this state (the last commit succeeded), so the noise is worse than the harm, but the checkpoint gate is genuinely closed until the next write
A fix PR follows shortly: all commit paths now advance currentGTID to the commit position, so keepalive LSNs are never behind the last checkpoint LSN.
🤖 AI disclosure: this issue was generated by Claude (via Claude Code). The investigation, reproduction, and write-up were produced by Claude working from the customer's logs, directed and reviewed by @michaelbarnes.
Background
This comes out of a PowerSync support case: a customer running Service 1.22.0 with a MySQL source and MongoDB bucket storage reported replication lag on a quiet test instance that never recovered on its own. Waiting did nothing, compaction did nothing, and only restarting the service cleared it. We root-caused it from their logs, then reproduced it in our support workbench against the pinned
journeyapps/powersync-service:1.22.0image, and verified the code is unchanged on currentmain.Symptom
On an idle server (no writes arriving), the service logs this every ~30 seconds, indefinitely:
Note the signature: the current LSN and
last_checkpoint_lsnshare the same padded transaction id (39489899), but the current binlog offset (565835613) is behind the checkpoint offset (565836177).Root cause
MySQL LSNs are strings compared lexicographically (for example
canCheckpointStateinmodules/module-mongodb-storage/src/storage/implementation/CheckpointState.ts, which requireslastCheckpointLsn <= lsn). Inmodules/module-mysql/src/replication/zongji/BinLogListener.ts:currentGTIDwith the position of the GTID event, i.e. the start of the transaction.evt.nextPosition, i.e. the end of the transaction. That LSN becomeslast_checkpoint_lsn.currentGTID.comparable, the stale start-of-transaction LSN.So the moment the last transaction commits on a quiet server, every subsequent heartbeat presents an LSN that sorts below the stored checkpoint, and checkpoint creation is blocked until the next real transaction arrives. The same applies to the DDL auto-commit and non-transactional query commit paths in
processQueryEvent.Reproduction
Fully scripted in our workbench; the minimal manual version:
KEEPALIVE_INACTIVITY_THRESHOLD = 30) onward, the service logsWaiting before creating checkpointwith the same transaction id and a smaller binlog offset thanlast_checkpoint_lsnIn our repro the commit stored offset 607 while every idle keepalive re-sent offset 276 for the same transaction, matching the customer's log pattern digit-for-digit at their offsets.
Impact
A fix PR follows shortly: all commit paths now advance
currentGTIDto the commit position, so keepalive LSNs are never behind the last checkpoint LSN.🤖 AI disclosure: this issue was generated by Claude (via Claude Code). The investigation, reproduction, and write-up were produced by Claude working from the customer's logs, directed and reviewed by @michaelbarnes.