10 Commits (9745c68eb1fa3795a998d4cd8170d420b97651a3)

Author	SHA1	Message	Date
Andrew Kryczka	ed75dddc35	Optimize db_stress setup phase (#9475) ... Summary: It is too slow that our `db_crashtest.py` often kills `db_stress` before the setup phase completes. Profiled it and found a few ways to optimize. Pull Request resolved: https://github.com/facebook/rocksdb/pull/9475 Test Plan: Measured setup phase time reduced 22% (36 -> 28 seconds) for first run, and 36% (38 -> 24 seconds) for non-first run on empty-ish DB. - first run benchmark command: `rm -rf /dev/shm/dbstress*/ && mkdir -p /dev/shm/dbstress_expected/ && ./db_stress -max_key=100000000 -destroy_db_initially=1 -expected_values_dir=/dev/shm/dbstress_expected/ -db=/dev/shm/dbstress/ --clear_column_family_one_in=0 --reopen=0 --nooverwritepercent=1` output before this PR: ``` 2022/01/31-11:14:05 Initializing db_stress ... 2022/01/31-11:14:41 Starting database operations ``` output after this PR: ``` ... 2022/01/31-11:12:23 Initializing db_stress ... 2022/01/31-11:12:51 Starting database operations ``` - non-first run benchmark command: `./db_stress -max_key=100000000 -destroy_db_initially=0 -expected_values_dir=/dev/shm/dbstress_expected/ -db=/dev/shm/dbstress/ --clear_column_family_one_in=0 --reopen=0 --nooverwritepercent=1` output before this PR: ``` 2022/01/31-11:20:45 Initializing db_stress ... 2022/01/31-11:21:23 Starting database operations ``` output after this PR: ``` 2022/01/31-11:22:02 Initializing db_stress ... 2022/01/31-11:22:26 Starting database operations ``` - ran minified crash test a while: `DEBUG_LEVEL=0 TEST_TMPDIR=/dev/shm python3 tools/db_crashtest.py blackbox --simple --interval=10 --max_key=1000000 --write_buffer_size=1048576 --target_file_size_base=1048576 --max_bytes_for_level_base=4194304 --value_size_mult=33` Reviewed By: anand1976 Differential Revision: D33897793 Pulled By: ajkr fbshipit-source-id: 0d7b2c93e1e2a9f8a878e87632c2455406313087	2 years ago
Andrew Kryczka	aa2b3bf675	Added `TraceOptions::preserve_write_order` (#9334) ... Summary: This option causes trace records to be written in the serialized write thread. That way, the write records in the trace must follow the same order as writes that are logged to WAL and writes that are applied to the DB. By default I left it disabled to match existing behavior. I enabled it in `db_stress`, though, as that use case requires order of write records in trace matches the order in WAL. Pull Request resolved: https://github.com/facebook/rocksdb/pull/9334 Test Plan: - See if below unsynced data loss crash test can run for 24h straight. It used to crash after a few hours when reaching an unlucky trace ordering. ``` DEBUG_LEVEL=0 TEST_TMPDIR=/dev/shm /usr/local/bin/python3 -u tools/db_crashtest.py blackbox --interval=10 --max_key=100000 --write_buffer_size=524288 --target_file_size_base=524288 --max_bytes_for_level_base=2097152 --value_size_mult=33 --sync_fault_injection=1 --test_batches_snapshots=0 --duration=86400 ``` Reviewed By: zhichao-cao Differential Revision: D33301990 Pulled By: ajkr fbshipit-source-id: 82d97559727adb4462a7af69758449c8725b22d3	3 years ago
Andrew Kryczka	2ee20a669d	Extend trace filtering to more operation types (#9335) ... Summary: - Extended trace filtering to cover `MultiGet()`, `Seek()`, and `SeekForPrev()`. Now all user ops that can be traced support filtering. - Enabled the new filter masks in `db_stress` since it only cares to trace writes. Pull Request resolved: https://github.com/facebook/rocksdb/pull/9335 Test Plan: - trace-heavy `db_stress` command reduced 30% elapsed time (79.21 -> 55.47 seconds) Benchmark command: ``` $ /usr/bin/time ./db_stress -ops_per_thread=100000 -sync_fault_injection=1 --db=/dev/shm/rocksdb_stress_db/ --expected_values_dir=/dev/shm/rocksdb_stress_expected/ --clear_column_family_one_in=0 ``` - replay-heavy `db_stress` command reduced 12.4% elapsed time (23.69 -> 20.75 seconds) Setup command: ``` $ ./db_stress -ops_per_thread=100000000 -sync_fault_injection=1 -db=/dev/shm/rocksdb_stress_db/ -expected_values_dir=/dev/shm/rocksdb_stress_expected --clear_column_family_one_in=0 & sleep 120; pkill -9 db_stress ``` Benchmark command: ``` $ /usr/bin/time ./db_stress -ops_per_thread=1 -reopen=0 -expected_values_dir=/dev/shm/rocksdb_stress_expected/ -db=/dev/shm/rocksdb_stress_db/ --clear_column_family_one_in=0 --destroy_db_initially=0 ``` Reviewed By: zhichao-cao Differential Revision: D33304580 Pulled By: ajkr fbshipit-source-id: 0df10f87c1fc506e9484b6b42cea2ef96c7ecd65	3 years ago
Andrew Kryczka	dfff1cecff	Filter `Get()`s from `db_stress` traces (#9315) ... Summary: `db_stress` traces are used for tracking unsynced changes. For that purpose, we only need to track writes and not reads. Currently `TraceOptions` only supports excluding `Get()`s from the trace, so this PR only excludes `Get()`s. In the future it would be good to exclude `MultiGet()`s and iterator operations too. Pull Request resolved: https://github.com/facebook/rocksdb/pull/9315 Test Plan: - trace-heavy `db_stress` command elapsed time reduced 37% Benchmark: ``` TEST_TMPDIR=/dev/shm /usr/bin/time ./db_stress -ops_per_thread=100000 -sync_fault_injection=1 -expected_values_dir=/dev/shm/dbstress_expected --clear_column_family_one_in=0 ``` - replay-heavy `db_stress` command elapsed time reduced 38% Setup: ``` TEST_TMPDIR=/dev/shm /usr/bin/time ./db_stress -ops_per_thread=100000000 -sync_fault_injection=1 -expected_values_dir=/dev/shm/dbstress_expected --clear_column_family_one_in=0 & sleep 120; pkill -9 db_stress ``` Benchmark: ``` TEST_TMPDIR=/dev/shm /usr/bin/time ./db_stress -ops_per_thread=1 -reopen=0 -expected_values_dir=/dev/shm/dbstress_expected --clear_column_family_one_in=0 --destroy_db_initially=0 ``` Reviewed By: zhichao-cao Differential Revision: D33229900 Pulled By: ajkr fbshipit-source-id: 0e4251c674d236ddbc4548e9bbfdd608bf3cdc93	3 years ago
Andrew Kryczka	b448b71222	`db_stress` tolerate incomplete tail records in trace file (#9316) ... Summary: I saw the following error when running crash test for a while with unsynced data loss: ``` Error restoring historical expected values: Corruption: Corrupted trace file. ``` The trace file turned out to have an incomplete tail record. This is normal considering blackbox kills `db_stress` while trace can be ongoing. In the case where the trace file is not otherwise corrupted, there should be enough records already seen to sync up the expected state with the recovered DB. This PR ignores any `Status::Corruption` the `Replayer` returns when that happens. Pull Request resolved: https://github.com/facebook/rocksdb/pull/9316 Reviewed By: jay-zhuang Differential Revision: D33230579 Pulled By: ajkr fbshipit-source-id: 9814af4e39e57f00d85be7404363211762f9b41b	3 years ago
Andrew Kryczka	863c78d2c9	Fix unsynced data loss correctness test with mixed `-test_batches_snapshots` (#9302) ... Summary: This fixes two bugs in the recently committed DB verification following crash-recovery with unsynced data loss (https://github.com/facebook/rocksdb/issues/8966): The first bug was in crash test runs involving mixed values for `-test_batches_snapshots`. The problem was we were neither restoring expected values nor enabling tracing when `-test_batches_snapshots=1`. This caused a future `-test_batches_snapshots=0` run to not find enough trace data to restore expected values. The fix is to restore expected values at the start of `-test_batches_snapshots=1` runs, but still leave tracing disabled as we do not need to track those KVs. The second bug was in `db_stress` runs that restore the expected values file and use compaction filter. The compaction filter was initialized to use the pre-restore expected values, which would be `munmap()`'d during `FileExpectedStateManager::Restore()`. Then compaction filter would run into a segfault. The fix is just to reorder compaction filter init after expected values restore. Pull Request resolved: https://github.com/facebook/rocksdb/pull/9302 Test Plan: - To verify the first problem, the below sequence used to fail; now it passes. ``` $ ./db_stress --db=./test-db/ --expected_values_dir=./test-db-expected/ --max_key=100000 --ops_per_thread=1000 --sync_fault_injection=1 --clear_column_family_one_in=0 --destroy_db_initially=0 -reopen=0 -test_batches_snapshots=0 $ ./db_stress --db=./test-db/ --expected_values_dir=./test-db-expected/ --max_key=100000 --ops_per_thread=1000 --sync_fault_injection=1 --clear_column_family_one_in=0 --destroy_db_initially=0 -reopen=0 -test_batches_snapshots=1 $ ./db_stress --db=./test-db/ --expected_values_dir=./test-db-expected/ --max_key=100000 --ops_per_thread=1000 --sync_fault_injection=1 --clear_column_family_one_in=0 --destroy_db_initially=0 -reopen=0 -test_batches_snapshots=0 ``` - The second problem occurred rarely in the form of a SIGSEGV on a file that was `munmap()`d. I have not seen it after this PR though this doesn't prove much. Reviewed By: jay-zhuang Differential Revision: D33155283 Pulled By: ajkr fbshipit-source-id: 66fd0f0edf34015a010c30015f14f104734e964e	3 years ago
Andrew Kryczka	c9818b3325	db_stress verify with lost unsynced operations (#8966) ... Summary: When a previous run left behind historical state/trace files (implying it was run with --sync_fault_injection set), this PR uses them to restore the expected state according to the DB's recovered sequence number. That way, a tail of latest unsynced operations are permitted to be dropped, as is the case when data in page cache or certain `Env`s is lost. The point of the verification in this scenario is just to ensure there is no hole in the recovered data. Pull Request resolved: https://github.com/facebook/rocksdb/pull/8966 Test Plan: - ran it a while, made sure it is restoring expected values using the historical state/trace files: ``` $ rm -rf ./tmp-db/ ./exp/ && mkdir -p ./tmp-db/ ./exp/ && while ./db_stress -compression_type=none -clear_column_family_one_in=0 -expected_values_dir=./exp -sync_fault_injection=1 -destroy_db_initially=0 -db=./tmp-db -max_key=1000000 -ops_per_thread=10000 -reopen=0 -threads=32 ; do : ; done ``` Reviewed By: pdillinger Differential Revision: D31219445 Pulled By: ajkr fbshipit-source-id: f0e1d51fe5b35465b00565c33331190ea38ba0ad	3 years ago
Hui Xiao	66b31c5098	Fix -Werror=maybe-uninitialized in db_stress_tool (#9265) ... Summary: Context/Summary: Uninitialized variable `SequenceNumber old_saved_seqno` causes asan related compilation error/warning below: ``` db_stress_tool/expected_state.cc:308:55: error: ‘old_saved_seqno’ may be used uninitialized in this function [-Werror=maybe-uninitialized] 308 | if (s.ok() && old_saved_seqno != kMaxSequenceNumber && | ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^~ ``` Fix it by initializing to 0. Pull Request resolved: https://github.com/facebook/rocksdb/pull/9265 Test Plan: - make clean && COMPILE_WITH_ASAN=1 make -j48 db_stress_tool/expected_state.o - monitor if same error happens again after merging Reviewed By: ajkr Differential Revision: D32939630 Pulled By: hx235 fbshipit-source-id: 41697515fd11ada8427f606b5dceb4e58d12cb80	3 years ago
Andrew Kryczka	a6a6aad74e	db_stress support tracking historical values (#8960) ... Summary: When `--sync_fault_injection` is set, this PR takes a snapshot of the expected values and starts an operation trace when the DB is opened. These files are stored in `--expected_values_dir`. They will be used for recovering the expected state of the DB following a crash where a suffix of unsynced operations are allowed to be lost. Pull Request resolved: https://github.com/facebook/rocksdb/pull/8960 Test Plan: injected crashed at various points in `FileExpectedStateManager` and verified the next run recovers the state/trace file with highest seqno and removes all older/temporary files. Note we don't use sync_fault_injection in CI crash tests yet. Reviewed By: pdillinger Differential Revision: D31194941 Pulled By: ajkr fbshipit-source-id: b0f935a529a0186c5a9c7709fcaa8829de8a84cf	3 years ago
Andrew Kryczka	559943cdc0	Refactor expected state in stress/crash test (#8913) ... Summary: This is a precursor refactoring to enable an upcoming feature: persistence failure correctness testing. - Changed `--expected_values_path` to `--expected_values_dir` and migrated "db_crashtest.py" to use the new flag. For persistence failure correctness testing there are multiple possible correct states since unsynced data is allowed to be dropped. Making it possible to restore all these possible correct states will eventually involve files containing snapshots of expected values and DB trace files. - The expected values directory is managed by an `ExpectedStateManager` instance. Managing expected state files is separated out of `SharedState` to prevent `SharedState` from becoming too complex when the new files and features (snapshotting, tracing, and restoring) are introduced. - Migrated expected values file access/management out of `SharedState` into a separate class called `ExpectedState`. This is not exposed directly to the test but rather the `ExpectedState` for the latest values file is accessed via a pass-through API on `ExpectedStateManager`. This forces the test to always access the single latest `ExpectedState`. - Changed the initialization of the latest expected values file to use a tempfile followed by rename, and also add cleanup logic for possible stranded tempfiles. Pull Request resolved: https://github.com/facebook/rocksdb/pull/8913 Test Plan: run in several ways; try to make sure it's not obviously broken. - crashtest blackbox without TEST_TMPDIR ``` $ python3 tools/db_crashtest.py blackbox --simple --write_buffer_size=1048576 --target_file_size_base=1048576 --max_bytes_for_level_base=4194304 --max_key=100000 --value_size_mult=33 --compression_type=none --duration=120 --interval=10 --compression_type=none --blob_compression_type=none ``` - crashtest blackbox with TEST_TMPDIR ``` $ TEST_TMPDIR=/dev/shm python3 tools/db_crashtest.py blackbox --simple --write_buffer_size=1048576 --target_file_size_base=1048576 --max_bytes_for_level_base=4194304 --max_key=100000 --value_size_mult=33 --compression_type=none --duration=120 --interval=10 --compression_type=none --blob_compression_type=none ``` - crashtest whitebox with TEST_TMPDIR ``` $ TEST_TMPDIR=/dev/shm python3 tools/db_crashtest.py whitebox --simple --write_buffer_size=1048576 --target_file_size_base=1048576 --max_bytes_for_level_base=4194304 --max_key=100000 --value_size_mult=33 --compression_type=none --duration=120 --interval=10 --compression_type=none --blob_compression_type=none --random_kill_odd=88887 ``` - db_stress without expected_values_dir ``` $ ./db_stress --write_buffer_size=1048576 --target_file_size_base=1048576 --max_bytes_for_level_base=4194304 --max_key=100000 --value_size_mult=33 --compression_type=none --ops_per_thread=10000 --clear_column_family_one_in=0 --destroy_db_initially=true ``` - db_stress with expected_values_dir and manual corruption ``` $ ./db_stress --write_buffer_size=1048576 --target_file_size_base=1048576 --max_bytes_for_level_base=4194304 --max_key=100000 --value_size_mult=33 --compression_type=none --ops_per_thread=10000 --clear_column_family_one_in=0 --destroy_db_initially=true --expected_values_dir=./ // modify one byte in "./LATEST.state" $ ./db_stress --write_buffer_size=1048576 --target_file_size_base=1048576 --max_bytes_for_level_base=4194304 --max_key=100000 --value_size_mult=33 --compression_type=none --ops_per_thread=10000 --clear_column_family_one_in=0 --destroy_db_initially=false --expected_values_dir=./ ... Verification failed for column family 0 key 0000000000000000 (0): Value not found: NotFound: ... ``` Reviewed By: riversand963 Differential Revision: D30921951 Pulled By: ajkr fbshipit-source-id: babfe218062e55d018c9b046536c0289fb78f41c	3 years ago