Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Mis-reuse StoragePool::max_data_page_id cause data corruption after upgraded #9039

Closed
JaySon-Huang opened this issue May 13, 2024 · 4 comments · Fixed by #9041
Closed

Mis-reuse StoragePool::max_data_page_id cause data corruption after upgraded #9039

JaySon-Huang opened this issue May 13, 2024 · 4 comments · Fixed by #9041
Labels
affects-6.5 This bug affects the 6.5.x(LTS) versions. affects-7.1 This bug affects the 7.1.x(LTS) versions. affects-7.5 This bug affects the 7.5.x(LTS) versions. affects-8.1 This bug affects the 8.1.x(LTS) versions. component/storage severity/critical type/bug The issue is confirmed as a bug.

Comments

@JaySon-Huang
Copy link
Contributor

JaySon-Huang commented May 13, 2024

Bug Report

Please answer these questions before submitting your issue. Thanks!

1. Minimal reproduce step (Required)

  1. Deploy a cluster with tiflash replica and load some data, the cluster version < 6.5.0
  2. Before upgrade, alter table ... compact tiflash replica to make the table has no data in the delta layer (this raises the possibility of the bug happening)
  3. Upgrade the cluster to a version >= 6.5.0 and wait for a while
  4. Restart the tiflash instance(s)

2. What did you expect to see? (Required)

TiFlash instances restart successfully

3. What did you see instead (Required)

TiFlash fails to restart with error message like

["Code: 10017, e.displayText() = DB::Exception: try to create external version with invalid state [ver=23783.0] [state={type:VAR_REF, create_ver: 1653.0, is_deleted: true, delete_ver: 21767.0, ori_page_id: 22935.100, being_ref_count: 1, num_entries: 0}]:  [type=PUT_EXTERNAL] [page_id=22935.106] [ver=23783.0]
["Code: 10015, e.displayText() = DB::Exception: Invalid page id, entry not exist [page_id=69.2] [resolve_id=69.2]: keyspace=4294967295 physical_table_id=-1: (while preHandleSnapshot region_id=100, index=3246, term=7), e.what() = DB::Exception, Stack trace:
       0x1ef3aee    DB::Exception::Exception(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, int) [tiflash+32455406]
                    dbms/src/Common/Exception.h:46
       0x1e7afb2    DB::PS::V3::PageDirectory<DB::PS::V3::u128::PageDirectoryTrait>::getByIDImpl(DB::UInt128 const&, std::__1::shared_ptr<DB::PS::V3::PageDirectorySnapshot> const&, bool) const [tiflash+31961010]
                    dbms/src/Storages/Page/V3/PageDirectory.cpp:1137
       0x86cad1e    DB::PS::V3::PageStorageImpl::readImpl(unsigned long, unsigned long, std::__1::shared_ptr<DB::ReadLimiter> const&, std::__1::shared_ptr<DB::PageStorageSnapshot>, bool) [tiflash+141339934]
                    dbms/src/Storages/Page/V3/PageStorageImpl.cpp:192
       0x867d0dd    DB::PageReaderImplNormal::read(unsigned long) const [tiflash+141021405]
                    dbms/src/Storages/Page/PageStorage.cpp:110
       0x77356ec    DB::DM::ColumnFilePersistedSet::restore(DB::DM::DMContext&, DB::DM::RowKeyRange const&, unsigned long) [tiflash+124999404]
                    dbms/src/Storages/DeltaMerge/Delta/ColumnFilePersistedSet.cpp:104
       0x75d788f    DB::DM::Segment::restoreSegment(std::__1::shared_ptr<DB::Logger> const&, DB::DM::DMContext&, unsigned long) [tiflash+123566223]
                    dbms/src/Storages/DeltaMerge/Segment.cpp:400
       0x7565905    DB::DM::DeltaMergeStore::DeltaMergeStore(DB::Context&, bool, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, unsigned int, long, bool, std::__1::vector<DB::DM::ColumnDefine, std::__1::allocator<DB::DM::ColumnDefine> > const&, DB::DM::ColumnDefine const&, bool, unsigned long, DB::DM::DeltaMergeStore::Settings const&, DB::ThreadPoolImpl<DB::ThreadFromGlobalPoolImpl<false> >*) [tiflash+123099397]
                    dbms/src/Storages/DeltaMerge/DeltaMergeStore.cpp:295
...
  0x7f0bb92db450    clone3 [libc.so.6+259152]"] [source="DB::RawCppPtr DB::PreHandleSnapshot(DB::EngineStoreServerWrap *, DB::BaseBuffView, uint64_t, DB::SSTViewVec, uint64_t, uint64_t)"] [thread_id=208]
[INFO] [DeltaMergeStore.cpp:221] ["Restore DeltaMerge Store start"] [source="keyspace_id=4294967295 table_id=315604"] [thread_id=1282]
[INFO] [StoragePool.cpp:243] ["PageStorage V2 is already mark deleted. Current pagestorage change from 3 to 2 [ns_id=315604]"] [source=db_315555.t_315604] [thread_id=1282]
[ERROR] [Exception.cpp:94] ["Storage inited fail, keyspace_id=4294967295 table_id=315604: Code: 33, e.displayText() = DB::Exception: Cannot read all data, e.what() = DB::Exception, Stack trace:
       0x1c414fe    DB::Exception::Exception(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, int) [tiflash+29627646]
                    dbms/src/Common/Exception.h:46
       0x1ccbb00    DB::ReadBuffer::readStrict(char*, unsigned long) [tiflash+30194432]
                    dbms/src/IO/ReadBuffer.h:161
       0x73ab52f    DB::DM::readSegmentMetaInfo(DB::ReadBuffer&, DB::DM::Segment::SegmentMetaInfo&) [tiflash+121287983]
                    dbms/src/Storages/DeltaMerge/Segment.cpp:319
       0x73ab20f    DB::DM::Segment::getAllSegmentIds(DB::DM::DMContext const&, unsigned long) [tiflash+121287183]
                    dbms/src/Storages/DeltaMerge/Segment.cpp:335
       0x7336bb4    DB::DM::DeltaMergeStore::DeltaMergeStore(DB::Context&, bool, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, unsigned int, long, bool, std::__1::vector<DB::DM::ColumnDefine, std::__1::allocator<DB::DM::ColumnDefine> > const&, DB::DM::ColumnDefine const&, bool, unsigned long, DB::DM::DeltaMergeStore::Settings const&, DB::ThreadPoolImpl<DB::ThreadFromGlobalPoolImpl<false> >*) [tiflash+120810420]
                    dbms/src/Storages/DeltaMerge/DeltaMergeStore.cpp:287
...

a similar issue #8695

4. What is your TiFlash version? (Required)

v7.1.5

@JaySon-Huang JaySon-Huang added type/bug The issue is confirmed as a bug. affects-6.5 This bug affects the 6.5.x(LTS) versions. affects-7.1 This bug affects the 7.1.x(LTS) versions. affects-7.5 This bug affects the 7.5.x(LTS) versions. affects-8.1 This bug affects the 8.1.x(LTS) versions. component/storage severity/critical labels May 13, 2024
@JaySon-Huang
Copy link
Contributor Author

JaySon-Huang commented May 13, 2024

The root cause is:

  1. When the cluster upgrade from version lower than v6.5.0 to higher or equal to v6.5.0, TiFlash will try to migrate the data from PageStorage V2 to PageStorage V3.
  2. When the table has no data in the delta layer, it will run under PageStorage V3 mode
  3. But we get a wrong max_id for this situation, we must use max_data_page_id = std::max(data_storage_v2->getMaxId(), data_storage_v3->getMaxId()); to avoid the page_id from being mis-reused. Otherwise it will cause data corruption and make tiflash fails to restart in the next restart

max_log_page_id = log_storage_v3->getMaxId();
max_data_page_id = data_storage_v3->getMaxId();
max_meta_page_id = meta_storage_v3->getMaxId();


Related logs for a case that locate this bug:

-- After restart, the data is upgraded to PageStorage V3
[2024/03/18 16:08:50.178 +08:00] [INFO] [DeltaMergeStore.cpp:221] ["Restore DeltaMerge Store start"] [source="keyspace_id=4294967295 table_id=22935"] [thread_id=1119]
[2024/03/18 16:08:50.225 +08:00] [DEBUG] [DeltaMergeStore.cpp:1691] ["Loading dt files"] [source="keyspace_id=4294967295 table_id=22935"] [thread_id=1119]
[2024/03/18 16:08:50.228 +08:00] [INFO] [PageStorage.cpp:209] ["db_22933.t_22935.log begin to restore data from disk. [path=/data2/tidb/data/tiflash-9000/data/t_22935/log] [num_writers=4]"] [source=PageStorage] [thread_id=1119]
[2024/03/18 16:08:50.284 +08:00] [INFO] [PageStorage.cpp:364] ["db_22933.t_22935.log restore 0 pages, write batch sequence: 0, 0 puts and 0 refs and 0 deletes and 0 upserts"] [source=PageStorage] [thread_id=1119]
[2024/03/18 16:08:50.420 +08:00] [INFO] [PageStorage.cpp:209] ["db_22933.t_22935.data begin to restore data from disk. [path=/data2/tidb/data/tiflash-9000/data/t_22935/data] [num_writers=1]"] [source=PageStorage] [thread_id=1119]
[2024/03/18 16:08:50.567 +08:00] [INFO] [PageStorage.cpp:364] ["db_22933.t_22935.data restore 1734 pages, write batch sequence: 52177, 18373 puts and 16475 refs and 33994 deletes and 0 upserts"] [source=PageStorage] [thread_id=1119]
[2024/03/18 16:08:50.818 +08:00] [INFO] [PageStorage.cpp:209] ["db_22933.t_22935.meta begin to restore data from disk. [path=/data2/tidb/data/tiflash-9000/data/t_22935/meta] [num_writers=2]"] [source=PageStorage] [thread_id=1119]
[2024/03/18 16:08:51.059 +08:00] [INFO] [PageStorage.cpp:364] ["db_22933.t_22935.meta restore 2643 pages, write batch sequence: 19254, 38851 puts and 0 refs and 0 deletes and 0 upserts"] [source=PageStorage] [thread_id=1119]
[2024/03/18 16:08:51.374 +08:00] [INFO] [StoragePool.cpp:461] ["Current pool.meta transform to V3 begin [ns_id=22935] [pages_before_transform=2643]"] [source=db_22933.t_22935] [thread_id=1119]
[2024/03/18 16:08:51.543 +08:00] [INFO] [StoragePool.cpp:468] ["Current pool.meta transform to V3 finished [ns_id=22935] [done=true] [pages_before_transform=2643], [pages_after_transform=0]"] [source=db_22933.t_22935] [thread_id=1119]
[2024/03/18 16:08:52.227 +08:00] [INFO] [StoragePool.cpp:477] ["Current pool.data transform to V3 begin [ns_id=22935] [pages_before_transform=1734]"] [source=db_22933.t_22935] [thread_id=1119]
[2024/03/18 16:08:52.848 +08:00] [INFO] [StoragePool.cpp:484] ["Current pool.data transform to V3 finished [ns_id=22935] [done=true] [pages_before_transform=1734], [pages_after_transform=0]"] [source=db_22933.t_22935] [thread_id=1119]
[2024/03/18 16:08:53.519 +08:00] [INFO] [StoragePool.cpp:498] ["Current pagestorage change from 3 to 2 [ns_id=22935]"] [source=db_22933.t_22935] [thread_id=1119]
[2024/03/18 16:08:53.519 +08:00] [INFO] [PageStorage.cpp:830] ["db_22933.t_22935.log is going to drop"] [source=PageStorage] [thread_id=1119]
[2024/03/18 16:08:54.315 +08:00] [INFO] [PageStorage.cpp:855] ["db_22933.t_22935.log drop done."] [source=PageStorage] [thread_id=1119]
[2024/03/18 16:08:55.302 +08:00] [INFO] [PageStorage.cpp:830] ["db_22933.t_22935.data is going to drop"] [source=PageStorage] [thread_id=1119]
[2024/03/18 16:08:55.311 +08:00] [INFO] [PageStorage.cpp:855] ["db_22933.t_22935.data drop done."] [source=PageStorage] [thread_id=1119]
[2024/03/18 16:08:55.311 +08:00] [INFO] [PageStorage.cpp:830] ["db_22933.t_22935.meta is going to drop"] [source=PageStorage] [thread_id=1119]
[2024/03/18 16:08:56.220 +08:00] [INFO] [PageStorage.cpp:855] ["db_22933.t_22935.meta drop done."] [source=PageStorage] [thread_id=1119]
[2024/03/18 16:09:04.191 +08:00] [INFO] [DeltaMergeStore.cpp:322] ["Restore DeltaMerge Store end, ps_run_mode=ONLY_V3"] [source="keyspace_id=4294967295 table_id=22935"] [thread_id=1119]
[2024/03/18 16:09:04.191 +08:00] [INFO] [BgStorageInit.cpp:57] ["Storage inited done, keyspace_id=4294967295 table_id=22935"] [thread_id=1119]
-- In later running, it create a dmf_1 (the id==1 is mis-reused) and drop the old dmf_100


[2024/03/18 16:09:52.807 +08:00] [INFO] [DeltaMergeStore_InternalBg.cpp:794] ["GC - Trigger MergeDelta, compact_reason=TooMuchOutOfRange segment=<segment_id=1 epoch=21 range=[-9223372036854775808,204906)> table=t_22935"] [source="keyspace_id=4294967295 table_id=22935"] [thread_id=6618]
-- In the old segment_id=1, there is "dmf_100"
[2024/03/18 16:09:52.807 +08:00] [INFO] [DeltaMergeStore_InternalSegment.cpp:357] ["MergeDelta - Begin, reason=BackgroundGCThread safe_point=448458651756396545 segment=<segment_id=1 epoch=21 range=[-9223372036854775808,204906) next_segment_id=8 delta_rows=0 delta_bytes=0 delta_deletes=0 stable_file=dmf_100 stable_rows=204800 stable_bytes=527735975 dmf_rows=407837 dmf_bytes=1050953764 dmf_packs=50>"] [source="keyspace_id=4294967295 table_id=22935"] [thread_id=6618]
[2024/03/18 16:09:52.807 +08:00] [DEBUG] [Segment.cpp:1043] ["MergeDelta - Begin prepare, delta_column_files=1 delta_rows=0 delta_bytes=0"] [source="keyspace_id=4294967295 table_id=22935 segment_id=1 epoch=21"] [thread_id=6618]
[2024/03/18 16:09:52.807 +08:00] [DEBUG] [Segment.cpp:2132] ["Begin segment getReadInfo"] [source="keyspace_id=4294967295 table_id=22935 segment_id=1 epoch=21 onSyncGc"] [thread_id=6618]
[2024/03/18 16:09:52.807 +08:00] [DEBUG] [Segment.cpp:2147] ["Finish segment getReadInfo"] [source="keyspace_id=4294967295 table_id=22935 segment_id=1 epoch=21 onSyncGc"] [thread_id=6618]
[2024/03/18 16:09:52.807 +08:00] [DEBUG] [StableValueSpace.cpp:446] ["max_data_version: 18446744073709551615, enable_handle_clean_read: false, is_fast_mode: false, enable_del_clean_read: false"] [source="keyspace_id=4294967295 table_id=22935 segment_id=1 epoch=21"] [thread_id=6618]
[2024/03/18 16:09:52.807 +08:00] [DEBUG] [DMFilePackFilter.h:224] ["RSFilter exclude rate: 0.00, after_pk: 25, after_read_packs: 25, after_filter: 25, handle_ranges: {[-9223372036854775808,204906)}, read_packs: 0, pack_count: 50"] [source=onSyncGc] [thread_id=6618]
[2024/03/18 16:09:55.227 +08:00] [DEBUG] [Segment.cpp:1057] ["MergeDelta - Finish prepare, segment=<segment_id=1 epoch=21 range=[-9223372036854775808,204906) next_segment_id=8 delta_rows=0 delta_bytes=0 delta_deletes=0 stable_file=dmf_100 stable_rows=204800 stable_bytes=527735975 dmf_rows=407837 dmf_bytes=1050953764 dmf_packs=50>"] [source="keyspace_id=4294967295 table_id=22935 segment_id=1 epoch=21"] [thread_id=6618]
[2024/03/18 16:09:55.227 +08:00] [DEBUG] [DMVersionFilterBlockInputStream.h:85] ["Total rows: 203918, pass: 100.00%, complete pass: 100.00%, complete not pass: 0.00%, not clean: 0.00%, is deleted: 0.00%, effective: 100.00%, start_ts: 448458651756396545"] [source="mode=COMPACT"] [thread_id=6618]
[2024/03/18 16:09:55.232 +08:00] [DEBUG] [Segment.cpp:1068] ["MergeDelta - Begin apply"] [source="keyspace_id=4294967295 table_id=22935 segment_id=1 epoch=21"] [thread_id=6618]

-- But in the new segment_id=1, epoch=21, the new generated dmfile is "dmf_1"
[2024/03/18 16:09:55.232 +08:00] [DEBUG] [Segment.cpp:1105] ["MergeDelta - Finish apply, old_me=<segment_id=1 epoch=21 range=[-9223372036854775808,204906) next_segment_id=8 delta_rows=0 delta_bytes=0 delta_deletes=0 stable_file=dmf_100 stable_rows=204800 stable_bytes=527735975 dmf_rows=407837 dmf_bytes=1050953764 dmf_packs=50> new_me=<segment_id=1 epoch=22 range=[-9223372036854775808,204906) next_segment_id=8 delta_rows=0 delta_bytes=0 delta_deletes=0 stable_file=dmf_1 stable_rows=203918 stable_bytes=525460521 dmf_rows=203918 dmf_bytes=525460521 dmf_packs=25>"] [source="keyspace_id=4294967295 table_id=22935 segment_id=1 epoch=21"] [thread_id=6618]
[2024/03/18 16:09:55.233 +08:00] [DEBUG] [Segment.h:540] ["Abandon segment, segment=<segment_id=1 epoch=21 range=[-9223372036854775808,204906)>"] [source="keyspace_id=4294967295 table_id=22935 segment_id=1 epoch=21"] [thread_id=6618]
[2024/03/18 16:09:55.233 +08:00] [INFO] [DeltaMergeStore_InternalSegment.cpp:472] ["MergeDelta - Finish, delta is merged, old_segment=<segment_id=1 epoch=21 range=[-9223372036854775808,204906) abandoned=true next_segment_id=8 delta_rows=0 delta_bytes=0 delta_deletes=0 stable_file=dmf_100 stable_rows=204800 stable_bytes=527735975 dmf_rows=407837 dmf_bytes=1050953764 dmf_packs=50> new_segment=<segment_id=1 epoch=22 range=[-9223372036854775808,204906) next_segment_id=8 delta_rows=0 delta_bytes=0 delta_deletes=0 stable_file=dmf_1 stable_rows=203918 stable_bytes=525460521 dmf_rows=203918 dmf_bytes=525460521 dmf_packs=25>"] [source="keyspace_id=4294967295 table_id=22935"] [thread_id=6618]
-- And in next restart, tiflash fails to restart because data corruption
[2024/05/13 23:39:23.238 +08:00] [ERROR] [Exception.cpp:100] ["Code: 10017, e.displayText() = DB::Exception: try to create external version with invalid state [ver=23783.0] [state={type:VAR_REF, create_ver: 1653.0, is_deleted: true, delete_ver: 21767.0, ori_page_id: 22935.100, being_ref_count: 1, num_entries: 0}]:  [type=PUT_EXTERNAL] [page_id=22935.106] [ver=23783.0], e.what() = DB::Exception, Stack trace:
       0x1c414fe    DB::Exception::Exception(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, int) [tiflash+29627646]
                    dbms/src/Common/Exception.h:46
       0x1b71d15    DB::PS::V3::VersionedPageEntries<DB::PS::V3::u128::PageDirectoryTrait>::createNewExternal(DB::PS::V3::PageVersion const&, DB::PS::V3::PageEntryV3 const&) [tiflash+28777749]
                    dbms/src/Storages/Page/V3/PageDirectory.cpp:259
       0x1b93e4c    DB::PS::V3::PageDirectoryFactory<DB::PS::V3::u128::FactoryTrait>::createFromReader(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, std::__1::shared_ptr<DB::PS::V3::WALStoreReader>, std::__1::unique_ptr<DB::PS::V3::WALStore, std::__1::default_delete<DB::PS::V3::WALStore> >) [tiflash+28917324]
                    dbms/src/Storages/Page/V3/PageDirectoryFactory.cpp:48
       0x1b9329e    DB::PS::V3::PageDirectoryFactory<DB::PS::V3::u128::FactoryTrait>::create(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, std::__1::shared_ptr<DB::FileProvider>&, std::__1::shared_ptr<DB::PSDiskDelegator>&, DB::PS::V3::WALConfig const&) [tiflash+28914334]
                    dbms/src/Storages/Page/V3/PageDirectoryFactory.cpp:40
       0x75b1542    DB::PS::V3::PageStorageImpl::restore() [tiflash+123409730]
                    dbms/src/Storages/Page/V3/PageStorageImpl.cpp:75
       0x743d576    DB::DM::GlobalStoragePool::restore() [tiflash+121886070]
                    dbms/src/Storages/DeltaMerge/StoragePool.cpp:117
       0x771604c    DB::Context::initializeGlobalStoragePoolIfNeed(DB::PathPool const&) [tiflash+124870732]
                    dbms/src/Interpreters/Context.cpp:1689
       0x1cef897    DB::Server::main(std::__1::vector<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::allocator<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > > > const&) [tiflash+30341271]
                    dbms/src/Server/Server.cpp:1249
       0x88be1aa    Poco::Util::Application::run() [tiflash+143385002]
                    contrib/poco/Util/src/Application.cpp:335
       0x1ce689a    DB::Server::run() [tiflash+30304410]
                    dbms/src/Server/Server.cpp:263
       0x88c8a94    Poco::Util::ServerApplication::run(int, char**) [tiflash+143428244]
                    contrib/poco/Util/src/ServerApplication.cpp:618
       0x1cfd4f9    mainEntryClickHouseServer(int, char**) [tiflash+30397689]
                    dbms/src/Server/Server.cpp:1733
       0x1c2d91c    main [tiflash+29546780]
                    dbms/src/Server/main.cpp:167
  0x7fe7b3632555    __libc_start_main [libc.so.6+140629]
       0x192b669    <unknown symbol> [tiflash+26392169]"] [source="bool DB::Context::initializeGlobalStoragePoolIfNeed(const DB::PathPool &)"] [thread_id=1]

@JaySon-Huang
Copy link
Contributor Author

JaySon-Huang commented May 13, 2024

A minimal reproduce ut:


TEST_F(PageStorageMixedTest, GetMaxIdAfterUpgraded)
try
{
    const size_t buf_sz = 1024;
    char c_buff[buf_sz] = {0};

    const PageIdU64 max_data_page_id_allocated = (1 << 30) + 1;
    const PageIdU64 max_meta_page_id_allocated = (1 << 28) + 1;
    {
        // Prepare a StoragePool with
        // - 0 pages in "log" (must be 0)
        // - some pages in "data" with `max_data_page_id_allocated`
        // - some pages in "meta" with `max_meta_page_id_allocated`
        {
            WriteBatch batch;
            ReadBufferPtr buff = std::make_shared<ReadBufferFromMemory>(c_buff, sizeof(c_buff));
            batch.putPage(1, 0, buff, buf_sz);
            batch.putRefPage(2, 1);
            ReadBufferPtr buff2 = std::make_shared<ReadBufferFromMemory>(c_buff, sizeof(c_buff));
            batch.putPage(1 << 30, 0, buff2, buf_sz);
            batch.putRefPage(max_data_page_id_allocated, 1 << 30);
            storage_pool_v2->dataWriter()->write(std::move(batch), nullptr);
        }
        {
            WriteBatch batch;
            ReadBufferPtr buff = std::make_shared<ReadBufferFromMemory>(c_buff, sizeof(c_buff));
            batch.putPage(max_meta_page_id_allocated, 0, buff, buf_sz);
            storage_pool_v2->metaWriter()->write(std::move(batch), nullptr);
        }
    }

    // Mock that after upgraded, the run_mode is transformed to `ONLY_V3`
    ASSERT_EQ(reloadMixedStoragePool(), PageStorageRunMode::ONLY_V3);

    // Disable some failpoint to avoid it affect the allocated id
    DB::FailPointHelper::disableFailPoint(DB::FailPoints::force_set_dtfile_exist_when_acquire_id);
    SCOPE_EXIT({ DB::FailPointHelper::enableFailPoint(DB::FailPoints::force_set_dtfile_exist_when_acquire_id); });

    // Allocate new id for "data" should be larger than `max_data_page_id_allocated`
    auto d = storage_path_pool_v2->getStableDiskDelegator();
    EXPECT_GT(storage_pool_mix->newDataPageIdForDTFile(d, "GetMaxIdAfterUpgraded"), max_data_page_id_allocated);

    // Allocate new id for "meta" should be larger than `max_meta_page_id_allocated`
    EXPECT_GT(storage_pool_mix->newMetaPageId(), max_meta_page_id_allocated);
}
CATCH

@JaySon-Huang
Copy link
Contributor Author

JaySon-Huang commented May 13, 2024

This bug won't happen when the tiflash instance is newly deployed with version >= 6.5.0 with no existing data.

Workaround after the crash happened: set the tables' tiflash replica to zero, scale-in the tiflash instance with corrupted data, then scale-out new tiflash instance.

When upgrading a cluster < v6.5.0 to these LTS versions, tiflash may happen to this bug:

  • v6.5.0~v6.5.9
  • v7.1.0~v7.1.5
  • v7.5.0~v7.5.1

It is recommended that upgrading to at least v6.5.10/v7.1.6/v7.5.2/v8.1.0.

If you have to upgrade from < v6.5.0 to those affected versions, there is a way to avoid this bug:

  1. Set the tables' tiflash replica to zero, scale-in the tiflash instances before upgrade.
  2. Upgrade the cluster
  3. Scale-out the tiflash instances

@JaySon-Huang
Copy link
Contributor Author

JaySon-Huang commented May 14, 2024

Reproduce another error,

Steps:

-- Deploy a cluster with v6.1.7, and load data with the following SQLs

CREATE TABLE `comp1` (
  `factory` varchar(20) DEFAULT NULL,
  `goods` varchar(20) DEFAULT NULL
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_bin;

alter table comp1 set tiflash replica 1;

-- prepare data
insert into comp1(factory, goods) values ('A', 'A'),('A', 'A'),('A', 'A'),('A', 'A'),('A', 'A'),('A', 'A');
-- repeat it until comp1 contains more than 50,000 rows
insert into comp1 select * from comp1;insert into comp1 select * from comp1;insert into comp1 select * from comp1;
-- compact to make sure there is no data in delta layer
alter table comp1 compact tiflash replica;

-- Upgrade the cluster to v7.5.1

-- compact the table for multiple time to corrupt the data
alter table comp1 compact tiflash replica;
alter table comp1 compact tiflash replica;

-- Restart the tiflash instance
["Code: 10015, e.displayText() = DB::Exception: Invalid page id, entry not exist [page_id=69.2] [resolve_id=69.2]: keyspace=4294967295 physical_table_id=-1: (while preHandleSnapshot region_id=100, index=3246, term=7), e.what() = DB::Exception, Stack trace:
       0x1ef3aee    DB::Exception::Exception(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, int) [tiflash+32455406]
                    dbms/src/Common/Exception.h:46
       0x1e7afb2    DB::PS::V3::PageDirectory<DB::PS::V3::u128::PageDirectoryTrait>::getByIDImpl(DB::UInt128 const&, std::__1::shared_ptr<DB::PS::V3::PageDirectorySnapshot> const&, bool) const [tiflash+31961010]
                    dbms/src/Storages/Page/V3/PageDirectory.cpp:1137
       0x86cad1e    DB::PS::V3::PageStorageImpl::readImpl(unsigned long, unsigned long, std::__1::shared_ptr<DB::ReadLimiter> const&, std::__1::shared_ptr<DB::PageStorageSnapshot>, bool) [tiflash+141339934]
                    dbms/src/Storages/Page/V3/PageStorageImpl.cpp:192
       0x867d0dd    DB::PageReaderImplNormal::read(unsigned long) const [tiflash+141021405]
                    dbms/src/Storages/Page/PageStorage.cpp:110
       0x77356ec    DB::DM::ColumnFilePersistedSet::restore(DB::DM::DMContext&, DB::DM::RowKeyRange const&, unsigned long) [tiflash+124999404]
                    dbms/src/Storages/DeltaMerge/Delta/ColumnFilePersistedSet.cpp:104
       0x75d788f    DB::DM::Segment::restoreSegment(std::__1::shared_ptr<DB::Logger> const&, DB::DM::DMContext&, unsigned long) [tiflash+123566223]
                    dbms/src/Storages/DeltaMerge/Segment.cpp:400
       0x7565905    DB::DM::DeltaMergeStore::DeltaMergeStore(DB::Context&, bool, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, unsigned int, long, bool, std::__1::vector<DB::DM::ColumnDefine, std::__1::allocator<DB::DM::ColumnDefine> > const&, DB::DM::ColumnDefine const&, bool, unsigned long, DB::DM::DeltaMergeStore::Settings const&, DB::ThreadPoolImpl<DB::ThreadFromGlobalPoolImpl<false> >*) [tiflash+123099397]
                    dbms/src/Storages/DeltaMerge/DeltaMergeStore.cpp:295
...
  0x7f0bb92db450    clone3 [libc.so.6+259152]"] [source="DB::RawCppPtr DB::PreHandleSnapshot(DB::EngineStoreServerWrap *, DB::BaseBuffView, uint64_t, DB::SSTViewVec, uint64_t, uint64_t)"] [thread_id=208]
[INFO] [DeltaMergeStore.cpp:221] ["Restore DeltaMerge Store start"] [source="keyspace_id=4294967295 table_id=315604"] [thread_id=1282]
[INFO] [StoragePool.cpp:243] ["PageStorage V2 is already mark deleted. Current pagestorage change from 3 to 2 [ns_id=315604]"] [source=db_315555.t_315604] [thread_id=1282]
[ERROR] [Exception.cpp:94] ["Storage inited fail, keyspace_id=4294967295 table_id=315604: Code: 33, e.displayText() = DB::Exception: Cannot read all data, e.what() = DB::Exception, Stack trace:
       0x1c414fe    DB::Exception::Exception(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, int) [tiflash+29627646]
                    dbms/src/Common/Exception.h:46
       0x1ccbb00    DB::ReadBuffer::readStrict(char*, unsigned long) [tiflash+30194432]
                    dbms/src/IO/ReadBuffer.h:161
       0x73ab52f    DB::DM::readSegmentMetaInfo(DB::ReadBuffer&, DB::DM::Segment::SegmentMetaInfo&) [tiflash+121287983]
                    dbms/src/Storages/DeltaMerge/Segment.cpp:319
       0x73ab20f    DB::DM::Segment::getAllSegmentIds(DB::DM::DMContext const&, unsigned long) [tiflash+121287183]
                    dbms/src/Storages/DeltaMerge/Segment.cpp:335
       0x7336bb4    DB::DM::DeltaMergeStore::DeltaMergeStore(DB::Context&, bool, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, unsigned int, long, bool, std::__1::vector<DB::DM::ColumnDefine, std::__1::allocator<DB::DM::ColumnDefine> > const&, DB::DM::ColumnDefine const&, bool, unsigned long, DB::DM::DeltaMergeStore::Settings const&, DB::ThreadPoolImpl<DB::ThreadFromGlobalPoolImpl<false> >*) [tiflash+120810420]
                    dbms/src/Storages/DeltaMerge/DeltaMergeStore.cpp:287
...

ti-chi-bot bot pushed a commit that referenced this issue May 15, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
affects-6.5 This bug affects the 6.5.x(LTS) versions. affects-7.1 This bug affects the 7.1.x(LTS) versions. affects-7.5 This bug affects the 7.5.x(LTS) versions. affects-8.1 This bug affects the 8.1.x(LTS) versions. component/storage severity/critical type/bug The issue is confirmed as a bug.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

1 participant