Please answer these questions before submitting your issue. Thanks!
[m�[0;32m[==========] �[mRunning 1 test from 1 test case.
�[0;32m[----------] �[mGlobal test environment set-up.
�[0;32m[----------] �[m1 test from DMStoreForSegmentReadTaskTest
�[0;32m[ RUN ] �[mDMStoreForSegmentReadTaskTest.DisaggReadSnapshot
[2025/12/11 22:26:35.517 +08:00] [WARN] [Context.cpp:1670] ["GlobalStoragePool has already been initialized."] [source=Context] [thread_id=1]
[2025/12/11 22:26:35.517 +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 22:26:35.517 +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 22:26:35.517 +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 22:26:35.518 +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 22:26:35.518 +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 22:26:35.518 +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 22:26:35.519 +08:00] [WARN] [Context.cpp:1670] ["GlobalStoragePool has already been initialized."] [source=Context] [thread_id=1]
[2025/12/11 22:26:35.519 +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 22:26:35.519 +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 22:26:35.519 +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 22:26:35.520 +08:00] [INFO] [BlobStore.cpp:130] ["Ignore not blob file, dir=/tmp-memfs/tiflash-tests/tmp/DMStoreForSegmentReadTaskTest.DisaggReadSnapshot/page/log file=wal err_msg="] [source=__global__.log] [thread_id=1]
[2025/12/11 22:26:35.520 +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 22:26:35.520 +08:00] [INFO] [BlobStore.cpp:130] ["Ignore not blob file, dir=/tmp-memfs/tiflash-tests/tmp/DMStoreForSegmentReadTaskTest.DisaggReadSnapshot/page/data file=wal err_msg="] [source=__global__.data] [thread_id=1]
[2025/12/11 22:26:35.520 +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 22:26:35.521 +08:00] [INFO] [BlobStore.cpp:130] ["Ignore not blob file, dir=/tmp-memfs/tiflash-tests/tmp/DMStoreForSegmentReadTaskTest.DisaggReadSnapshot/page/meta file=wal err_msg="] [source=__global__.meta] [thread_id=1]
[2025/12/11 22:26:35.521 +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 22:26:35.522 +08:00] [INFO] [DeltaMergeStore.cpp:290] ["Restore DeltaMerge Store start"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.522 +08:00] [DEBUG] [DeltaMergeStore.cpp:2179] ["Loading dt files"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.522 +08:00] [INFO] [StoragePool.cpp:720] ["Finished StoragePool restore. run_mode=ONLY_V3 keyspace=4294967295 table_id=100 max_log_page_id=0 max_data_page_id=0 max_meta_page_id=1"] [source=test.t_100] [thread_id=1]
[2025/12/11 22:26:35.522 +08:00] [INFO] [DeltaMergeStore.cpp:365] ["Restore DeltaMerge Store end, ps_run_mode=ONLY_V3"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.523 +08:00] [INFO] [Disagg.cpp:49] ["Local cache directory will be cleared before setting up LocalPageCache"] [thread_id=1]
[2025/12/11 22:26:35.524 +08:00] [INFO] [Disagg.cpp:66] ["Initialize Read Node page cache in cache directory. path=/tmp-memfs/tiflash-tests/tmp/DMStoreForSegmentReadTaskTest.DisaggReadSnapshot capacity=1073741824"] [thread_id=1]
[2025/12/11 22:26:35.525 +08:00] [INFO] [PageDirectoryFactory.cpp:68] ["PageDirectory restored, max_page_id=0 max_applied_ver=0"] [source=read_cache] [thread_id=1]
[2025/12/11 22:26:35.525 +08:00] [DEBUG] [BlobStore.cpp:1337] ["BlobStore gc get status done. details {ReadOnly: [null]} {Unchanged: [null]} {FullGC: [null]} {Truncated: [null]}"] [source=read_cache] [thread_id=6]
[2025/12/11 22:26:35.525 +08:00] [DEBUG] [GCDefines.cpp:154] ["GC finished without full gc. [total time=0ms] [compact wal=0ms] [compact directory=0ms] [compact spacemap=0ms] [gc status=0ms] [gc entries=0ms] [gc data=0ms] [gc apply=0ms]"] [source=read_cache] [thread_id=6]
[2025/12/11 22:26:35.525 +08:00] [DEBUG] [RNLocalPageCache.cpp:52] ["Initialized local page cache from existing PS, stats=<occupied=<total_n=0 total_size=0 max_size=1073741824> evictable=<total_n=0 total_size=0 max_size=1073741824>>"] [thread_id=1]
[2025/12/11 22:26:35.526 +08:00] [WARN] [Context.cpp:1670] ["GlobalStoragePool has already been initialized."] [source=Context] [thread_id=1]
[2025/12/11 22:26:35.526 +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 22:26:35.526 +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 22:26:35.526 +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 22:26:35.526 +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 22:26:35.527 +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 22:26:35.527 +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 22:26:35.527 +08:00] [INFO] [DeltaMergeStore.cpp:290] ["Restore DeltaMerge Store start"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.527 +08:00] [DEBUG] [DeltaMergeStore.cpp:2179] ["Loading dt files"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.528 +08:00] [INFO] [StoragePool.cpp:720] ["Finished StoragePool restore. run_mode=ONLY_V3 keyspace=4294967295 table_id=100 max_log_page_id=0 max_data_page_id=0 max_meta_page_id=1"] [source=test.t_100] [thread_id=1]
[2025/12/11 22:26:35.528 +08:00] [INFO] [DeltaMergeStore.cpp:365] ["Restore DeltaMerge Store end, ps_run_mode=ONLY_V3"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.528 +08:00] [INFO] [DeltaMergeStore.cpp:408] ["Release DeltaMerge Store start"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.528 +08:00] [TRACE] [DeltaMergeStore.cpp:523] ["Shutdown DeltaMerge start"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.528 +08:00] [INFO] [LocalIndexerScheduler.cpp:179] ["Removed 0 tasks, keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.528 +08:00] [TRACE] [DeltaMergeStore.cpp:541] ["Shutdown DeltaMerge end, clear_light_tasks=0 clear_heavy_tasks=0"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.528 +08:00] [INFO] [DeltaMergeStore.cpp:412] ["Release DeltaMerge Store end"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.530 +08:00] [TRACE] [DeltaMergeStore.cpp:636] ["Table write block, rows=4096 bytes=69632"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.530 +08:00] [INFO] [DeltaMergeStore.cpp:2359] ["creating the first segment with segment_id=1"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.530 +08:00] [WARN] [StoragePool.cpp:899] ["The DTFile is already exists, continue to acquire another ID. call=StableValueSpacePtr DB::DM::createNewStable(DMContext &, const ColumnDefinesPtr &, const BlockInputStreamPtr &, PageIdU64, WriteBatches &) path=<mock for existed path> file_id=1"] [source=test.t_100] [thread_id=1]
[2025/12/11 22:26:35.538 +08:00] [DEBUG] [PathPool.cpp:552] ["added new dtfile. [id=2] [path=/tmp-memfs/tiflash-tests/tmp/DMStoreForSegmentReadTaskTest.DisaggReadSnapshot/data/t_100] [real_size=414] [reported_size=0]"] [thread_id=1]
[2025/12/11 22:26:35.539 +08:00] [TRACE] [WriteBatchesImpl.h:120] ["Write into data : E100.2"] [thread_id=1]
[2025/12/11 22:26:35.539 +08:00] [INFO] [WALStore.cpp:143] ["Creating log file for writing, fullname=/tmp-memfs/tiflash-tests/tmp/DMStoreForSegmentReadTaskTest.DisaggReadSnapshot/page/data/wal/log_1_0"] [source=__global__.data] [thread_id=1]
[2025/12/11 22:26:35.539 +08:00] [TRACE] [WriteBatchesImpl.h:239] ["Write into meta : 100.2,100.3,100.1"] [thread_id=1]
[2025/12/11 22:26:35.539 +08:00] [INFO] [BlobStat.cpp:147] ["Created a new BlobStat [blob_id=10] [capacity=268435456]"] [source=__global__.meta] [thread_id=1]
[2025/12/11 22:26:35.540 +08:00] [INFO] [WALStore.cpp:143] ["Creating log file for writing, fullname=/tmp-memfs/tiflash-tests/tmp/DMStoreForSegmentReadTaskTest.DisaggReadSnapshot/page/meta/wal/log_1_0"] [source=__global__.meta] [thread_id=1]
[2025/12/11 22:26:35.541 +08:00] [TRACE] [WriteBatchesImpl.h:120] ["Write into log : 100.1"] [thread_id=1]
[2025/12/11 22:26:35.542 +08:00] [INFO] [BlobStat.cpp:147] ["Created a new BlobStat [blob_id=10] [capacity=268435456]"] [source=__global__.log] [thread_id=1]
[2025/12/11 22:26:35.542 +08:00] [INFO] [WALStore.cpp:143] ["Creating log file for writing, fullname=/tmp-memfs/tiflash-tests/tmp/DMStoreForSegmentReadTaskTest.DisaggReadSnapshot/page/log/wal/log_1_0"] [source=__global__.log] [thread_id=1]
[2025/12/11 22:26:35.542 +08:00] [TRACE] [Segment.cpp:694] ["Segment write to disk, rows=4096 isBigFile=false"] [source="keyspace=4294967295 table_id=100 segment_id=1 epoch=0"] [thread_id=1]
[2025/12/11 22:26:35.543 +08:00] [DEBUG] [DeltaMergeStore.cpp:162] ["Segment task add to background task pool, segment=<segment_id=1 epoch=0 range=[-9223372036854775808,9223372036854775807)> task=Flush by_whom=Write"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.543 +08:00] [DEBUG] [DeltaMergeStore.cpp:180] ["Segment task pop from background task pool, segment=<segment_id=1 epoch=0 range=[-9223372036854775808,9223372036854775807)> task=Flush"] [source="keyspace=4294967295 table_id=100"] [thread_id=6]
[2025/12/11 22:26:35.543 +08:00] [DEBUG] [DeltaValueSpace.cpp:360] ["Flush start, delta=MemTableSet: 1 column files, 4096 rows, 69632 bytes, 0 deletes. ColumnFilePersistedSet [2]: 0 column files, 0 rows, 0 bytes, 0 deletes."] [source="keyspace=4294967295 table_id=100 segment_id=1 epoch=0"] [thread_id=6]
[2025/12/11 22:26:35.543 +08:00] [TRACE] [WriteBatchesImpl.h:239] ["Write into meta : 100.2"] [thread_id=6]
[2025/12/11 22:26:35.543 +08:00] [DEBUG] [ColumnFilePersistedSet.cpp:238] ["ColumnFilePersistedSet [2]: 1 column files, 4096 rows, 69632 bytes, 0 deletes., after append 1 column files, persisted column files: [T_4096]"] [source="keyspace=4294967295 table_id=100 segment_id=1 epoch=0"] [thread_id=6]
[2025/12/11 22:26:35.544 +08:00] [DEBUG] [DeltaValueSpace.cpp:441] ["Flush end, flush_tasks=1 flush_rows=4096 flush_bytes=69632 flush_deletes=0 delta=MemTableSet: 0 column files, 0 rows, 0 bytes, 0 deletes. ColumnFilePersistedSet [2]: 1 column files, 4096 rows, 69632 bytes, 0 deletes."] [source="keyspace=4294967295 table_id=100 segment_id=1 epoch=0"] [thread_id=6]
[2025/12/11 22:26:35.544 +08:00] [DEBUG] [Segment.cpp:2634] ["Begin segment getReadInfo <segment_id=1 epoch=0 range=[-9223372036854775808,9223372036854775807)>"] [source="write seg_id=1"] [thread_id=6]
[2025/12/11 22:26:35.545 +08:00] [DEBUG] [StableValueSpace.cpp:466] ["StableVS getInputStream start_ts=18446744073709551615 enable_handle_clean_read=false is_fast_mode=false enable_del_clean_read=false"] [source="keyspace=4294967295 table_id=100 segment_id=1 epoch=0"] [thread_id=6]
[2025/12/11 22:26:35.545 +08:00] [DEBUG] [DMFilePackFilter.cpp:183] ["RSFilter exclude rate: nan, after_pk: 0, after_read_packs: 0, after_filter: 0, handle_ranges: [[0,9223372036854775807)], read_packs: 0, pack_count: 0, none_count: 0, some_count: 0, all_count: 0, all_null_count: 0"] [source=write] [thread_id=6]
[2025/12/11 22:26:35.556 +08:00] [INFO] [DeltaMergeStore.cpp:920] ["Begin table mergeDeltaAll"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.556 +08:00] [INFO] [DeltaMergeStore_InternalSegment.cpp:1187] ["MergeDelta - Begin, reason=Manual safe_point=0 segment=<segment_id=1 epoch=0 range=[-9223372036854775808,9223372036854775807) next_segment_id=0 delta_rows=4096 delta_bytes=69632 delta_deletes=0 stable_file=[dmf_2(v=0)] stable_rows=0 stable_bytes=0 dmf_rows=0 dmf_bytes=0 dmf_packs=0>"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.556 +08:00] [DEBUG] [DeltaValueSpace.h:241] ["Cannot get update lock because DeltaValueSpace is updating. Current update operation will be discarded, delta=<delta_id=2>"] [source="keyspace=4294967295 table_id=100 segment_id=1 epoch=0"] [thread_id=1]
[2025/12/11 22:26:35.556 +08:00] [DEBUG] [DeltaMergeStore_InternalSegment.cpp:1213] ["MergeDelta - Give up segmentMergeDelta because snapshot failed, segment=<segment_id=1 epoch=0 range=[-9223372036854775808,9223372036854775807)>"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.556 +08:00] [INFO] [DeltaMergeStore.cpp:941] ["Finish table mergeDeltaAll: false"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.556 +08:00] [INFO] [DeltaMergeStore.cpp:817] ["Table delete range, range=[0,128)"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.556 +08:00] [TRACE] [Segment.cpp:741] ["Segment write delete range, delete_range=[0,128)"] [source="keyspace=4294967295 table_id=100 segment_id=1 epoch=0"] [thread_id=1]
[2025/12/11 22:26:35.573 +08:00] [DEBUG] [PathPool.cpp:552] ["added new dtfile. [id=3] [path=/tmp-memfs/tiflash-tests/tmp/DMStoreForSegmentReadTaskTest.DisaggReadSnapshot/data/t_100] [real_size=1511] [reported_size=621]"] [thread_id=1]
[2025/12/11 22:26:35.578 +08:00] [INFO] [DeltaMergeStore_Ingest.cpp:740] ["Table ingest files - begin, use_split_replace=false files=[<file=dmf_3 range=[0,128)>] rows=128 bytes=2176 bytes_on_disk=621 range=[0,128) clear=false"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.578 +08:00] [TRACE] [WriteBatchesImpl.h:120] ["Write into data : E100.3"] [thread_id=1]
[2025/12/11 22:26:35.581 +08:00] [DEBUG] [Segment.cpp:2897] ["Finish segment ensurePlace, read_ranges=[[-9223372036854775808,9223372036854775807)] placed_items=1 shared_delta_index=<placed_rows=0 placed_deletes=0 tree_entries=0 tree_inserts=0 tree_deletes=0> my_delta_index=<placed_rows=4096 placed_deletes=0 tree_entries=4096 tree_inserts=4096 tree_deletes=0> <segment_id=1 epoch=0 range=[-9223372036854775808,9223372036854775807)>"] [source="write seg_id=1"] [thread_id=6]
[2025/12/11 22:26:35.583 +08:00] [TRACE] [WriteBatchesImpl.h:120] ["Write into data : 100.4 > 100.3"] [thread_id=1]
[2025/12/11 22:26:35.583 +08:00] [TRACE] [Segment.cpp:824] ["Segment ingest data to delta, range=[0,128) clear=false"] [source="keyspace=4294967295 table_id=100 segment_id=1 epoch=0"] [thread_id=1]
[2025/12/11 22:26:35.583 +08:00] [DEBUG] [Segment.cpp:2661] ["Finish segment getReadInfo, my_delta_index=<placed_rows=4096 placed_deletes=0 tree_entries=4096 tree_inserts=4096 tree_deletes=0> fully_indexed=true read_ranges=[[-9223372036854775808,9223372036854775807)] snap={stable_rows=0 persisted_rows=4096 persisted_dels=0 persisted_cfs=1 mem_rows=0 mem_dels=0 mem_cfs=0} <segment_id=1 epoch=0 range=[-9223372036854775808,9223372036854775807)>"] [source="write seg_id=1"] [thread_id=6]
[2025/12/11 22:26:35.583 +08:00] [DEBUG] [Segment.cpp:2673] ["Segment updated delta index, my_delta_index=<placed_rows=4096 placed_deletes=0 tree_entries=4096 tree_inserts=4096 tree_deletes=0> <segment_id=1 epoch=0 range=[-9223372036854775808,9223372036854775807)>"] [source="write seg_id=1"] [thread_id=6]
[2025/12/11 22:26:35.584 +08:00] [DEBUG] [DMFilePackFilter.cpp:183] ["RSFilter exclude rate: 0.00, after_pk: 1, after_read_packs: 1, after_filter: 1, handle_ranges: [[-9223372036854775808,9223372036854775807)], read_packs: 0, pack_count: 1, none_count: 0, some_count: 1, all_count: 0, all_null_count: 0"] [thread_id=1]
[2025/12/11 22:26:35.584 +08:00] [TRACE] [WriteBatchesImpl.h:191] ["Rollback remove from data_wb : X100.3"] [thread_id=1]
[2025/12/11 22:26:35.584 +08:00] [INFO] [DeltaMergeStore_Ingest.cpp:842] ["Table ingest files - finished ingested files into segments, ingested_files=[<file=dmf_3 range=[0,128)>] updated_segments=[<segment_id=1 epoch=0 range=[-9223372036854775808,9223372036854775807)>] clear=false"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.584 +08:00] [DEBUG] [DeltaValueSpace.cpp:360] ["Flush start, delta=MemTableSet: 2 column files, 128 rows, 2176 bytes, 1 deletes. ColumnFilePersistedSet [2]: 1 column files, 4096 rows, 69632 bytes, 0 deletes."] [source="keyspace=4294967295 table_id=100 segment_id=1 epoch=0"] [thread_id=1]
[2025/12/11 22:26:35.585 +08:00] [TRACE] [WriteBatchesImpl.h:239] ["Write into meta : 100.2"] [thread_id=1]
[2025/12/11 22:26:35.585 +08:00] [DEBUG] [ColumnFilePersistedSet.cpp:238] ["ColumnFilePersistedSet [2]: 3 column files, 4224 rows, 71808 bytes, 1 deletes., after append 2 column files, persisted column files: [T_4096,D_[0,128),F_128]"] [source="keyspace=4294967295 table_id=100 segment_id=1 epoch=0"] [thread_id=1]
[2025/12/11 22:26:35.585 +08:00] [DEBUG] [DeltaValueSpace.cpp:441] ["Flush end, flush_tasks=2 flush_rows=128 flush_bytes=2176 flush_deletes=1 delta=MemTableSet: 0 column files, 0 rows, 0 bytes, 0 deletes. ColumnFilePersistedSet [2]: 3 column files, 4224 rows, 71808 bytes, 1 deletes."] [source="keyspace=4294967295 table_id=100 segment_id=1 epoch=0"] [thread_id=1]
[2025/12/11 22:26:35.586 +08:00] [TRACE] [DeltaMergeStore.cpp:636] ["Table write block, rows=128 bytes=2176"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.586 +08:00] [TRACE] [Segment.cpp:700] ["Segment write to cache, rows=128"] [source="keyspace=4294967295 table_id=100 segment_id=1 epoch=0"] [thread_id=1]
[2025/12/11 22:26:35.586 +08:00] [DEBUG] [DeltaValueSpace.cpp:360] ["Flush start, delta=MemTableSet: 1 column files, 128 rows, 2176 bytes, 0 deletes. ColumnFilePersistedSet [2]: 3 column files, 4224 rows, 71808 bytes, 1 deletes."] [source="keyspace=4294967295 table_id=100 segment_id=1 epoch=0"] [thread_id=1]
[2025/12/11 22:26:35.587 +08:00] [TRACE] [WriteBatchesImpl.h:120] ["Write into log : 100.2"] [thread_id=1]
[2025/12/11 22:26:35.588 +08:00] [TRACE] [WriteBatchesImpl.h:239] ["Write into meta : 100.2"] [thread_id=1]
[2025/12/11 22:26:35.588 +08:00] [DEBUG] [ColumnFilePersistedSet.cpp:238] ["ColumnFilePersistedSet [2]: 4 column files, 4352 rows, 73984 bytes, 1 deletes., after append 1 column files, persisted column files: [T_4096,D_[0,128),F_128,T_128]"] [source="keyspace=4294967295 table_id=100 segment_id=1 epoch=0"] [thread_id=1]
[2025/12/11 22:26:35.588 +08:00] [DEBUG] [DeltaValueSpace.cpp:441] ["Flush end, flush_tasks=1 flush_rows=128 flush_bytes=2176 flush_deletes=0 delta=MemTableSet: 0 column files, 0 rows, 0 bytes, 0 deletes. ColumnFilePersistedSet [2]: 4 column files, 4352 rows, 73984 bytes, 1 deletes."] [source="keyspace=4294967295 table_id=100 segment_id=1 epoch=0"] [thread_id=1]
[2025/12/11 22:26:35.589 +08:00] [TRACE] [DeltaMergeStore.cpp:636] ["Table write block, rows=128 bytes=2176"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.589 +08:00] [TRACE] [Segment.cpp:700] ["Segment write to cache, rows=128"] [source="keyspace=4294967295 table_id=100 segment_id=1 epoch=0"] [thread_id=1]
[2025/12/11 22:26:35.589 +08:00] [DEBUG] [DeltaValueSpace.cpp:360] ["Flush start, delta=MemTableSet: 1 column files, 128 rows, 2176 bytes, 0 deletes. ColumnFilePersistedSet [2]: 4 column files, 4352 rows, 73984 bytes, 1 deletes."] [source="keyspace=4294967295 table_id=100 segment_id=1 epoch=0"] [thread_id=1]
[2025/12/11 22:26:35.590 +08:00] [TRACE] [WriteBatchesImpl.h:120] ["Write into log : 100.3"] [thread_id=1]
[2025/12/11 22:26:35.590 +08:00] [TRACE] [WriteBatchesImpl.h:239] ["Write into meta : 100.2"] [thread_id=1]
[2025/12/11 22:26:35.591 +08:00] [DEBUG] [ColumnFilePersistedSet.cpp:238] ["ColumnFilePersistedSet [2]: 5 column files, 4480 rows, 76160 bytes, 1 deletes., after append 1 column files, persisted column files: [T_4096,D_[0,128),F_128,T_128,T_128]"] [source="keyspace=4294967295 table_id=100 segment_id=1 epoch=0"] [thread_id=1]
[2025/12/11 22:26:35.591 +08:00] [DEBUG] [DeltaValueSpace.cpp:441] ["Flush end, flush_tasks=1 flush_rows=128 flush_bytes=2176 flush_deletes=0 delta=MemTableSet: 0 column files, 0 rows, 0 bytes, 0 deletes. ColumnFilePersistedSet [2]: 5 column files, 4480 rows, 76160 bytes, 1 deletes."] [source="keyspace=4294967295 table_id=100 segment_id=1 epoch=0"] [thread_id=1]
[2025/12/11 22:26:35.591 +08:00] [TRACE] [DeltaMergeStore.cpp:636] ["Table write block, rows=128 bytes=2176"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.591 +08:00] [TRACE] [Segment.cpp:700] ["Segment write to cache, rows=128"] [source="keyspace=4294967295 table_id=100 segment_id=1 epoch=0"] [thread_id=1]
[2025/12/11 22:26:35.592 +08:00] [INFO] [DeltaMergeStore.cpp:2288] ["Segment read tasks build done, cost=0ms sorted_ranges=1 n_tasks_before_split=1 n_tasks_final=1 n_ranges_final=1 segments=[s0_t100_1_0_24985326994047330_4608]"] [source="keyspace=4294967295 table_id=100 req_id"] [thread_id=1]
[2025/12/11 22:26:35.592 +08:00] [INFO] [DeltaMergeStore.cpp:1559] ["Read create segment snapshot done"] [source="keyspace=4294967295 table_id=100 req_id"] [thread_id=1]
[2025/12/11 22:26:35.599 +08:00] [DEBUG] [Serializer.cpp:286] ["Rebuild local ColumnFileInMemory from remote, rows=128"] [thread_id=1]
[2025/12/11 22:26:35.599 +08:00] [DEBUG] [Serializer.cpp:396] ["Rebuild local ColumnFileDeleteRange from remote, range=[0,128)"] [thread_id=1]
[2025/12/11 22:26:35.599 +08:00] [DEBUG] [Serializer.cpp:420] ["Rebuild local ColumnFileBig from remote, key=/tmp-memfs/tiflash-tests/tmp/DMStoreForSegmentReadTaskTest.DisaggReadSnapshot/data/t_100/stable/dmf_3"] [thread_id=1]
[2025/12/11 22:26:35.605 +08:00] [DEBUG] [SegmentReadTask.cpp:179] ["memory_cfs_count=1 memory_page_count=0 persisted_cfs_count=5 persisted_page_count=3 remote_page_ids=[1, 2, 3] delta_index=<placed_rows=0 placed_deletes=0 tree_entries=0 tree_inserts=0 tree_deletes=0> store_address=127.0.0.1"] [source=" segment_id=1 epoch=0 delta_epoch=24985326994047330"] [thread_id=1]
/home/jenkins/agent/workspace/tiflash-build-common/tiflash/dbms/src/Storages/DeltaMerge/tests/gtest_segment_read_task.cpp:773: Failure
Expected equality of these values:
persist_set_wn->getColumnFileCount()
Which is: 5
4
[2025/12/11 22:26:35.606 +08:00] [ERROR] [Exception.cpp:93] ["std::exception. Code: 1001, type: testing::AssertionException, e.what() = /home/jenkins/agent/workspace/tiflash-build-common/tiflash/dbms/src/Storages/DeltaMerge/tests/gtest_segment_read_task.cpp:773: Failure\nExpected equality of these values:\n persist_set_wn->getColumnFileCount()\n Which is: 5\n 4"] [source="virtual void DB::DM::tests::DMStoreForSegmentReadTaskTest_DisaggReadSnapshot_Test::TestBody()"] [thread_id=1]
/home/jenkins/agent/workspace/tiflash-build-common/tiflash/dbms/src/Storages/DeltaMerge/tests/gtest_segment_read_task.cpp:822: Failure
Failed
[2025/12/11 22:26:35.607 +08:00] [INFO] [DeltaMergeStore.cpp:408] ["Release DeltaMerge Store start"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.607 +08:00] [TRACE] [DeltaMergeStore.cpp:523] ["Shutdown DeltaMerge start"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.607 +08:00] [INFO] [LocalIndexerScheduler.cpp:179] ["Removed 0 tasks, keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.607 +08:00] [TRACE] [DeltaMergeStore.cpp:541] ["Shutdown DeltaMerge end, clear_light_tasks=0 clear_heavy_tasks=0"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
[2025/12/11 22:26:35.607 +08:00] [INFO] [DeltaMergeStore.cpp:412] ["Release DeltaMerge Store end"] [source="keyspace=4294967295 table_id=100"] [thread_id=1]
�[0;31m[ FAILED ] �[mDMStoreForSegmentReadTaskTest.DisaggReadSnapshot (91 ms)
�[0;32m[----------] �[m1 test from DMStoreForSegmentReadTaskTest (91 ms total)
�[0;32m[----------] �[mGlobal test environment tear-down
�[0;32m[==========] �[m1 test from 1 test case ran. (91 ms total)
�[0;32m[ PASSED ] �[m0 tests.
�[0;31m[ FAILED ] �[m1 test, listed below:
�[0;31m[ FAILED ] �[mDMStoreForSegmentReadTaskTest.DisaggReadSnapshot
Bug Report
Please answer these questions before submitting your issue. Thanks!
1. Minimal reproduce step (Required)
2. What did you expect to see? (Required)
3. What did you see instead (Required)
4. What is your TiFlash version? (Required)
#10607
https://do.pingcap.net/jenkins/blue/organizations/jenkins/pingcap%2Ftiflash%2Fpull_unit_test/detail/pull_unit_test/5241/pipeline/