Ensure writes to WAL tail during `FlushWAL(true /* sync */)` will be synced #10560

ajkr · 2022-08-23T21:31:15Z

WAL append and switch can both happen between FlushWAL(true /* sync */)'s sync operations and its call to MarkLogsSynced(). We permit this since locks need to be released for the sync operations. Such an appended/switched WAL is both inactive and incompletely synced at the time MarkLogsSynced() processes it.

Prior to this PR, MarkLogsSynced() assumed all inactive WALs were fully synced and removed them from consideration for future syncs. That was wrong in the scenario described above and led to the latest append(s) never being synced. This PR changes MarkLogsSynced() to only remove inactive WALs from consideration for which all flushed data has been synced.

Test Plan: repro unit test for the scenario described above. Without this PR, it fails on "key2" not found

facebook-github-bot · 2022-08-23T21:32:48Z

@ajkr has imported this pull request. If you are a Meta employee, you can view this diff on Phabricator.

facebook-github-bot · 2022-08-24T05:27:09Z

@ajkr has updated the pull request. You must reimport the pull request before landing.

facebook-github-bot · 2022-08-24T05:45:10Z

@ajkr has imported this pull request. If you are a Meta employee, you can view this diff on Phabricator.

facebook-github-bot · 2022-08-24T22:44:14Z

@ajkr has updated the pull request. You must reimport the pull request before landing.

facebook-github-bot · 2022-08-24T22:44:32Z

@ajkr has imported this pull request. If you are a Meta employee, you can view this diff on Phabricator.

facebook-github-bot · 2022-08-24T22:45:19Z

@ajkr has updated the pull request. You must reimport the pull request before landing.

facebook-github-bot · 2022-08-24T22:45:39Z

@ajkr has imported this pull request. If you are a Meta employee, you can view this diff on Phabricator.

riversand963 · 2022-08-25T18:08:23Z

db/db_impl/db_impl.cc

      if (immutable_db_options_.track_and_verify_wals_in_manifest &&
          wal.GetPreSyncSize() > 0) {
        synced_wals->AddWal(wal.number, WalMetadata(wal.GetPreSyncSize()));
      }
-      logs_to_free_.push_back(wal.ReleaseWriter());
-      it = logs_.erase(it);
+      if (wal.GetPreSyncSize() == wal.writer->file()->GetFlushedSize()) {


Can we add an assertion as below?

if (wal.GetPreSyncSize() == wal.writer->file()->GetFlushedSize()) { // Fully synced logs_to_free_.push_back(wal.ReleaseWriter()); it = logs_.erase(it); } else if (wal.GetPreSyncSize() < wal.writer->file()->GetFlushedSize()) { wal.FinishSync(); ++it; } else { assert(false); }

Done, though slightly differently as that gives me fear of infinite loop

@ajkr It might be noob question. How is it ensured that no other thread is writing to this wal file at this point.

It looks like wal.number < logs_.back().number tells us the log is inactive because a newer one exists, and we only append to the newest (active) WAL.

ajkr

Thanks for the review!

ajkr · 2022-08-25T18:50:42Z

db/db_impl/db_impl.cc

      if (immutable_db_options_.track_and_verify_wals_in_manifest &&
          wal.GetPreSyncSize() > 0) {
        synced_wals->AddWal(wal.number, WalMetadata(wal.GetPreSyncSize()));
      }
-      logs_to_free_.push_back(wal.ReleaseWriter());
-      it = logs_.erase(it);
+      if (wal.GetPreSyncSize() == wal.writer->file()->GetFlushedSize()) {


Done, though slightly differently as that gives me fear of infinite loop

facebook-github-bot · 2022-08-25T18:51:37Z

@ajkr has updated the pull request. You must reimport the pull request before landing.

facebook-github-bot · 2022-08-25T18:53:00Z

@ajkr has imported this pull request. If you are a Meta employee, you can view this diff on Phabricator.

…synced (facebook#10560) Summary: WAL append and switch can both happen between `FlushWAL(true /* sync */)`'s sync operations and its call to `MarkLogsSynced()`. We permit this since locks need to be released for the sync operations. Such an appended/switched WAL is both inactive and incompletely synced at the time `MarkLogsSynced()` processes it. Prior to this PR, `MarkLogsSynced()` assumed all inactive WALs were fully synced and removed them from consideration for future syncs. That was wrong in the scenario described above and led to the latest append(s) never being synced. This PR changes `MarkLogsSynced()` to only remove inactive WALs from consideration for which all flushed data has been synced. Pull Request resolved: facebook#10560 Test Plan: repro unit test for the scenario described above. Without this PR, it fails on "key2" not found Reviewed By: riversand963 Differential Revision: D38957391 Pulled By: ajkr fbshipit-source-id: da77175eba97ff251a4219b227b3bb2d4843ed26

…synced (facebook#10560) (#357) Summary: WAL append and switch can both happen between `FlushWAL(true /* sync */)`'s sync operations and its call to `MarkLogsSynced()`. We permit this since locks need to be released for the sync operations. Such an appended/switched WAL is both inactive and incompletely synced at the time `MarkLogsSynced()` processes it. Prior to this PR, `MarkLogsSynced()` assumed all inactive WALs were fully synced and removed them from consideration for future syncs. That was wrong in the scenario described above and led to the latest append(s) never being synced. This PR changes `MarkLogsSynced()` to only remove inactive WALs from consideration for which all flushed data has been synced. Pull Request resolved: facebook#10560 Test Plan: repro unit test for the scenario described above. Without this PR, it fails on "key2" not found Reviewed By: riversand963 Differential Revision: D38957391 Pulled By: ajkr fbshipit-source-id: da77175eba97ff251a4219b227b3bb2d4843ed26 Co-authored-by: Andrew Kryczka <andrewkr@fb.com>

mittalrishabh · 2024-03-26T04:39:01Z

db/db_impl/db_impl.cc

@@ -1532,20 +1532,28 @@ void DBImpl::MarkLogsSynced(uint64_t up_to, bool synced_dir,
    auto& wal = *it;
    assert(wal.IsSyncing());

-    if (logs_.size() > 1) {
+    if (wal.number < logs_.back().number) {
+      // Inactive WAL
      if (immutable_db_options_.track_and_verify_wals_in_manifest &&


line 1537 to 1541 should be moved to if block at line 1541

I thought the WAL tracking was designed to allow a WAL's synced size to grow over multiple manifest entries. For some time we were even tracking the active WAL's synced size so this was a requirement. If you are confident this logic causes errors, though, I will look deeper into this.

…synced (facebook#10560) Summary: WAL append and switch can both happen between `FlushWAL(true /* sync */)`'s sync operations and its call to `MarkLogsSynced()`. We permit this since locks need to be released for the sync operations. Such an appended/switched WAL is both inactive and incompletely synced at the time `MarkLogsSynced()` processes it. Prior to this PR, `MarkLogsSynced()` assumed all inactive WALs were fully synced and removed them from consideration for future syncs. That was wrong in the scenario described above and led to the latest append(s) never being synced. This PR changes `MarkLogsSynced()` to only remove inactive WALs from consideration for which all flushed data has been synced. Pull Request resolved: facebook#10560 Test Plan: repro unit test for the scenario described above. Without this PR, it fails on "key2" not found Reviewed By: riversand963 Differential Revision: D38957391 Pulled By: ajkr fbshipit-source-id: da77175eba97ff251a4219b227b3bb2d4843ed26

#358) * Ensure writes to WAL tail during `FlushWAL(true /* sync */)` will be synced (facebook#10560) Summary: WAL append and switch can both happen between `FlushWAL(true /* sync */)`'s sync operations and its call to `MarkLogsSynced()`. We permit this since locks need to be released for the sync operations. Such an appended/switched WAL is both inactive and incompletely synced at the time `MarkLogsSynced()` processes it. Prior to this PR, `MarkLogsSynced()` assumed all inactive WALs were fully synced and removed them from consideration for future syncs. That was wrong in the scenario described above and led to the latest append(s) never being synced. This PR changes `MarkLogsSynced()` to only remove inactive WALs from consideration for which all flushed data has been synced. Pull Request resolved: facebook#10560 Test Plan: repro unit test for the scenario described above. Without this PR, it fails on "key2" not found Reviewed By: riversand963 Differential Revision: D38957391 Pulled By: ajkr fbshipit-source-id: da77175eba97ff251a4219b227b3bb2d4843ed26 * comment out test Signed-off-by: Connor1996 <zbk602423539@gmail.com> --------- Signed-off-by: Connor1996 <zbk602423539@gmail.com> Co-authored-by: Andrew Kryczka <andrewkr@fb.com>

mittalrishabh · 2024-04-12T16:59:11Z

@ajkr If the memtable is switched after the population of log_context->writer but before a writer writes to the Write-Ahead Log , is there a chance of a race condition occurring? If this race condition does occur, the presync size will be the same as the flush size, resulting in the release of the log while writer is still writing to it.

Summary: Our `FileSystem` for simulating unsynced data loss should not sync during `Close()` because it masks bugs where we forgot to sync as long as we closed the file. Pull Request resolved: #12528 Test Plan: Peeled back #10560 fix and verified it is caught much faster now (few seconds vs. ???) with command like ``` $ TEST_TMPDIR=./ python3 tools/db_crashtest.py blackbox --disable_wal=0 --max_key=1000 --write_buffer_size=131072 --max_bytes_for_level_base=524288 --target_file_size_base=131072 --interval=3 --sync_fault_injection=1 --enable_blob_files=0 --manual_wal_flush_one_in=10 --sync_wal_one_in=0 --get_live_files_one_in=0 --get_sorted_wal_files_one_in=0 --backup_one_in=0 --checkpoint_one_in=0 --write_fault_one_in=0 --read_fault_one_in=0 --open_write_fault_one_in=0 --compact_range_one_in=0 --compact_files_one_in=0 --open_read_fault_one_in=0 --get_property_one_in=0 --writepercent=100 -readpercent=0 -prefixpercent=0 -delpercent=0 -delrangepercent=0 -iterpercent=0 ``` Reviewed By: anand1976 Differential Revision: D56033250 Pulled By: ajkr fbshipit-source-id: 6bbf480d79a06c46f08f6214010937f6654af5ca

mittalrishabh · 2024-04-17T20:46:52Z

@ajkr do you think the scenario described above is valid ?

facebook-github-bot added the CLA Signed label Aug 23, 2022

ajkr requested a review from pdillinger August 23, 2022 21:32

ajkr requested a review from riversand963 August 24, 2022 20:16

ajkr requested a review from siying August 25, 2022 16:49

riversand963 approved these changes Aug 25, 2022

View reviewed changes

ajkr added 5 commits August 25, 2022 11:51

repro unit test

b6e51ba

apply patch for missing tail sync

f9db54c

prevent dropping active WAL

672bbaf

update HISTORY.md

95f4896

add assertions

6c3d5ae

ajkr commented Aug 25, 2022

View reviewed changes

ajkr force-pushed the fix-sync-wal-tail branch from 8e48be3 to 6c3d5ae Compare August 25, 2022 18:51

facebook-github-bot closed this in 7ad4b38 Aug 25, 2022

ajkr mentioned this pull request Mar 22, 2024

non-latest WAL log corruption after EBS snapshot restore in AWS #12467

Open

Connor1996 mentioned this pull request Mar 25, 2024

Ensure writes to WAL tail during FlushWAL(true /* sync */) will be … tikv/rocksdb#357

Merged

Connor1996 mentioned this pull request Mar 25, 2024

Ensure writes to WAL tail during FlushWAL(true /* sync */) will be … tikv/rocksdb#358

Merged

mittalrishabh reviewed Mar 26, 2024

View reviewed changes

ajkr mentioned this pull request Apr 11, 2024

Drop unsynced data in TestFSWritableFile::Close() #12528

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Ensure writes to WAL tail during `FlushWAL(true /* sync */)` will be synced #10560

Ensure writes to WAL tail during `FlushWAL(true /* sync */)` will be synced #10560

ajkr commented Aug 23, 2022 •

edited

Loading

facebook-github-bot commented Aug 23, 2022

facebook-github-bot commented Aug 24, 2022

facebook-github-bot commented Aug 24, 2022

facebook-github-bot commented Aug 24, 2022

facebook-github-bot commented Aug 24, 2022

facebook-github-bot commented Aug 24, 2022

facebook-github-bot commented Aug 24, 2022

riversand963 Aug 25, 2022

ajkr Aug 25, 2022

mittalrishabh Mar 25, 2024

ajkr Mar 26, 2024

ajkr left a comment

ajkr Aug 25, 2022

facebook-github-bot commented Aug 25, 2022

facebook-github-bot commented Aug 25, 2022

mittalrishabh Mar 26, 2024 •

edited

Loading

ajkr Mar 27, 2024

mittalrishabh commented Apr 12, 2024 •

edited

Loading

mittalrishabh commented Apr 17, 2024

Ensure writes to WAL tail during FlushWAL(true /* sync */) will be synced #10560

Ensure writes to WAL tail during FlushWAL(true /* sync */) will be synced #10560

Conversation

ajkr commented Aug 23, 2022 • edited Loading

facebook-github-bot commented Aug 23, 2022

facebook-github-bot commented Aug 24, 2022

facebook-github-bot commented Aug 24, 2022

facebook-github-bot commented Aug 24, 2022

facebook-github-bot commented Aug 24, 2022

facebook-github-bot commented Aug 24, 2022

facebook-github-bot commented Aug 24, 2022

riversand963 Aug 25, 2022

Choose a reason for hiding this comment

ajkr Aug 25, 2022

Choose a reason for hiding this comment

mittalrishabh Mar 25, 2024

Choose a reason for hiding this comment

ajkr Mar 26, 2024

Choose a reason for hiding this comment

ajkr left a comment

Choose a reason for hiding this comment

ajkr Aug 25, 2022

Choose a reason for hiding this comment

facebook-github-bot commented Aug 25, 2022

facebook-github-bot commented Aug 25, 2022

mittalrishabh Mar 26, 2024 • edited Loading

Choose a reason for hiding this comment

ajkr Mar 27, 2024

Choose a reason for hiding this comment

mittalrishabh commented Apr 12, 2024 • edited Loading

mittalrishabh commented Apr 17, 2024

Ensure writes to WAL tail during `FlushWAL(true /* sync */)` will be synced #10560

Ensure writes to WAL tail during `FlushWAL(true /* sync */)` will be synced #10560

ajkr commented Aug 23, 2022 •

edited

Loading

mittalrishabh Mar 26, 2024 •

edited

Loading

mittalrishabh commented Apr 12, 2024 •

edited

Loading