Repository navigation
Engine checks, the bugs they found, and one value per key in memdb - #51
Merged
Merged
Conversation
A job runs every package but the end-to-end tests under -race, which takes about a minute and a half. At least ten of the engine's fixes were races, found by chance or by a test failing one run in hundreds. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
DB.Verify checks the state memdb keeps besides its records: a block in use is not freed, each record points at its entry, a block's count is its records not deleted, and the time filters name the blocks holding their keys. A model test runs random puts, deletes, batches, flushes, sleeps and reopens against a map of each key's versions, and checks Get, Size and Verify after each. Run on master, Verify finds the count fixed in #50 within ten operations. The model found: - An aborted batch kept its entries: Get found them until a reopen. Abort released only the logs written, not the block put to; and every committed batch left the empty block it opened after its write, with a buffer of the pool. - Every time block was kept: rotation left an empty one each block duration, each with a buffer of the pool, and nothing released it. The commit loop now releases a past block with no entries once its data is in the WAL. - A deleted version came back on the reopen after next. Releasing a block marked its logs applied, and they held the deletes of versions in older blocks still in the WAL. Delete meant to move those first, but read offsets as time IDs. A block's logs now stay until the logs of the blocks it deletes from have gone, which recovery rebuilds. - Recovery put a batch's log in the block of its time truncated, so a delete naming the batch's block found nothing, or deleted a version of the second's block. The WAL header (version 3) records the log's block, and recovery puts the log back in it; a log from before goes where it went. - A reopen within a block duration wrote the recovered entries to the WAL again, deleted ones as puts: the recovered block's data was taken as not written yet. - A put deleted before it reached the WAL reached it marked deleted. Recovery took it for a delete and read its value as a time ID; a value under 8 bytes at the end of a log panicked, and the DB did not open. Delete leaves the put as written; recovery skips such a put in WALs written before. - Two logs of one microsecond were written to one file, the second replacing the first: a log's file is named by its time, and macOS clocks tick in microseconds. Log IDs are now unique, and a batch's block is never named as a time's block. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
DB.Verify checks the state the DB keeps besides its entries: checksums; each index entry in its block, once, under the DB's sequence and in the filter; Count; each topic's window blocks linked to older blocks of the topic, named in the trie and pointed at by it; every live entry in a window block; and the memdb's own Verify. A model test runs random puts, deletes, batches, syncs, flushes, sleeps and reopens against a map of each topic's messages; a crash variant kills a child process at random and checks every message a Flush or Batch made durable is back, no deleted one is, and the rest are in order. They found: - A topic's messages were all lost on reopen when its first entry, which holds its name, reached disk after another of the topic, as a batch's does after a Put of the same second: open read the name from the oldest window entry only. It now searches the topic's blocks; a topic no entry on disk names yet is kept, and joins the trie, at its blocks, once an entry names it. - Recovery held back the window entries of a topic named by a later block, then didn't write them: the entries were in the index and no query found them. - Deleting a topic's first entry before a sync waited in memory for the entry to reach disk, and a crash lost the delete, even after a Flush. The entry is now replaced in memory by its tombstone, as the index keeps a deleted entry holding its topic; it reaches the WAL as a put does, in one log with the delete (memdb's new Replace). The deletes that waited, and Close's wait for them, are gone. - A batch's entries were lost in a crash when a Put not yet in the WAL had named their topic: a batch reaches the WAL as it commits, before earlier Puts may. A batch's first entry of each topic now holds the topic's name too. - Batch.Write dropped the error of its writes, and reported success. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
Fuzz targets read bytes a bug or a bad disk could leave, with valid checksums where the format has them: WAL logs (FuzzReadLog), memdb recovery from them (FuzzRecovery, which also wants a DB that opens to pass Verify), the engine's blocks and records (FuzzDecode, which also wants a block to decode as it encodes), and a DB with a file overwritten and its checksums put back (FuzzOpenCorrupt). CI fuzzes each for half a minute; inputs that failed are kept under testdata and run by go test. They, and tests of what they pointed at, found: - The WAL reader trusted each record's length: one shorter than its prefix, or past the log, panicked; and a log of no data panicked in the buffer pool. - memdb recovery parsed entries with no bounds: a short or overlong entry panicked, and the DB did not open. It now reports the log corrupt (wal.ErrCorrupted), which the engine reports as corrupted. - Topic.Unmarshal panicked on a topic name cut short. - A corrupt value size made reading a message allocate up to 4GB before finding the data file shorter, which Open does checking every message: a 2GB size took 2GB. A large read is now checked against the file. - A free list holding the space of stored messages, as a bug freeing the wrong block would leave it, gave that space to new messages, which overwrote the stored ones. Open now drops the free blocks that overlap a stored message or run past the data file. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
timeMark.add set a block's count of logs to write to one, whatever it was: a block written in two logs, as after a Flush, counted as written with the first, and the engine's sync could take it before the second. add now counts, and a block written to again is not done until that log is. A log is counted done when its write fails too, or its block would never be synced; its entries are in memory either way. All listed the blocks counted done, and so missed a recovered block the live tiny log writes to after a reopen within its block duration. It lists the blocks recovery made. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
Count was kept in the info file, written apart from the entries it counts: a delete writes its tombstone, then the count without the entry, and a crash between the two left Count one high for good. The model's crash test found it, two runs in sixty. Open now sets Count from the index, which it reads checking checksums already, and the recovery counts only the entries it writes. With background expiry, which uncounts the entries it frees and leaves them in the index, the count kept is kept, and the recovery still counts the entries of the block a sync was writing. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
The adapter deletes every version of a message key, as memdb deletes the newest only. It returned nil after 64 deletes with versions left, and on any error of the Get it checked with, such as the store closed: the caller took the key for deleted, and a get still found it. It now deletes until memdb reports the key not found (memdb.ErrNotFound, now exported), and returns any other error, or one for versions left. The adapter's calls after Close dereferenced the closed stores and panicked; they now return an error. Close returned the second store's error over the first's. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
The lock order lived in commit messages: a deadlock between Put and Size, Keys or releaseLog was each fixed on its own. memdb/locks.go now gives its locks their order, and its mutexes their rank in it; built with the lockcheck tag (internal/lockcheck), taking one out of order panics, in any test that runs the path once. CI's race job sets the tag. db.go gives the engine's order. The check found recovery holding db.mu for reading throughout, and taking the locks below it; it also wrote the map of time blocks under it. Recovery runs before any other goroutine has the DB, and takes none. Writing the order down found a deadlock the check can't: rotation holds the log manager's lock sending a log to the write queue, which only the commit loop drains, and the commit loop now reads the current time ID (releaseEmpty), which took that lock. The current time ID is now read without one. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
…bytes format.go lays out each file and record the engine writes, with what zero means in each, and gives the info header, index block and window block their field offsets, which the encoders and decoders now take: the encryption flag was written at one offset and read at another. memdb and the WAL lay out theirs at their encoders. TestFormat encodes known values of each format and compares them with saved bytes (testdata/format), decodes the bytes back, and reads fields at their offsets written out in the test, so that moving one fails it; a deliberate change rewrites the bytes with -update-format. Format 2's info header, and version 1 of the WAL's, are built from their layouts and read. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
memdb's recovery kept its own copy of what Put, Batch and Delete do to the blocks, and it differed: it applied a log's puts after its deletes, rebuilt a block's data without its deletes, kept its own delete, and set the time filters itself. The fixes to it this week were each such a difference. The changes to the blocks are now putEntry and deleteEntry, which the writes make, and which recovery makes again, entry by entry of the WAL in the order written; recovered blocks hold what they held. The engine's recovery kept a copy of Sync's loop over a memdb block. Both now write a block with syncBlock: recovery's extras, the sequence advanced, topics named by their entries, the window entries of a topic named later held back, are harmless to Sync, and Sync writes what it holds back too (writePending). Counting the entries a stopped sync had written stays recovery's, and only without a recount. The model and race tests of this found: - Sync failed when a key was deleted between listing a memdb block's keys and reading it, and its abort then uncounted entries it had not counted: Count fell below the entries stored. - Delete appended its record to the current block without holding the rotation lock, as Put does: rotation could make the block past, and releaseEmpty free it, between. - Rotation enqueued a log before making the next current: the commit loop could write it while its block was current, and an empty block was then never released. - The background syncer panicked on a sync that failed, as one racing Close does with errClosed, and Close did not wait for it: it was counted done as it started. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
A block's life was in flags set in several places: released, walGone, and data freed. It is now one state, live, released, then gone, set by setState, which panics on any other step; free panics on a block freed already, which returned its buffer to the pool twice (29da7d8). Verify checks a block in use is live. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
A topic's name was packed into its first entry only, and four bugs this week were that entry's: deleted before a sync (f49a0ff, and then waiting in memory and lost in a crash), reaching disk after others of the topic, recovered after others, and lost in a crash with a batch's entries kept. Each fix made that entry matter less; the topics file makes it not matter: a topic's name is recorded there before its first entry is put, and entries no longer hold it. The record is written as the WAL is, to the OS and not synced: a process crash keeps both, and neither survives a power loss before a sync, which syncs the topics file with the other files. Syncing each record took milliseconds a topic. A topic of a hash named for another topic is refused: their entries were one topic's. Open reads names from the file first, and from entries for a DB written before it, recording those; the DB is then format 4, which older versions refuse. testdata/compat/v3 is a DB written by format 3, with topics named on disk, in the WAL, and by a deleted first entry, which TestOpenFormat3 opens. Verify checks the trie's topics are named. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
Count, the bloom filter and the sequence are kept apart from the entries they describe, and a crash between writing the two left them wrong: the count one high (fixed by recounting on open), the filter missing entries it must hold (208db2e), the sequence below a stored one (1905ee5). Open's pass over the index, which recounted, now makes the filter and raises the sequence too; the filter file is still saved, for older versions. In memdb, a block's count is changed by put and delete only, since recovery replays through them. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
A key had a version in each time block it was put in: Get returned the newest block's, by time ID rather than by when it was put, and Delete deleted that one, the one before then reading again. Callers deleted every version before each put (the server's adapter up to 64 of them), and a store that wrote tombstones instead never emptied a block, so kept every block, and every log of the WAL: one such store piled up 85,698 logs in a day, and a Get took 6ms, scanning 11,576 blocks. An index now gives the block holding each key's value. Put replaces the value: one in another block is deleted first, and the delete written to the WAL, as Delete writes it; one in the same block is replaced. Delete deletes the key. Get and Delete look the key up, and the time filters they scanned are gone. Keys and Size count keys. Replace is Put. A batch's values are its keys' once it is written, not before: an aborted batch leaves the values it would have replaced. Writing it deletes the values it replaces, with the deletes in its own log, and writes the current tiny log first, holding off puts: recovery replays logs in the order written, and a batch's log, written as it commits, went before the current block's tail, which may hold an earlier put of the same key. Recovery keeps the index as it replays; a WAL from before, with a key's versions in several blocks, recovers its last. The jammed store's writes, replayed with deletes for its tombstones, leave 307 logs, and a Get takes under a microsecond. The server's adapter puts and deletes once. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
The lockcheck tag reads a stack trace on every lock memdb takes, and the server's tests, under the race detector too, ran past their timeouts: TestRevoke waited 5s for a connect acknowledgement. memdb's and the engine's tests drive memdb's paths; the server's run under the race detector alone. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
# Conflicts: # server/internal/db/unitdb/adapter.go
The fuzzer, in CI, found a log whose header says its data is 4GB: the reader extended a buffer to that size before reading the file, and its workers stalled. The size is now checked against the file first, and a log past it is corrupt. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
A CONNECT refused for an invalid or v1 client id queued its CONNACK, and the new client id, for the write loop, and returned the error that closes the connection: the close could stop the write loop before it wrote them, and the client saw the connection close with no answer. TestConnectRejectsForgedClientID failed so under the race detector in CI. They are now written before the handler returns, under a lock the write loop takes for its writes too. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Checks for the engine and memdb, the bugs they found, and the design changes that prevent their kind. Each commit says what it fixes and how it was found; this is the summary.
Checks
-tags lockcheck).Verify()onunitdb.DBandmemdb.DB: the state kept besides the data (counts, filter, sequence, window chains, the trie and topics file, memdb's blocks and index) agrees with the data.testdata/format), and a DB written by format 3 (testdata/compat/v3).Bugs fixed (reachable on master)
Flush.Countdrifted after a crash during a delete, or a delete during a sync.Closedidn't wait for it.Design changes
Sync's block writer (engine).Gettaking 6 ms. Its writes, replayed with this branch, leave 307 logs, withGetunder a microsecond.Breaking
Getreturns the last value written,Deletedeletes the key,KeysandSizecount keys,Lookup(timeID, key)finds only a key's current value, and a batch's values apply when it's written. The engine is unaffected: its keys are never put twice.Not in this PR
Includes #50's commit.
🤖 Generated with Claude Code