flaky test S3DMFile.WithFileCache #10611
Description
Bug Report
Please answer these questions before submitting your issue. Thanks!
1. Minimal reproduce step (Required)
2. What did you expect to see? (Required)
�[m�[0;32m[==========] �[mRunning 1 test from 1 test case.
�[0;32m[----------] �[mGlobal test environment set-up.
�[0;32m[----------] �[m1 test from DMFileMetaVersion/S3DMFile
�[0;32m[ RUN ] �[mDMFileMetaVersion/S3DMFile.WithFileCache/0
[2025/12/11 21:28:58.258 +08:00] [INFO] [StorageConfigParser.cpp:512] ["enable with StorageS3Config{endpoint= bucket=mockbucket root=tiflash_ut/ max_connections=4096 max_redirections=10 connection_timeout_ms=1000 request_timeout_ms=30000 access_key_id_size=0 secret_access_key_size=0 enable_http_pool=false enable_poco_client=true}"] [thread_id=1]
[2025/12/11 21:28:58.258 +08:00] [DEBUG] [TiFlashTestEnv.cpp:287] ["Created bucket mockbucket"] [source="bucket=mockbucket root=tiflash_ut/"] [thread_id=1]
[2025/12/11 21:28:58.259 +08:00] [WARN] [Context.cpp:1832] ["GlobalStoragePool has already been initialized."] [source=Context] [thread_id=1]
[2025/12/11 21:28:58.259 +08:00] [INFO] [PageStorageImpl.cpp:54] ["PageStorageImpl start. Config{ PageStorageConfig {blob_file_limit_size: 268435456, blob_spacemap_type: 2, blob_heavy_gc_valid_rate: 0.500, blob_heavy_gc_valid_rate_raft_data: 0.050, blob_block_alignment_bytes: 0, wal_roll_size: 2097152, wal_max_persisted_log_files: 4} }"] [source=__global__.log] [thread_id=1]
[2025/12/11 21:28:58.259 +08:00] [INFO] [PageStorageImpl.cpp:54] ["PageStorageImpl start. Config{ PageStorageConfig {blob_file_limit_size: 268435456, blob_spacemap_type: 2, blob_heavy_gc_valid_rate: 0.500, blob_heavy_gc_valid_rate_raft_data: 0.050, blob_block_alignment_bytes: 0, wal_roll_size: 2097152, wal_max_persisted_log_files: 4} }"] [source=__global__.data] [thread_id=1]
[2025/12/11 21:28:58.259 +08:00] [INFO] [PageStorageImpl.cpp:54] ["PageStorageImpl start. Config{ PageStorageConfig {blob_file_limit_size: 268435456, blob_spacemap_type: 2, blob_heavy_gc_valid_rate: 0.500, blob_heavy_gc_valid_rate_raft_data: 0.050, blob_block_alignment_bytes: 0, wal_roll_size: 2097152, wal_max_persisted_log_files: 4} }"] [source=__global__.meta] [thread_id=1]
[2025/12/11 21:28:58.260 +08:00] [INFO] [PageDirectoryFactory.cpp:68] ["PageDirectory restored, max_page_id=0 max_applied_ver=0"] [source=__global__.log] [thread_id=1]
[2025/12/11 21:28:58.260 +08:00] [INFO] [PageDirectoryFactory.cpp:68] ["PageDirectory restored, max_page_id=0 max_applied_ver=0"] [source=__global__.data] [thread_id=1]
[2025/12/11 21:28:58.260 +08:00] [INFO] [PageDirectoryFactory.cpp:68] ["PageDirectory restored, max_page_id=0 max_applied_ver=0"] [source=__global__.meta] [thread_id=1]
[2025/12/11 21:28:58.261 +08:00] [INFO] [FileCache.cpp:881] ["restore: cost=0.000s used=0 capacity=800000000 total_count=0"] [source=FileCache] [thread_id=1]
[2025/12/11 21:28:58.286 +08:00] [DEBUG] [DataStoreS3.cpp:69] ["Start upload DMFile local files, local_dir=/tmp-memfs/tiflash-tests/tmp/DMFileMetaVersion/S3DMFile.WithFileCache/0/dmf_1 remote_dir=s17/data/t_100/dmf_1 local_files=[0.merged, meta]"] [source=DataStoreS3] [thread_id=1]
[2025/12/11 21:28:58.287 +08:00] [DEBUG] [S3Common.cpp:674] ["uploadFile local_fname=/tmp-memfs/tiflash-tests/tmp/DMFileMetaVersion/S3DMFile.WithFileCache/0/dmf_1/0.merged, key=s17/data/t_100/dmf_1/0.merged, write_bytes=497 cost=0.001s"] [source="bucket=mockbucket root=tiflash_ut/"] [thread_id=6]
[2025/12/11 21:28:58.289 +08:00] [DEBUG] [S3Common.cpp:674] ["uploadFile local_fname=/tmp-memfs/tiflash-tests/tmp/DMFileMetaVersion/S3DMFile.WithFileCache/0/dmf_1/meta, key=s17/data/t_100/dmf_1/meta, write_bytes=890 cost=0.001s"] [source="bucket=mockbucket root=tiflash_ut/"] [thread_id=7]
[2025/12/11 21:28:58.289 +08:00] [INFO] [DataStoreS3.cpp:123] ["Upload DMFile finished, key=s17/data/t_100/dmf_1, cost=3ms"] [source=DataStoreS3] [thread_id=1]
[2025/12/11 21:28:58.290 +08:00] [INFO] [DMFileV3IncrementWriter.cpp:104] ["Write incremental update for DMFile, local_path=/tmp-memfs/tiflash-tests/tmp/DMFileMetaVersion/S3DMFile.WithFileCache/0/data/t1/stable/dmf_1 dmfile_path=s3://s17/data/t_100/dmf_1 old_meta_version=0 new_meta_version=1"] [thread_id=1]
[2025/12/11 21:28:58.290 +08:00] [DEBUG] [DataStoreS3.cpp:69] ["Start upload DMFile local files, local_dir=/tmp-memfs/tiflash-tests/tmp/DMFileMetaVersion/S3DMFile.WithFileCache/0/data/t1/stable/dmf_1 remote_dir=s17/data/t_100/dmf_1 local_files=[v1.meta]"] [source=DataStoreS3] [thread_id=1]
[2025/12/11 21:28:58.291 +08:00] [DEBUG] [S3Common.cpp:674] ["uploadFile local_fname=/tmp-memfs/tiflash-tests/tmp/DMFileMetaVersion/S3DMFile.WithFileCache/0/data/t1/stable/dmf_1/v1.meta, key=s17/data/t_100/dmf_1/v1.meta, write_bytes=894 cost=0.000s"] [source="bucket=mockbucket root=tiflash_ut/"] [thread_id=6]
[2025/12/11 21:28:58.291 +08:00] [INFO] [DataStoreS3.cpp:123] ["Upload DMFile finished, key=s17/data/t_100/dmf_1, cost=0ms"] [source=DataStoreS3] [thread_id=1]
[2025/12/11 21:28:58.291 +08:00] [DEBUG] [FileCache.cpp:776] ["downloading count 1 => s3_key s17/data/t_100/dmf_1/meta start"] [source=FileCache] [thread_id=1]
[2025/12/11 21:28:58.293 +08:00] [DEBUG] [FileCache.cpp:733] ["Download s3_key=s17/data/t_100/dmf_1/meta to local=/tmp-memfs/tiflash-tests/tmp/DMFileMetaVersion/S3DMFile.WithFileCache/0/fs_cache/dtfile/s17/data/t_100/dmf_1/meta size=890 cost=1ms"] [source=FileCache] [thread_id=8]
[2025/12/11 21:28:58.293 +08:00] [DEBUG] [FileCache.cpp:766] ["downloading count 0 => s3_key s17/data/t_100/dmf_1/meta finished"] [source=FileCache] [thread_id=8]
[2025/12/11 21:28:58.296 +08:00] [DEBUG] [FileCache.cpp:776] ["downloading count 1 => s3_key s17/data/t_100/dmf_1/v1.meta start"] [source=FileCache] [thread_id=1]
[2025/12/11 21:28:58.299 +08:00] [DEBUG] [TiFlashTestEnv.cpp:287] ["Created bucket mockbucket"] [source="bucket=mockbucket root=tiflash_ut/"] [thread_id=1]
[2025/12/11 21:28:58.299 +08:00] [WARN] [TiFlashTestEnv.cpp:335] ["DeleteBucket: :"] [source="bucket=mockbucket root=tiflash_ut/"] [thread_id=1]
�[0;32m[ OK ] �[mDMFileMetaVersion/S3DMFile.WithFileCache/0 (41 ms)
�[0;32m[----------] �[m1 test from DMFileMetaVersion/S3DMFile (41 ms total)
�[0;32m[----------] �[mGlobal test environment tear-down
�[0;32m[==========] �[m1 test from 1 test case ran. (42 ms total)
�[0;32m[ PASSED ] �[m1 test.
Received signal Segmentation fault
[2025/12/11 21:28:58.306 +08:00] [INFO] [SegmentReader.cpp:60] ["Pop fail, stop=true"] [thread_id=4]
[2025/12/11 21:28:58.306 +08:00] [INFO] [SegmentReader.cpp:60] ["Pop fail, stop=true"] [thread_id=5]
[2025/12/11 21:28:58.306 +08:00] [DEBUG] [SegmentReader.cpp:45] [Stopped] [thread_id=1]
[2025/12/11 21:28:58.306 +08:00] [DEBUG] [SegmentReader.cpp:45] [Stopped] [thread_id=1]
[2025/12/11 21:28:58.307 +08:00] [INFO] [SegmentReader.cpp:60] ["Pop fail, stop=true"] [thread_id=2]
[2025/12/11 21:28:58.307 +08:00] [INFO] [SegmentReader.cpp:60] ["Pop fail, stop=true"] [thread_id=3]
[2025/12/11 21:28:58.307 +08:00] [DEBUG] [SegmentReader.cpp:45] [Stopped] [thread_id=1]
[2025/12/11 21:28:58.307 +08:00] [DEBUG] [SegmentReader.cpp:45] [Stopped] [thread_id=1]
0x1233894e StackTrace::StackTrace() [gtests_dbms+305367374]
0x869d3b4 fault_signal_handler(int) [gtests_dbms+141153204]
0x7f7188eb25b0 <unknown symbol> [libc.so.6+320944]
0x4c7b3f3 DB::Logger::is(int) const [gtests_dbms+80196595]
0x122aeb62 DB::tryLogCurrentWarningException(std::__1::shared_ptr<DB::Logger> const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> const&) [gtests_dbms+304802658]
0x10b89432 DB::FileCache::bgDownloadExecutor(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> const&, std::__1::shared_ptr<DB::FileSegment>&) [gtests_dbms+280532018]
0x10b8c6a3 DB::FileCache::bgDownload(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> const&, std::__1::shared_ptr<DB::FileSegment>&)::$_1::operator()() [gtests_dbms+280544931]
0x10b8c675 decltype(std::declval<DB::FileCache::bgDownload(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> const&, std::__1::shared_ptr<DB::FileSegment>&)::$_1&>()()) std::__1::__invoke[abi:ue170006]<DB::FileCache::bgDownload(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> const&, std::__1::shared_ptr<DB::FileSegment>&)::$_1&>(DB::FileCache::bgDownload(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> const&, std::__1::shared_ptr<DB::FileSegment>&)::$_1&) [gtests_dbms+280544885]
0x10b8c635 void std::__1::__invoke_void_return_wrapper<void, true>::__call[abi:ue170006]<DB::FileCache::bgDownload(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> const&, std::__1::shared_ptr<DB::FileSegment>&)::$_1&>(DB::FileCache::bgDownload(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> const&, std::__1::shared_ptr<DB::FileSegment>&)::$_1&) [gtests_dbms+280544821]
0x10b8c60d std::__1::__function::__alloc_func<DB::FileCache::bgDownload(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> const&, std::__1::shared_ptr<DB::FileSegment>&)::$_1, std::__1::allocator<DB::FileCache::bgDownload(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> const&, std::__1::shared_ptr<DB::FileSegment>&)::$_1>, void ()>::operator()[abi:ue170006]() [gtests_dbms+280544781]
0x10b8ba29 std::__1::__function::__func<DB::FileCache::bgDownload(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> const&, std::__1::shared_ptr<DB::FileSegment>&)::$_1, std::__1::allocator<DB::FileCache::bgDownload(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> const&, std::__1::shared_ptr<DB::FileSegment>&)::$_1>, void ()>::operator()() [gtests_dbms+280541737]
0x521dae2 std::__1::__function::__value_func<void ()>::operator()[abi:ue170006]() const [gtests_dbms+86104802]
0x52108b5 std::__1::function<void ()>::operator()() const [gtests_dbms+86050997]
0x123caf88 DB::ThreadPoolImpl<DB::ThreadFromGlobalPoolImpl<false>>::worker(std::__1::__list_iterator<DB::ThreadFromGlobalPoolImpl<false>, void*>) [gtests_dbms+305966984]
0x123d5594 void DB::ThreadPoolImpl<DB::ThreadFromGlobalPoolImpl<false>>::scheduleImpl<void>(std::__1::function<void ()>, long, std::__1::optional<unsigned long>, bool)::'lambda0'()::operator()() const [gtests_dbms+306009492]
0x123d5565 decltype(std::declval<void>()()) std::__1::__invoke[abi:ue170006]<void DB::ThreadPoolImpl<DB::ThreadFromGlobalPoolImpl<false>>::scheduleImpl<void>(std::__1::function<void ()>, long, std::__1::optional<unsigned long>, bool)::'lambda0'()&>(void&&) [gtests_dbms+306009445]
0x123d5549 decltype(auto) std::__1::__apply_tuple_impl[abi:ue170006]<void DB::ThreadPoolImpl<DB::ThreadFromGlobalPoolImpl<false>>::scheduleImpl<void>(std::__1::function<void ()>, long, std::__1::optional<unsigned long>, bool)::'lambda0'()&, std::__1::tuple<>&>(void&&, std::__1::tuple<>&, std::__1::__tuple_indices<>) [gtests_dbms+306009417]
0x123d540d decltype(auto) std::__1::apply[abi:ue170006]<void DB::ThreadPoolImpl<DB::ThreadFromGlobalPoolImpl<false>>::scheduleImpl<void>(std::__1::function<void ()>, long, std::__1::optional<unsigned long>, bool)::'lambda0'()&, std::__1::tuple<>&>(void&&, std::__1::tuple<>&) [gtests_dbms+306009101]
0x123d5323 DB::ThreadFromGlobalPoolImpl<false>::ThreadFromGlobalPoolImpl<void DB::ThreadPoolImpl<DB::ThreadFromGlobalPoolImpl<false>>::scheduleImpl<void>(std::__1::function<void ()>, long, std::__1::optional<unsigned long>, bool)::'lambda0'()>(void&&)::'lambda'()::operator()() [gtests_dbms+306008867]
0x123d52b5 decltype(std::declval<void>()()) std::__1::__invoke[abi:ue170006]<DB::ThreadFromGlobalPoolImpl<false>::ThreadFromGlobalPoolImpl<void DB::ThreadPoolImpl<DB::ThreadFromGlobalPoolImpl<false>>::scheduleImpl<void>(std::__1::function<void ()>, long, std::__1::optional<unsigned long>, bool)::'lambda0'()>(void&&)::'lambda'()&>(void&&) [gtests_dbms+306008757]
0x123d5275 void std::__1::__invoke_void_return_wrapper<void, true>::__call[abi:ue170006]<DB::ThreadFromGlobalPoolImpl<false>::ThreadFromGlobalPoolImpl<void DB::ThreadPoolImpl<DB::ThreadFromGlobalPoolImpl<false>>::scheduleImpl<void>(std::__1::function<void ()>, long, std::__1::optional<unsigned long>, bool)::'lambda0'()>(void&&)::'lambda'()&>(DB::ThreadFromGlobalPoolImpl<false>::ThreadFromGlobalPoolImpl<void DB::ThreadPoolImpl<DB::ThreadFromGlobalPoolImpl<false>>::scheduleImpl<void>(std::__1::function<void ()>, long, std::__1::optional<unsigned long>, bool)::'lambda0'()>(void&&)::'lambda'()&) [gtests_dbms+306008693]
0x123d524d std::__1::__function::__alloc_func<DB::ThreadFromGlobalPoolImpl<false>::ThreadFromGlobalPoolImpl<void DB::ThreadPoolImpl<DB::ThreadFromGlobalPoolImpl<false>>::scheduleImpl<void>(std::__1::function<void ()>, long, std::__1::optional<unsigned long>, bool)::'lambda0'()>(void&&)::'lambda'(), std::__1::allocator<DB::ThreadFromGlobalPoolImpl<false>::ThreadFromGlobalPoolImpl<void DB::ThreadPoolImpl<DB::ThreadFromGlobalPoolImpl<false>>::scheduleImpl<void>(std::__1::function<void ()>, long, std::__1::optional<unsigned long>, bool)::'lambda0'()>(void&&)::'lambda'()>, void ()>::operator()[abi:ue170006]() [gtests_dbms+306008653]
0x123d4639 std::__1::__function::__func<DB::ThreadFromGlobalPoolImpl<false>::ThreadFromGlobalPoolImpl<void DB::ThreadPoolImpl<DB::ThreadFromGlobalPoolImpl<false>>::scheduleImpl<void>(std::__1::function<void ()>, long, std::__1::optional<unsigned long>, bool)::'lambda0'()>(void&&)::'lambda'(), std::__1::allocator<DB::ThreadFromGlobalPoolImpl<false>::ThreadFromGlobalPoolImpl<void DB::ThreadPoolImpl<DB::ThreadFromGlobalPoolImpl<false>>::scheduleImpl<void>(std::__1::function<void ()>, long, std::__1::optional<unsigned long>, bool)::'lambda0'()>(void&&)::'lambda'()>, void ()>::operator()() [gtests_dbms+306005561]
0x521dae2 std::__1::__function::__value_func<void ()>::operator()[abi:ue170006]() const [gtests_dbms+86104802]
0x52108b5 std::__1::function<void ()>::operator()() const [gtests_dbms+86050997]
0x123c8f08 DB::ThreadPoolImpl<std::__1::thread>::worker(std::__1::__list_iterator<std::__1::thread, void*>) [gtests_dbms+305958664]
0x123ce884 void DB::ThreadPoolImpl<std::__1::thread>::scheduleImpl<void>(std::__1::function<void ()>, long, std::__1::optional<unsigned long>, bool)::'lambda0'()::operator()() const [gtests_dbms+305981572]
0x123ce835 decltype(std::declval<void>()()) std::__1::__invoke[abi:ue170006]<void DB::ThreadPoolImpl<std::__1::thread>::scheduleImpl<void>(std::__1::function<void ()>, long, std::__1::optional<unsigned long>, bool)::'lambda0'()>(void&&) [gtests_dbms+305981493]
0x123ce80d void std::__1::__thread_execute[abi:ue170006]<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct>>, void DB::ThreadPoolImpl<std::__1::thread>::scheduleImpl<void>(std::__1::function<void ()>, long, std::__1::optional<unsigned long>, bool)::'lambda0'()>(std::__1::tuple<void, void DB::ThreadPoolImpl<std::__1::thread>::scheduleImpl<void>(std::__1::function<void ()>, long, std::__1::optional<unsigned long>, bool)::'lambda0'()>&, std::__1::__tuple_indices<>) [gtests_dbms+305981453]
0x123ce632 void* std::__1::__thread_proxy[abi:ue170006]<std::__1::tuple<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct>>, void DB::ThreadPoolImpl<std::__1::thread>::scheduleImpl<void>(std::__1::function<void ()>, long, std::__1::optional<unsigned long>, bool)::'lambda0'()>>(void*) [gtests_dbms+305980978]
0x7f718945a1ca start_thread [libpthread.so.0+33226]
0x7f7188e9d8d3 __clone [libc.so.6+235731]
3. What did you see instead (Required)
4. What is your TiFlash version? (Required)
release-8.5 branch at #10604