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
This commit is contained in:
Andrew Kryczka 2022-01-31 13:31:00 -08:00 committed by Facebook GitHub Bot
parent 8dbd0bd11f
commit c7ce03dce1
3 changed files with 17 additions and 9 deletions

View File

@ -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(); now = clock->NowMicros();
fprintf(stdout, "%s Starting database operations\n", fprintf(stdout, "%s Starting database operations\n",
clock->TimeToString(now / 1000000).c_str()); clock->TimeToString(now / 1000000).c_str());

View File

@ -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) { if (FLAGS_enable_compaction_filter) {
auto* compaction_filter_factory = auto* compaction_filter_factory =
reinterpret_cast<DbStressCompactionFilterFactory*>( reinterpret_cast<DbStressCompactionFilterFactory*>(
@ -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() { bool StressTest::VerifySecondaries() {
#ifndef ROCKSDB_LITE #ifndef ROCKSDB_LITE
if (FLAGS_test_secondary) { if (FLAGS_test_secondary) {

View File

@ -34,6 +34,8 @@ class StressTest {
// dependency with `SharedState`. // dependency with `SharedState`.
virtual void FinishInitDb(SharedState*); virtual void FinishInitDb(SharedState*);
void TrackExpectedState(SharedState* shared);
// Return false if verification fails. // Return false if verification fails.
bool VerifySecondaries(); bool VerifySecondaries();