From 710592283fc946c24b5c0844274a84f73fdec5d1 Mon Sep 17 00:00:00 2001 From: Akanksha Mahajan <43301668+akankshamahajan15@users.noreply.github.com> Date: Wed, 27 Apr 2022 22:33:29 -0700 Subject: [PATCH] Fix bug in async_io path which reads incorrect length (#9916) Summary: In FilePrefetchBuffer, in case data is overlapping between two buffers and more data is required to read and copy that to third buffer, incorrect length was updated resulting in ``` Iterator diverged from control iterator which has value 00000000000310C3000000000000012B0000000000000274 total_order_seek: 1 auto_prefix_mode: 0 S 000000000002C37F000000000000012B000000000000001C NNNPPPPPNN; total_order_seek: 1 auto_prefix_mode: 0 S 000000000002F10B00000000000000BF78787878787878 NNNPNNNNPN; total_order_seek: 1 auto_prefix_mode: 0 S 00000000000310C3000000000000012B000000000000026B iterator is not valid Control CF default db_stress: db_stress_tool/db_stress_test_base.cc:1388: void rocksdb::StressTest::VerifyIterator(rocksdb::ThreadState*, rocksdb::ColumnFamilyHandle*, const rocksdb::ReadOptions&, rocksdb::Iterator*, rocksdb::Iterator*, rocksdb::StressTest::LastIterateOp, const rocksdb::Slice&, const string&, bool*): Assertion `false' failed. Aborted (core dumped) ``` Pull Request resolved: https://github.com/facebook/rocksdb/pull/9916 Test Plan: ``` - CircleCI jobs - Ran db_stress with OPTIONS file which caught the bug ./db_stress --acquire_snapshot_one_in=10000 --adaptive_readahead=0 --async_io=1 --avoid_flush_during_recovery=0 --avoid_unnecessary_blocking_io=1 --backup_max_size=104857600 --backup_one_in=0 --batch_protection_bytes_per_key=0 --block_size=16384 --bloom_bits=42.26248932628998 --bottommost_compression_type=disable --cache_index_and_filter_blocks=0 --cache_size=8388608 --checkpoint_one_in=0 --checksum_type=kxxHash --clear_column_family_one_in=0 --compact_files_one_in=1000000 --compact_range_one_in=1000000 --compaction_ttl=0 --compression_max_dict_buffer_bytes=1073741823 --compression_max_dict_bytes=16384 --compression_parallel_threads=1 --compression_type=zstd --compression_zstd_max_train_bytes=65536 --continuous_verification_interval=0 --db=/dev/shm/rocksdb/ --db_write_buffer_size=134217728 --delpercent=5 --delrangepercent=0 --destroy_db_initially=0 --detect_filter_construct_corruption=0 --disable_wal=0 --enable_blob_files=0 --enable_compaction_filter=0 --enable_pipelined_write=0 --fail_if_options_file_error=0 --file_checksum_impl=none --flush_one_in=1000000 --format_version=4 --get_current_wal_file_one_in=0 --get_live_files_one_in=1000000 --get_property_one_in=1000000 --get_sorted_wal_files_one_in=0 --index_block_restart_interval=12 --index_type=2 --ingest_external_file_one_in=0 --iterpercent=10 --key_len_percent_dist=1,30,69 --level_compaction_dynamic_level_bytes=True --long_running_snapshots=0 --mark_for_compaction_one_file_in=0 --max_background_compactions=20 --max_bytes_for_level_base=10485760 --max_key=25000000 --max_key_len=3 --max_manifest_file_size=1073741824 --max_write_batch_group_size_bytes=1048576 --max_write_buffer_number=3 --max_write_buffer_size_to_maintain=8388608 --memtable_prefix_bloom_size_ratio=0.001 --memtable_whole_key_filtering=1 --memtablerep=skip_list --mmap_read=0 --mock_direct_io=False --nooverwritepercent=1 --open_files=100 --open_metadata_write_fault_one_in=0 --open_read_fault_one_in=0 --open_write_fault_one_in=16 --ops_per_thread=100000000 --optimize_filters_for_memory=0 --paranoid_file_checks=1 --partition_filters=0 --partition_pinning=1 --pause_background_one_in=1000000 --periodic_compaction_seconds=0 --prefix_size=-1 --prefixpercent=0 --prepopulate_block_cache=0 --progress_reports=0 --read_fault_one_in=0 --read_only=0 --readpercent=50 --recycle_log_file_num=1 --reopen=0 --reserve_table_reader_memory=0 --ribbon_starting_level=999 --secondary_cache_fault_one_in=0 --secondary_catch_up_one_in=0 --set_options_one_in=10000 --snapshot_hold_ops=100000 --sst_file_manager_bytes_per_sec=104857600 --sst_file_manager_bytes_per_truncate=0 --subcompactions=2 --sync=0 --sync_fault_injection=False --target_file_size_base=2097152 --target_file_size_multiplier=2 --test_batches_snapshots=0 --test_cf_consistency=0 --top_level_index_pinning=3 --unpartitioned_pinning=3 --use_blob_db=0 --use_block_based_filter=0 --use_clock_cache=0 --use_direct_io_for_flush_and_compaction=1 --use_direct_reads=0 --use_full_merge_v1=0 --use_merge=0 --use_multiget=0 --use_txn=0 --user_timestamp_size=0 --value_size_mult=32 --verify_checksum=1 --verify_checksum_one_in=1000000 --verify_db_one_in=100000 --wal_compression=zstd --write_buffer_size=4194304 --write_dbid_to_manifest=0 --writepercent=35 --options_file=/home/akankshamahajan/OPTIONS.orig -column_families=1 db_bench with async_io enabled to make sure db_bench completes successfully without any failure. - ./db_bench -use_existing_db=true -db=/tmp/prefix_scan_prefetch_main -benchmarks="seekrandom" -key_size=32 -value_size=512 -num=5000000 -use_direct_reads=true -seek_nexts=327680 -duration=120 -ops_between_duration_checks=1 -async_io=1 ``` crash_test in progress Reviewed By: anand1976 Differential Revision: D35985789 Pulled By: akankshamahajan15 fbshipit-source-id: 5abe185f34caa99ca587d4bdc8954bd0802b1bf9 --- HISTORY.md | 4 ++++ env/fs_posix.cc | 8 +++++++- file/file_prefetch_buffer.cc | 5 +++-- 3 files changed, 14 insertions(+), 3 deletions(-) diff --git a/HISTORY.md b/HISTORY.md index c7948371e..c28190fcd 100644 --- a/HISTORY.md +++ b/HISTORY.md @@ -1,4 +1,8 @@ # Rocksdb Change Log +## Unreleased +### Bug Fixes +* Fixed a bug in async_io path where incorrect length of data is read by FilePrefetchBuffer if data is consumed from two populated buffers and request for more data is sent. + ## 7.2.1 (04/26/2022) ### Bug Fixes * Fixed a bug where RocksDB could corrupt DBs with `avoid_flush_during_recovery == true` by removing valid WALs, leading to `Status::Corruption` with message like "SST file is ahead of WALs" when attempting to reopen. diff --git a/env/fs_posix.cc b/env/fs_posix.cc index 629ebe5b8..057058d24 100644 --- a/env/fs_posix.cc +++ b/env/fs_posix.cc @@ -1122,7 +1122,13 @@ class PosixFileSystem : public FileSystem { // in posix for IOUring requests. Currently it calls Poll to wait for requests // to complete the request. virtual IOStatus AbortIO(std::vector& io_handles) override { - return Poll(io_handles, io_handles.size()); + IOStatus s = Poll(io_handles, io_handles.size()); + // If Poll is not supported then it didn't submit any request and it should + // return OK. + if (s.IsNotSupported()) { + return IOStatus::OK(); + } + return s; } #if defined(ROCKSDB_IOURING_PRESENT) diff --git a/file/file_prefetch_buffer.cc b/file/file_prefetch_buffer.cc index ec92758fe..222166876 100644 --- a/file/file_prefetch_buffer.cc +++ b/file/file_prefetch_buffer.cc @@ -282,7 +282,7 @@ Status FilePrefetchBuffer::PrefetchAsync(const IOOptions& opts, bufs_[curr_].offset_ + bufs_[curr_].buffer_.CurrentSize()) { offset += length; length = 0; - prefetch_size -= length; + prefetch_size = readahead_size; } // Data is overlapping i.e. some of the data is in curr_ buffer and remaining // in second buffer. @@ -311,7 +311,8 @@ Status FilePrefetchBuffer::PrefetchAsync(const IOOptions& opts, // sync prefetching and copy the remaining data to third buffer in the end. // swap the buffers. curr_ = curr_ ^ 1; - prefetch_size -= length; + // Update prefetch_size as length has been updated in CopyDataToBuffer. + prefetch_size = length + readahead_size; } // Update second again if swap happened.