Repository navigation
fix(engine): power-loss crash tests and the five durability bugs they found - #98
Merged
Merged
Conversation
…power Every file the engine writes or syncs is now opened through FileHandle.channel, and memory-mapped files are forced through FileHandle.force. Both go through FileHandle.channels, a package-private static that defaults to FileChannel::open and only tests replace. The catalog, the reference journal and the WAL and feed directory syncs used FileChannel.open directly; CatalogStore and ReferenceJournal now share FileHandle.syncDirectory instead of their own copies. PowerLoss, a test helper, installs itself there for one directory. It records every write, truncation and force per file, every force of a mapping (pages.dir, pages.ref) and of a directory, can throw at a chosen event, and then rewrites the directory as a power failure could leave it: only forced bytes, all bytes, the last unsynced write cut in half or with a flipped byte, or a random mix. Files created since their directory was last forced may vanish.
verifyFormat wrote FORMAT with Files.newOutputStream and never forced
it or the directory. A power loss soon after a database was created
could leave FORMAT empty while the WAL already held acknowledged
commits. The next open then read no format property, took it for
format 1 and refused the database ("uses storage format 1").
FORMAT is now written to FORMAT.tmp, forced, renamed over FORMAT and the
directory forced, as the catalog files already are. It happens once per
database.
Nothing ever forced data/segments. A new segment file, and pages.dir and pages.ref themselves, could vanish after a power loss even though their contents had been forced, because the directory entry was never made durable. With PAGE_REFERENCES a commit whose pages sat in such a segment was acknowledged after pages.sync and wal.sync, but after the power loss recovery found its pages missing and discarded it and every commit after it. SegmentFile.open now forces the directory when it creates the file, and MappedLongs does the same when it creates pages.dir or pages.ref. That is one directory sync per new segment (256 MiB by default) and two per database.
MappedLongs forces the header of a new pages.dir with only its magic and format. PageDirectory.open sets the next page number to 1 after that and the first checkpoint forces it. If the power went out in between, the directory came back with next number 0, which PageDirectory.allocate handed out, and every checkpoint from then on failed in PageId.pack with "page number out of range: 0". The database could no longer write a page. Page number 0 is never used, so open now reads a stored 0 as 1. That also repairs a directory already left in this state.
…load A feed frame is [length][crc32c of payload][generation][payload], so the CRC does not cover the length or the generation. When power was lost with unsynced feed frames, two things got past ChangeFeed.restore: * A run of zeros, where a frame never reached the disk but a later one did, reads as frames of length 0, CRC 0 and generation 0 (the CRC of an empty payload is 0). restore set lastGeneration back to 0, so recovery re-appended the Feed records of every replayed commit after events that were already there, and the feed listed those commits twice. * A damaged generation field passed the check. A frame of generation 3 came back as generation 5898243, recovery skipped the Feed records of the replayed commits as already present, and truncateAfter(3) then dropped the bad frame, so the event of commit 3, which had been acknowledged, was gone for good. FeedCodec always writes the generation first in the payload, which the CRC does cover. A frame is now valid only if its payload is not empty and starts with the header's generation, and restore stops at a frame that is not newer than the one before it. The file format is unchanged.
PowerLossTest runs a seeded workload of small commits, bulk loads that spill and write pages at commit, deletes, aborted transactions, checkpoints and compactions, for both durability levels and both WAL modes. It cuts the power at four random I/O events per configuration with a random tear of the unsynced writes, recovers, cuts the power again somewhere in recovery and the commit and checkpoint after it, and recovers again. Every time the surviving commits must be a prefix of the attempted ones, holding every acknowledged commit under sync and every checkpointed one under async, with no aborted work, one feed event per commit, the same prefix after both recoveries, and trees and reference counts that pass TreeVerifier and verifyReferences. Four smaller tests pin the cases from the issue: async commits after the last checkpoint are lost together, a Commit record cut in half or with a flipped byte loses only the unacknowledged commit, and a torn page discards its commit although the log records survived. -Dhstore.powerloss.seeds=N runs more seeds.
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
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.
Closes #62
CrashRecoveryTeststops the engine at aCrashPoint, but every byte written before that point stays on disk. That is a process crash. This branch adds tests for a power failure, where only what was forced is certain to survive, and fixes the five bugs they found.How the tests see the I/O
The engine now opens every file it writes or syncs through
FileHandle.channel, and forcespages.dirandpages.ref(memory-mapped) throughFileHandle.force. Both go throughFileHandle.channels, a package-private static that defaults toFileChannel::open. Nothing else changes in production: the catalog, the reference journal and the WAL and feed directory syncs used to callFileChannel.openthemselves, andCatalogStoreandReferenceJournalnow shareFileHandle.syncDirectoryinstead of keeping their own copies. The seam has to sit inFileHandlebecause the mapped files are written through memory, so a wrapped channel alone can't see when they reach the disk.PowerLoss(test sources,io.hstore.engine.page) replaceschannelsfor one directory. Per file it records every write, truncation andforce, every force of a mapping and every force of a directory. It can cut the power before any of these events (the call throwsPowerLoss.Cut; later I/O is no longer recorded), andrestorerewrites the directory as the disk could hold it:NOTHING: each file holds what its lastforcesawALL: every unsynced write kept, as after a process crashHALF_LAST: the last unsynced write of each file cut in half (a WAL record cut short, half a page)FLIP_LAST: one byte flipped in the middle of the last unsynced write, so its checksum failsRANDOM: per file a prefix, a random subset or all of the unsynced writes, some applied only in part; mapped files mix 4 KiB blocks from the last force and from the moment of the crash; sometimes one unsynced byte flippedA file created since its directory was last forced may vanish (always under
NOTHING). A file written without going throughFileHandlecomes back empty, unless it was renamed from a forced.tmpfile.PowerLossModelTestchecks these rules on plain files.The tests
PowerLossTest.powerCutsAtRandomEventsRecoverAPrefixOfTheCommitsruns a seeded workload forSYNC/ASYNCxPAGE_IMAGES/PAGE_REFERENCES: small commits appending a node to one ordered edge, bulk loads of 300 or 5,000 members (spilled pages, pages written at commit), deletes of earlier bulk edges, aborted transactions with and without spilled pages, checkpoints and compactions. A dry run counts the I/O events, then it cuts the power at four random events, each with a random tear. After restoring it opens the database, checks it, commits once more and checkpoints, with a second power cut somewhere in that sequence (recovery included), restores and checks again. Each check requires:SYNCevery acknowledged commit survived; underASYNCevery commit covered by a completed checkpointTreeVerifierover every tree andverifyReferences, the same checkshstore checkrunsOne commit may have been in flight when the power went; it is allowed to be there or not.
Smaller tests pin the four cases from the issue: async commits after the last checkpoint are lost together; a
Commitrecord cut in half or with a flipped byte loses only the unacknowledged commit; aPAGE_REFERENCEScommit whose page was torn is discarded although its log records survived.PowerLossTesttook 14 to 28 s andPowerLossModelTestunder 1 s in my last runs, on a laptop busy with other builds (load average 13 to 20).-Dhstore.powerloss.seeds=Nruns more seeds. Locally I also ran seeds 100 to 111 and 200 to 211 (8 cuts each, the second set with longer workloads) before the feed check existed, and seeds 300 to 311 with it, all passing after the fixes.Bugs found
FORMATcould come back empty (StorageEngine.verifyFormat). It was written withFiles.newOutputStreamand never forced. After a power loss shortly after creating a database,FORMATcould be empty while the WAL held acknowledged commits. The next open read no format, took it for format 1 and refused the database withuses storage format 1. Now it is written toFORMAT.tmp, forced, renamed and the directory forced. Test:aDatabaseCreatedJustBeforeAPowerLossStillOpens.data/segmentswas never forced (SegmentFile.open,MappedLongs.open). A new segment file, orpages.dirandpages.refthemselves, could disappear after a power loss even though their contents were forced. WithPAGE_REFERENCES, a commit acknowledged afterpages.sync()andwal.sync()lost its pages, and recovery discarded it and everything after it. Now the directory is forced when one of these files is created: once per new segment (256 MiB by default) and twice per database. Test:pagesInASegmentCreatedSinceTheLastCheckpointSurvive(fails forPAGE_REFERENCES;PAGE_IMAGESrewrites the pages from the log and passed already).pages.dircould keep next page number 0 (PageDirectory.open). A new directory's header is forced with only magic and format, and the next number is set to 1 after that, to be forced at the first checkpoint. A power cut in between left next number 0;allocatehanded out 0 and every checkpoint after that failed withpage number out of range: 0, so the database could no longer write pages. Number 0 is never used, so a stored 0 is now read as 1, which also repairs a directory already in that state. Test:aPageDirectoryWhoseFirstPageNumberWasNeverForcedStillHandsOutNumbers.Zeros in the feed read as frames (
ChangeFeed.restore,FrameReader). A feed frame is[length][crc32c of payload][generation][payload]; the CRC doesn't cover the header. Where an unsynced frame never reached the disk but a later one did, the zeros read as frames of length 0, CRC 0 (the CRC of an empty payload) and generation 0.restoresetlastGenerationback to 0, and recovery appended the events of every replayed commit again, so the feed listed acknowledged commits twice. Test:aZeroedFeedFrameBeforeASurvivingOneDoesNotRepeatEvents.A damaged feed generation hid real events (same code). A frame of generation 3 with one bad byte in its header came back as generation 5898243 and passed the CRC. Recovery skipped the
Feedrecords of the replayed commits as already present, thentruncateAfter(3)removed the bad frame, so the event of commit 3, which had been acknowledged, was gone from the feed. In the random suite the same thing dropped the events of two acknowledged commits. Test:aFeedFrameWhoseUnsyncedGenerationWasDamagedDoesNotHideCommittedEvents.For 4 and 5,
FeedCodecalready writes the generation first in the payload, which the CRC covers. A frame is now valid only if its payload is not empty and starts with the header's generation, andrestorestops at a frame that isn't newer than the one before it. Covering the header with the CRC would be cleaner but changes the feed format, so I left that alone.Each test failed before its fix and passes after it. None of the fixes changes a file format.
Not covered
Files.createDirectoriesare assumed durable, and a deleted file is assumed to stay deleted.PayloadStore,SemanticPlane) don't go throughFileHandleand are not modelled.Docs
docs/transactions/wal-and-recovery.mddescribes the power loss tests and the newFORMATwrite,docs/storage/pages.mdthe directory syncs and the next-number rule, anddocs/storage/change-feed.mdthe stricter frame check.