From c7ce03dce12e6d2ca04d5a5892dc168a43d1fef9 Mon Sep 17 00:00:00 2001 From: Andrew Kryczka Date: Mon, 31 Jan 2022 13:31:00 -0800 Subject: [PATCH] db_stress begin tracking expected state after verification (#9470) Summary: Previously we enabled tracking expected state changes during `FinishInitDb()`, as soon as the DB was opened. This meant tracing was enabled during `VerifyDb()`. This cost extra CPU by requiring `DBImpl::trace_mutex_` to be acquired on each read operation. It was unnecessary since we know there are no expected state changes during the `VerifyDb()` phase. So, this PR delays tracking expected state changes until after the `VerifyDb()` phase has completed. Pull Request resolved: https://github.com/facebook/rocksdb/pull/9470 Test Plan: Measured this PR reduced `VerifyDb()` 76% (387 -> 92 seconds) with `-disable_wal=1` (i.e., expected state tracking enabled). - benchmark command: `./db_stress -max_key=100000000 -ops_per_thread=1 -destroy_db_initially=1 -expected_values_dir=/dev/shm/dbstress_expected/ -db=/dev/shm/dbstress/ --clear_column_family_one_in=0 --disable_wal=1 --reopen=0` - without this PR, `VerifyDb()` takes 387 seconds: ``` 2022/01/30-21:43:04 Initializing worker threads Crash-recovery verification passed :) 2022/01/30-21:49:31 Starting database operations ``` - with this PR, `VerifyDb()` takes 92 seconds ``` 2022/01/30-21:59:06 Initializing worker threads Crash-recovery verification passed :) 2022/01/30-22:00:38 Starting database operations ``` Reviewed By: riversand963 Differential Revision: D33884596 Pulled By: ajkr fbshipit-source-id: 5f259de8087de5b0531f088e11297f37ed2f7685 --- db_stress_tool/db_stress_driver.cc | 4 ++++ db_stress_tool/db_stress_test_base.cc | 20 +++++++++++--------- db_stress_tool/db_stress_test_base.h | 2 ++ 3 files changed, 17 insertions(+), 9 deletions(-) diff --git a/db_stress_tool/db_stress_driver.cc b/db_stress_tool/db_stress_driver.cc index 6bf46861f..00c007f08 100644 --- a/db_stress_tool/db_stress_driver.cc +++ b/db_stress_tool/db_stress_driver.cc @@ -117,6 +117,10 @@ bool RunStressTest(StressTest* stress) { } } + // This is after the verification step to avoid making all those `Get()`s + // and `MultiGet()`s contend on the DB-wide trace mutex. + stress->TrackExpectedState(&shared); + now = clock->NowMicros(); fprintf(stdout, "%s Starting database operations\n", clock->TimeToString(now / 1000000).c_str()); diff --git a/db_stress_tool/db_stress_test_base.cc b/db_stress_tool/db_stress_test_base.cc index f68092926..84922ccb2 100644 --- a/db_stress_tool/db_stress_test_base.cc +++ b/db_stress_tool/db_stress_test_base.cc @@ -310,15 +310,6 @@ void StressTest::FinishInitDb(SharedState* shared) { } } - if ((FLAGS_sync_fault_injection || FLAGS_disable_wal) && IsStateTracked()) { - Status s = shared->SaveAtAndAfter(db_); - if (!s.ok()) { - fprintf(stderr, "Error enabling history tracing: %s\n", - s.ToString().c_str()); - exit(1); - } - } - if (FLAGS_enable_compaction_filter) { auto* compaction_filter_factory = reinterpret_cast( @@ -333,6 +324,17 @@ void StressTest::FinishInitDb(SharedState* shared) { } } +void StressTest::TrackExpectedState(SharedState* shared) { + if ((FLAGS_sync_fault_injection || FLAGS_disable_wal) && IsStateTracked()) { + Status s = shared->SaveAtAndAfter(db_); + if (!s.ok()) { + fprintf(stderr, "Error enabling history tracing: %s\n", + s.ToString().c_str()); + exit(1); + } + } +} + bool StressTest::VerifySecondaries() { #ifndef ROCKSDB_LITE if (FLAGS_test_secondary) { diff --git a/db_stress_tool/db_stress_test_base.h b/db_stress_tool/db_stress_test_base.h index 60ecf46c1..786ace4ee 100644 --- a/db_stress_tool/db_stress_test_base.h +++ b/db_stress_tool/db_stress_test_base.h @@ -34,6 +34,8 @@ class StressTest { // dependency with `SharedState`. virtual void FinishInitDb(SharedState*); + void TrackExpectedState(SharedState* shared); + // Return false if verification fails. bool VerifySecondaries();