Tern Config Store: Crash Recovery, Checkpoints and Log Compaction

Tern: Crash Recovery for the Gateway Config Store

You've joined the platform-storage team that owns Tern, the tiny embedded key-value store inside the Heron edge-gateway firmware. Tern keeps device configuration in memory and makes it durable with a write-ahead log (WAL) on flash. Last week's lab power-pull test (INC-4417) turned up two problems: gateways rebooted with settings nobody had committed, and one gateway lost an update it had acknowledged after a second outage. Firmware freezes in three weeks, and the roadmap behind the incident is checkpoints, then log compaction, then making restarts fast on devices with very long histories.

Everything is simulated in memory: the "disk" is an object, a "crash" is an operation, and the log is a string.

Codebase

records.py, wal.py, memtable.py, txns.py and the operation checks in engine.py / api.py are believed correct. Read records.py first: its docstring is the on-disk format.

How your code is run

run(operations: list[list]) -> list executes the operations in order against a fresh store and returns one result per operation. Errors are returned as "error: <code>" strings, never raised. Check order for every operation: unknown name (unknown operation), argument count (invalid arguments), store is down (store is down), then the operation's own checks in the order listed below.

• Keys and values are strings of 1-32 characters from A-Z a-z 0-9 _ . : - (config.NAME_PATTERN); anything else (including non-strings) is invalid key / invalid value. A transaction id that is not an open transaction (never issued, committed, aborted, or lost in a crash) is unknown transaction.
• Transactions are concurrent and unlocked. put and delete are only logged (write-ahead) and buffered in the transaction; the committed state changes at commit, which applies that transaction's writes in the order they were made. Two transactions that write the same key: the one that commits last wins. get, count and dump only ever see committed state.
• Crashes. crash(keep) keeps only the first keep characters of the log (no effect if keep is at least the log size); crash_back(count) tears the last count characters off (the whole log if count is larger). Both can cut a record in half (a *torn write*), and both lose all memory: the committed state and every open transaction. The store is then down: every operation except crash, crash_back, flip, recover, log_size, log_text, master and recover_stats returns error: store is down. recover brings it back (it may also be called on a store that is up: a restart). flip(offset) damages one character of the log (bit rot, it becomes ~) and does not change whether the store is up.
• The log is a sequence of records, one per line: lsn|kind|tx|key|val|crc\n. Kinds B begin, P put, D delete, C commit, A abort get the next lsn (1, 2, 3, ...) as they are appended. crc is records.checksum of the five fields before it, four lowercase hex digits. See records.py for the exact layout and encode_record / decode_record for what *valid* means: a record counts only if it ends with its newline, has six fields, a canonical decimal lsn, a known kind and a matching checksum.

Worked example

[["begin"], ["put","t1","motd","hello"], ["put","t1","mode","eco"], ["commit","t1"],
 ["begin"], ["put","t2","mode","boost"],
 ["begin"], ["put","t3","fan","on"], ["commit","t3"],
 ["log_size"], ["crash_back",3], ["recover"], ["dump"], ["begin"]]

returns

["t1", true, true, true, "t2", true, "t3", true, true,
 156, 153, {"applied": 1, "losers": 2, "dropped": 11}, ["mode=eco", "motd=hello"], "t4"]

t3's commit record 9|C|t3|||xxxx\n lost its last three characters, so it never happened: only t1 committed (applied: 1), t2 and t3 are losers, and the 11 characters of the torn record are cut off the log.

Part 1: Make recovery correct (INC-4417)

Goal: after recover, the store holds exactly the transactions whose commit record fully reached the disk, and it keeps working correctly afterwards, including through the next crash.

The incident reports: (1) gateways came back with values from transactions that were never committed; (2) a gateway came back with garbage or a half-written value after a torn write; (3) after the first outage a gateway kept running and acknowledged new commits, and a second outage lost them; (4) transaction ids repeated after a reboot and merged unrelated writes after a later one.

Rules for recover (no checkpoints exist yet)

1. Read the log from the start. The log ends at the first record that is not valid: torn, damaged, or whose lsn is not exactly the previous lsn plus one (the first record must have lsn 1). Everything from there on, even later records that look fine, is discarded and physically removed from the disk. dropped is the number of characters removed (0 if nothing was cut).
2. Only committed transactions are applied: a transaction's writes are applied when its C record is reached, writes in the order they were made, transactions in the order of their C records. A transaction with an A record, or with no C/A record at all, is never applied. An A record concerns only its own transaction; scanning continues after it.
3. After recovery there are no open transactions (clients are gone), but records of unfinished transactions stay in the log. Transaction ids are never reused: the next id is one more than the highest id number that occurs in the surviving log (t1 if the log is empty).
4. The next lsn is the last surviving record's lsn plus one (1 if the log is empty).
5. The report: applied = committed transactions applied, losers = transactions with a B record in the surviving log and neither C nor A, dropped as above.
6. recover on a store with an intact log changes nothing and reports dropped: 0; calling it twice in a row gives the same state and the same applied/losers.

Part 2: Checkpoints (STO-731)

Goal: restart in time proportional to the *recent* history, by writing periodic snapshots of the committed state into the log and letting recovery start from the newest one that is intact.

["checkpoint"] (store must be up; no other errors) returns the lsn of the checkpoint's K record.

A checkpoint is a contiguous block of records, each with its own lsn, appended at the end of the log:

Only after the whole block is appended is (begin_offset, end_offset, lsn) appended to disk.master (end_offset is the offset just past the E record), and only the newest MASTER_RETAIN (see config.py) entries are kept. ["master"] returns the list as [[begin, end, lsn], ...], oldest first.

Recovery now works like this (replaces Part 1's "read from the start"; everything else in Part 1 still holds):

1. Walk disk.master newest first. An entry whose end_offset is larger than the log size is skipped without reading anything. Otherwise it is *usable* iff: a. a complete, valid block starts at begin_offset: a K record whose lsn equals the entry's lsn, exactly N S records, and an E record naming that lsn, all valid, with consecutive lsns, the block ending exactly at end_offset; and b. if K.val is a number smaller than begin_offset, then every record from that offset up to begin_offset is valid with consecutive lsns, ending exactly at begin_offset, the last lsn plus one equal to the K lsn. (Complete older checkpoint blocks inside that range are skipped as units.)
2. The first usable entry is the starting point; its S records are the starting state. If no entry is usable, start from the empty state at the beginning of the log (a full replay, as in Part 1). Nothing before the starting point's scan-start offset is read, so damage there is harmless.
3. Replay the transactions: read from the scan-start offset (K.val) through the block (skipped as a unit) and on to the end of the log, applying the Part 1 rules, with two differences: a commit whose lsn is below the checkpoint's lsn is already part of the snapshot and is not applied again (a transaction that was open at the checkpoint has its early records *before* the block and may commit after it, so those must still be read); and a complete checkpoint block met while scanning is skipped as a unit. A checkpoint block that is not complete (a torn tail or damage inside it) ends the log at its K record: the whole partial block is cut.
4. Cut the log to its last valid unit (dropped counts the characters cut), and remove from disk.master every entry newer than the starting point (all entries if none was usable).
5. Transaction ids: the next number is the larger of the starting K's tx field and one more than the highest id number among the transaction records read.
6. applied counts only commits applied in step 3; losers counts transactions without outcome among the records read.

Example

[["begin"], ["put","t1","a","1"], ["put","t1","b","2"], ["commit","t1"],
 ["begin"], ["put","t2","c","3"], ["checkpoint"], ["put","t2","a","9"], ["commit","t2"],
 ["begin"], ["put","t3","b","7"], ["commit","t3"],
 ["master"], ["crash_back",20], ["recover"], ["dump"], ["master"]]

returns

["t1", true, true, true, "t2", true, 7, true, true, "t3", true, true, [[90, 148, 7]], 207, {"applied": 1, "losers": 1, "dropped": 12}, ["a=9", "b=2", "c=3"], [[90, 148, 7]]]

The block written by checkpoint is 7|K|3|2|60|10eb, 8|S||a|1|0db7, 9|S||b|2|0dc6, 10|E||7||0dce. It was written while t2 was open, so K.val is 60, the offset of t2's B record. After crash_back 20 the log ends inside t3's P record. Recovery starts from the checkpoint (applied: 1: only t2's commit is above it, t1 is already in the snapshot), reads t2's put c from *before* the block and put a from after it, so t2 is applied whole; t3 is a loser and 12 torn characters are cut. master is unchanged.

Part 3: Log compaction (STO-802)

Requirements change. Flash is 4 MB and the log never shrinks. Ops wants ["compact"], and with it two earlier assumptions stop being true: a log no longer starts at lsn 1, and the log may no longer contain the history that explains the state.

["compact"] (store up) returns {"before": size, "after": size} and rewrites the log to a compacted image using this exact two-phase protocol. The disk's only atomic primitive is the rename of wal.tmp over wal (Disk.publish_tmp):

1. Build. Write the image to wal.tmp (Disk.write_tmp). The image is: a checkpoint block of the current committed state, whose K record takes the next lsn (continuing the numbering, never restarting it) and has K.val = ""; followed by every currently open transaction, in ascending id order, re-emitted as its B record then its P/D records in the order they were written, with the lsns following the block. Aborted and committed transactions are not copied.
2. Publish. Rename wal.tmp over wal, then replace disk.master by the single entry for the new block, (0, block_end_offset, K lsn). Offsets of the open transactions' B records change; the engine must keep its bookkeeping (their first_off, the next lsn) in step.

Crash points. ["compact", point] loses power at a point of the protocol (the store goes down, wal is left as the disk would have it) and returns "power loss": ["compact","tmp",n] after only the first n characters of the image reached wal.tmp (n >= 0, clipped to the image length), ["compact","written"] after wal.tmp is complete but before the rename, and ["compact","renamed"] after the rename but before the master list was rewritten. Any other argument list is invalid arguments.

Recovery rules that change or are added

1. recover always deletes wal.tmp and never reads it: only the rename publishes a compaction, so a crash before it leaves the old log fully intact, even if wal.tmp looks complete.
2. The first record of a log may have any lsn (it is the previous numbering's continuation); only *consecutive* lsns are checked. After a cut of an empty log the next lsn is 1.
3. When no master entry is usable and the log starts with a checkpoint block at offset 0, that block is the base image: if complete, its entries are the starting state, its K.tx is the starting next transaction number, and replay continues after it (commits with a lsn above its K apply). If that first block is incomplete, the log is cut to empty. (This is how a crash at "renamed" recovers: the stale master entries are rejected by the usability checks of Part 2.)
4. All Part 1 and Part 2 behaviour still holds, including on compacted logs: transaction ids and lsns continue, and a transaction that was open during compaction can still commit afterwards, and survive a crash.

Example

[["begin"], ["put","t1","a","1"], ["commit","t1"], ["begin"], ["put","t2","b","2"], ["abort","t2"],
 ["begin"], ["put","t3","c","3"], ["compact"], ["commit","t3"], ["log_text"], ["crash_back",0], ["recover"], ["dump"]]

returns

["t1", true, true, "t2", true, true, "t3", true, {"before": 118, "after": 75}, true,
 "9|K|4|1||0d25\n10|S||a|1|10e5\n11|E||9||0dde\n12|B|t3|||11d6\n13|P|t3|c|3|1838\n14|C|t3|||11de\n",
 90, {"applied": 1, "losers": 0, "dropped": 0}, ["a=1", "c=3"], "t4", [[0, 43, 9]]]

Before the compaction the log held lsns 1-8. The image is the checkpoint block at lsns 9-11 (K.tx is 4: the next id would be t4; one key, a=1; K.val empty) followed by the open t3 re-emitted as B and P with lsns 12 and 13. Committed t1 and aborted t2 are gone. t3 then commits with lsn 14. Recovery starts from the single master entry [0, 43, 9], applies t3's commit (applied: 1) and ids continue at t4.

Part 4: Long histories (OPS-95)

Goal: soak rigs run gateways for months: tens of thousands of transactions, a checkpoint every few hundred, and a crash every so often. Operations reports that a restart reads far more of the log than the checkpoint should require. Make recovery's work proportional to the newest usable checkpoint plus the log after it, prove it with a counter, and keep loading fast. The whole test suite runs in a few seconds in the browser sandbox.

1. ["bulk", n, keyspace, checkpoint_every] (the optional third argument, default 0) behaves as documented in Dispatcher.bulk. It is a loader built on the normal engine operations, so it exercises the same code paths (and costs) as ordinary commits and checkpoints.
2. ["recover_stats"] (allowed while down) reports the work of the most recent recover as {"records_read": r, "checkpoint_lsn": l}. records_read counts every attempt to decode one record, whether it succeeds or fails, in the order of the recovery procedure:

• for each master entry that is not skipped, newest first: the K record, then its S records and E record (stopping at the first failure); if that block is usable so far and K.val demands a scan-start range, then the records of that range, in order (stopping at the first failure);
• then the records after the starting point's block, up to and including the first one that fails to decode (no attempt is made, so none is counted, when the walk ends exactly at the end of the log);
• a complete older checkpoint block met while walking costs one attempt per record in it;
• the starting block itself is read once, not again when the walk passes it. When there is no usable entry and the log starts with a base image (Part 3), that block is read once, as the first thing of the walk.

checkpoint_lsn is the lsn of the K record the recovery started from (a base image counts), or null for a full replay. Before any recover the answer is {"records_read": 0, "checkpoint_lsn": null}.

1. Recovery must not read anything before the starting point's scan-start offset, and must not touch master entries older than the first usable one. Decoding the whole log "just to be safe" is a Part 2 mistake, not a feature.
2. Loading must stay fast: tens of thousands of transactions via bulk, then many crash/recover cycles, must fit comfortably in the time budget. Measure before changing code.

Example

[["recover_stats"],
 ["begin"], ["put","t1","a","1"], ["commit","t1"], ["checkpoint"],
 ["begin"], ["put","t2","b","2"], ["commit","t2"], ["checkpoint"],
 ["begin"], ["put","t3","c","3"], ["commit","t3"],
 ["master"], ["crash_back",30], ["recover"], ["recover_stats"], ["dump"]]

returns

[{"records_read": 0, "checkpoint_lsn": null},
 "t1", true, true, 4, "t2", true, true, 10, "t3", true, true,
 [[44, 85, 4], [129, 189, 10]], 206, {"applied": 0, "losers": 1, "dropped": 2},
 {"records_read": 6, "checkpoint_lsn": 10}, ["a=1", "b=2"]]

The log was 236 characters; 30 were torn off, so both checkpoints are intact. Recovery reads the newest one (K, two S, E: 4 attempts), then t3's B record, then the torn P record, which fails (2 more): 6.

Notes

• You may use the AI assistant freely; you are expected to verify what it produces.
• Later Parts must not break earlier ones; hidden tests re-check earlier behaviour after later Parts.
• tests/ has example unit tests; add your own around the rules above, especially torn writes at every record boundary.