Skip to content

tiflash crash frequently with error of HandleWriteRaftCmd failed #5648

New issue
New issue
Closed
Closed
tiflash crash frequently with error of HandleWriteRaftCmd failed#5648
Assignees
CalvinNeo
Labels
affects-6.2component/storagefeature/developingseverity/criticaltype/bugThe issue is confirmed as a bug.
@lilinghai

Description

@lilinghai
lilinghai
opened on Aug 18, 2022

Bug Report

Please answer these questions before submitting your issue. Thanks!

1. Minimal reproduce step (Required)

[2022/08/18 11:07:07.779 +08:00] [ERROR] [Exception.cpp:89] ["DB::EngineStoreApplyRes DB::HandleWriteRaftCmd(const DB::EngineStoreServerWrap *, DB::WriteCmdsView, DB::RaftCmdHeader):Code: 9008, e.displayText() = DB::Exception: Raw TiDB PK: 80000000000002AC, Prewrite ts: 435366236227108872 can not found in default cf for key: 7480000000000038FF485F728000000000FF0002AC0000000000FAF9F544B6F9C7FFD6, e.what() = DB::Exception, Stack trace:


       0x6d3eb5f    DB::RegionData::readDataByWriteIt(std::__1::__map_const_iterator<std::__1::__tree_const_iterator<std::__1::__value_type<std::__1::pair<DB::RawTiDBPK, unsigned long>, std::__1::tuple<std::__1::shared_ptr<DB::StringObject<true> const>, std::__1::shared_ptr<DB::StringObject<false> const>, DB::RecordKVFormat::InnerDecodedWriteCFValue> >, std::__1::__tree_node<std::__1::__value_type<std::__1::pair<DB::RawTiDBPK, unsigned long>, std::__1::tuple<std::__1::shared_ptr<DB::StringObject<true> const>, std::__1::shared_ptr<DB::StringObject<false> const>, DB::RecordKVFormat::InnerDecodedWriteCFValue> >, void*>*, long> > const&, bool) const [tiflash+114551647]
                    dbms/src/Storages/Transaction/RegionData.cpp:132
       0x6d0a149    DB::ReadRegionCommitCache(std::__1::shared_ptr<DB::Region> const&, bool) [tiflash+114336073]
                    dbms/src/Storages/Transaction/PartitionStreams.cpp:293
       0x6d0a720    DB::RegionTable::writeBlockByRegion(DB::Context&, DB::RegionPtrWithBlock const&, std::__1::vector<std::__1::tuple<DB::RawTiDBPK, unsigned char, unsigned long, std::__1::shared_ptr<DB::StringObject<false> const> >, std::__1::allocator<std::__1::tuple<DB::RawTiDBPK, unsigned char, unsigned long, std::__1::shared_ptr<DB::StringObject<false> const> > > >&, Poco::Logger*, bool) [tiflash+114337568]
                    dbms/src/Storages/Transaction/PartitionStreams.cpp:357
       0x6d2bd1d    DB::Region::handleWriteRaftCmd(DB::WriteCmdsView const&, unsigned long, unsigned long, DB::TMTContext&) [tiflash+114474269]
                    dbms/src/Storages/Transaction/Region.cpp:712
       0x6cf5efe    DB::KVStore::handleWriteRaftCmd(DB::WriteCmdsView const&, unsigned long, unsigned long, unsigned long, DB::TMTContext&) [tiflash+114253566]
                    dbms/src/Storages/Transaction/KVStore.cpp:287
       0x6d11535    HandleWriteRaftCmd [tiflash+114365749]
                    dbms/src/Storages/Transaction/ProxyFFI.cpp:94
  0x7f6ee3b82f35    raftstore::store::fsm::apply::ApplyDelegate$LT$EK$GT$::process_raft_cmd::h014208262e72074a [libtiflash_proxy.so+26382133]
  0x7f6ee3b7c11c    raftstore::store::fsm::apply::ApplyDelegate$LT$EK$GT$::handle_raft_committed_entries::h49ed5e6607aca670 [libtiflash_proxy.so+26353948]
  0x7f6ee3b9c691    raftstore::store::fsm::apply::ApplyFsm$LT$EK$GT$::handle_apply::h2f934294220474ab [libtiflash_proxy.so+26486417]
  0x7f6ee3b9f8f1    raftstore::store::fsm::apply::ApplyFsm$LT$EK$GT$::handle_tasks::hb16107e9fe07791f [libtiflash_proxy.so+26499313]
  0x7f6ee3ba22d0    _$LT$raftstore..store..fsm..apply..ApplyPoller$LT$EK$GT$$u20$as$u20$batch_system..batch..PollHandler$LT$raftstore..store..fsm..apply..ApplyFsm$LT$EK$GT$$C$raftstore..store..fsm..apply..ControlFsm$GT$$GT$::handle_normal::hfcc23133d633a8b7 [libtiflash_proxy.so+26510032]
  0x7f6ee36afa1b    batch_system::batch::Poller$LT$N$C$C$C$Handler$GT$::poll::hdf420fe5ef93c365 [libtiflash_proxy.so+21322267]
  0x7f6ee3f0f628    std::sys_common::backtrace::__rust_begin_short_backtrace::h4c6fdb2ef86273be [libtiflash_proxy.so+30103080]
  0x7f6ee35a4b91    core::ops::function::FnOnce::call_once$u7b$$u7b$vtable.shim$u7d$$u7d$::hf53d0a45851da92f [libtiflash_proxy.so+20229009]
  0x7f6ee468cb1a    std::sys::unix::thread::Thread::new::thread_start::hd39c5f08bdcda277 [libtiflash_proxy.so+37956378]
  0x7f6ee1937ea5    start_thread [libpthread.so.0+32421]
  0x7f6ee144a96d    __clone [libc.so.6+1042797]"] [thread_id=120]
[2022/08/18 11:07:07.779 +08:00] [ERROR] [Exception.cpp:89] ["DB::EngineStoreApplyRes DB::HandleWriteRaftCmd(const DB::EngineStoreServerWrap *, DB::WriteCmdsView, DB::RaftCmdHeader):Code: 9008, e.displayText() = DB::Exception: Raw TiDB PK: 80000000000002E7, Prewrite ts: 435366236227108903 can not found in default cf for key: 7480000000000038FF415F728000000000FF0002E70000000000FAF9F544B6F9C7FFD7, e.what() = DB::Exception, Stack trace:


       0x6d3eb5f    DB::RegionData::readDataByWriteIt(std::__1::__map_const_iterator<std::__1::__tree_const_iterator<std::__1::__value_type<std::__1::pair<DB::RawTiDBPK, unsigned long>, std::__1::tuple<std::__1::shared_ptr<DB::StringObject<true> const>, std::__1::shared_ptr<DB::StringObject<false> const>, DB::RecordKVFormat::InnerDecodedWriteCFValue> >, std::__1::__tree_node<std::__1::__value_type<std::__1::pair<DB::RawTiDBPK, unsigned long>, std::__1::tuple<std::__1::shared_ptr<DB::StringObject<true> const>, std::__1::shared_ptr<DB::StringObject<false> const>, DB::RecordKVFormat::InnerDecodedWriteCFValue> >, void*>*, long> > const&, bool) const [tiflash+114551647]
                    dbms/src/Storages/Transaction/RegionData.cpp:132
       0x6d0a149    DB::ReadRegionCommitCache(std::__1::shared_ptr<DB::Region> const&, bool) [tiflash+114336073]
                    dbms/src/Storages/Transaction/PartitionStreams.cpp:293
       0x6d0a720    DB::RegionTable::writeBlockByRegion(DB::Context&, DB::RegionPtrWithBlock const&, std::__1::vector<std::__1::tuple<DB::RawTiDBPK, unsigned char, unsigned long, std::__1::shared_ptr<DB::StringObject<false> const> >, std::__1::allocator<std::__1::tuple<DB::RawTiDBPK, unsigned char, unsigned long, std::__1::shared_ptr<DB::StringObject<false> const> > > >&, Poco::Logger*, bool) [tiflash+114337568]
                    dbms/src/Storages/Transaction/PartitionStreams.cpp:357
       0x6d2bd1d    DB::Region::handleWriteRaftCmd(DB::WriteCmdsView const&, unsigned long, unsigned long, DB::TMTContext&) [tiflash+114474269]
                    dbms/src/Storages/Transaction/Region.cpp:712
       0x6cf5efe    DB::KVStore::handleWriteRaftCmd(DB::WriteCmdsView const&, unsigned long, unsigned long, unsigned long, DB::TMTContext&) [tiflash+114253566]
                    dbms/src/Storages/Transaction/KVStore.cpp:287
       0x6d11535    HandleWriteRaftCmd [tiflash+114365749]
                    dbms/src/Storages/Transaction/ProxyFFI.cpp:94
  0x7f6ee3b82f35    raftstore::store::fsm::apply::ApplyDelegate$LT$EK$GT$::process_raft_cmd::h014208262e72074a [libtiflash_proxy.so+26382133]
  0x7f6ee3b7c11c    raftstore::store::fsm::apply::ApplyDelegate$LT$EK$GT$::handle_raft_committed_entries::h49ed5e6607aca670 [libtiflash_proxy.so+26353948]
  0x7f6ee3b9c691    raftstore::store::fsm::apply::ApplyFsm$LT$EK$GT$::handle_apply::h2f934294220474ab [libtiflash_proxy.so+26486417]
  0x7f6ee3b9f8f1    raftstore::store::fsm::apply::ApplyFsm$LT$EK$GT$::handle_tasks::hb16107e9fe07791f [libtiflash_proxy.so+26499313]
  0x7f6ee3ba22d0    _$LT$raftstore..store..fsm..apply..ApplyPoller$LT$EK$GT$$u20$as$u20$batch_system..batch..PollHandler$LT$raftstore..store..fsm..apply..ApplyFsm$LT$EK$GT$$C$raftstore..store..fsm..apply..ControlFsm$GT$$GT$::handle_normal::hfcc23133d633a8b7 [libtiflash_proxy.so+26510032]
  0x7f6ee36afa1b    batch_system::batch::Poller$LT$N$C$C$C$Handler$GT$::poll::hdf420fe5ef93c365 [libtiflash_proxy.so+21322267]
  0x7f6ee3f0f628    std::sys_common::backtrace::__rust_begin_short_backtrace::h4c6fdb2ef86273be [libtiflash_proxy.so+30103080]
  0x7f6ee35a4b91    core::ops::function::FnOnce::call_once$u7b$$u7b$vtable.shim$u7d$$u7d$::hf53d0a45851da92f [libtiflash_proxy.so+20229009]
  0x7f6ee468cb1a    std::sys::unix::thread::Thread::new::thread_start::hd39c5f08bdcda277 [libtiflash_proxy.so+37956378]
  0x7f6ee1937ea5    start_thread [libpthread.so.0+32421]
  0x7f6ee144a96d    __clone [libc.so.6+1042797]"] [thread_id=119]
[2022/08/18 11:07:07.779 +08:00] [ERROR] [Exception.cpp:89] ["DB::EngineStoreApplyRes DB::HandleWriteRaftCmd(const DB::EngineStoreServerWrap *, DB::WriteCmdsView, DB::RaftCmdHeader):Code: 9008, e.displayText() = DB::Exception: Raw TiDB PK: 800000000000027A, Prewrite ts: 435366236227108903 can not found in default cf for key: 7480000000000038FF415F728000000000FF00027A0000000000FAF9F544B6F9C7FFD7, e.what() = DB::Exception, Stack trace:


       0x6d3eb5f    DB::RegionData::readDataByWriteIt(std::__1::__map_const_iterator<std::__1::__tree_const_iterator<std::__1::__value_type<std::__1::pair<DB::RawTiDBPK, unsigned long>, std::__1::tuple<std::__1::shared_ptr<DB::StringObject<true> const>, std::__1::shared_ptr<DB::StringObject<false> const>, DB::RecordKVFormat::InnerDecodedWriteCFValue> >, std::__1::__tree_node<std::__1::__value_type<std::__1::pair<DB::RawTiDBPK, unsigned long>, std::__1::tuple<std::__1::shared_ptr<DB::StringObject<true> const>, std::__1::shared_ptr<DB::StringObject<false> const>, DB::RecordKVFormat::InnerDecodedWriteCFValue> >, void*>*, long> > const&, bool) const [tiflash+114551647]
                    dbms/src/Storages/Transaction/RegionData.cpp:132
       0x6d0a149    DB::ReadRegionCommitCache(std::__1::shared_ptr<DB::Region> const&, bool) [tiflash+114336073]
                    dbms/src/Storages/Transaction/PartitionStreams.cpp:293
       0x6d0a720    DB::RegionTable::writeBlockByRegion(DB::Context&, DB::RegionPtrWithBlock const&, std::__1::vector<std::__1::tuple<DB::RawTiDBPK, unsigned char, unsigned long, std::__1::shared_ptr<DB::StringObject<false> const> >, std::__1::allocator<std::__1::tuple<DB::RawTiDBPK, unsigned char, unsigned long, std::__1::shared_ptr<DB::StringObject<false> const> > > >&, Poco::Logger*, bool) [tiflash+114337568]
                    dbms/src/Storages/Transaction/PartitionStreams.cpp:357
       0x6d2bd1d    DB::Region::handleWriteRaftCmd(DB::WriteCmdsView const&, unsigned long, unsigned long, DB::TMTContext&) [tiflash+114474269]
                    dbms/src/Storages/Transaction/Region.cpp:712
       0x6cf5efe    DB::KVStore::handleWriteRaftCmd(DB::WriteCmdsView const&, unsigned long, unsigned long, unsigned long, DB::TMTContext&) [tiflash+114253566]
                    dbms/src/Storages/Transaction/KVStore.cpp:287
       0x6d11535    HandleWriteRaftCmd [tiflash+114365749]
                    dbms/src/Storages/Transaction/ProxyFFI.cpp:94
  0x7f6ee3b82f35    raftstore::store::fsm::apply::ApplyDelegate$LT$EK$GT$::process_raft_cmd::h014208262e72074a [libtiflash_proxy.so+26382133]
  0x7f6ee3b7c11c    raftstore::store::fsm::apply::ApplyDelegate$LT$EK$GT$::handle_raft_committed_entries::h49ed5e6607aca670 [libtiflash_proxy.so+26353948]
  0x7f6ee3b9c691    raftstore::store::fsm::apply::ApplyFsm$LT$EK$GT$::handle_apply::h2f934294220474ab [libtiflash_proxy.so+26486417]
  0x7f6ee3b9f8f1    raftstore::store::fsm::apply::ApplyFsm$LT$EK$GT$::handle_tasks::hb16107e9fe07791f [libtiflash_proxy.so+26499313]
  0x7f6ee3ba22d0    _$LT$raftstore..store..fsm..apply..ApplyPoller$LT$EK$GT$$u20$as$u20$batch_system..batch..PollHandler$LT$raftstore..store..fsm..apply..ApplyFsm$LT$EK$GT$$C$raftstore..store..fsm..apply..ControlFsm$GT$$GT$::handle_normal::hfcc23133d633a8b7 [libtiflash_proxy.so+26510032]
  0x7f6ee36afa1b    batch_system::batch::Poller$LT$N$C$C$C$Handler$GT$::poll::hdf420fe5ef93c365 [libtiflash_proxy.so+21322267]
  0x7f6ee3f0f628    std::sys_common::backtrace::__rust_begin_short_backtrace::h4c6fdb2ef86273be [libtiflash_proxy.so+30103080]
  0x7f6ee35a4b91    core::ops::function::FnOnce::call_once$u7b$$u7b$vtable.shim$u7d$$u7d$::hf53d0a45851da92f [libtiflash_proxy.so+20229009]
  0x7f6ee468cb1a    std::sys::unix::thread::Thread::new::thread_start::hd39c5f08bdcda277 [libtiflash_proxy.so+37956378]
  0x7f6ee1937ea5    start_thread [libpthread.so.0+32421]
  0x7f6ee144a96d    __clone [libc.so.6+1042797]"] [thread_id=118]
[2022/08/18 11:07:07.779 +08:00] [ERROR] [Exception.cpp:89] ["DB::EngineStoreApplyRes DB::HandleWriteRaftCmd(const DB::EngineStoreServerWrap *, DB::WriteCmdsView, DB::RaftCmdHeader):Code: 9008, e.displayText() = DB::Exception: Raw TiDB PK: 8000000000000098, Prewrite ts: 435366236227108872 can not found in default cf for key: 7480000000000038FF485F728000000000FF0000980000000000FAF9F544B6F9C7FFD6, e.what() = DB::Exception, Stack trace:


       0x6d3eb5f    DB::RegionData::readDataByWriteIt(std::__1::__map_const_iterator<std::__1::__tree_const_iterator<std::__1::__value_type<std::__1::pair<DB::RawTiDBPK, unsigned long>, std::__1::tuple<std::__1::shared_ptr<DB::StringObject<true> const>, std::__1::shared_ptr<DB::StringObject<false> const>, DB::RecordKVFormat::InnerDecodedWriteCFValue> >, std::__1::__tree_node<std::__1::__value_type<std::__1::pair<DB::RawTiDBPK, unsigned long>, std::__1::tuple<std::__1::shared_ptr<DB::StringObject<true> const>, std::__1::shared_ptr<DB::StringObject<false> const>, DB::RecordKVFormat::InnerDecodedWriteCFValue> >, void*>*, long> > const&, bool) const [tiflash+114551647]
                    dbms/src/Storages/Transaction/RegionData.cpp:132
       0x6d0a149    DB::ReadRegionCommitCache(std::__1::shared_ptr<DB::Region> const&, bool) [tiflash+114336073]
                    dbms/src/Storages/Transaction/PartitionStreams.cpp:293
       0x6d0a720    DB::RegionTable::writeBlockByRegion(DB::Context&, DB::RegionPtrWithBlock const&, std::__1::vector<std::__1::tuple<DB::RawTiDBPK, unsigned char, unsigned long, std::__1::shared_ptr<DB::StringObject<false> const> >, std::__1::allocator<std::__1::tuple<DB::RawTiDBPK, unsigned char, unsigned long, std::__1::shared_ptr<DB::StringObject<false> const> > > >&, Poco::Logger*, bool) [tiflash+114337568]
                    dbms/src/Storages/Transaction/PartitionStreams.cpp:357
       0x6d2bd1d    DB::Region::handleWriteRaftCmd(DB::WriteCmdsView const&, unsigned long, unsigned long, DB::TMTContext&) [tiflash+114474269]
                    dbms/src/Storages/Transaction/Region.cpp:712
       0x6cf5efe    DB::KVStore::handleWriteRaftCmd(DB::WriteCmdsView const&, unsigned long, unsigned long, unsigned long, DB::TMTContext&) [tiflash+114253566]
                    dbms/src/Storages/Transaction/KVStore.cpp:287
       0x6d11535    HandleWriteRaftCmd [tiflash+114365749]
                    dbms/src/Storages/Transaction/ProxyFFI.cpp:94
  0x7f6ee3b82f35    raftstore::store::fsm::apply::ApplyDelegate$LT$EK$GT$::process_raft_cmd::h014208262e72074a [libtiflash_proxy.so+26382133]
  0x7f6ee3b7c11c    raftstore::store::fsm::apply::ApplyDelegate$LT$EK$GT$::handle_raft_committed_entries::h49ed5e6607aca670 [libtiflash_proxy.so+26353948]
  0x7f6ee3b9c691    raftstore::store::fsm::apply::ApplyFsm$LT$EK$GT$::handle_apply::h2f934294220474ab [libtiflash_proxy.so+26486417]
  0x7f6ee3b9f8f1    raftstore::store::fsm::apply::ApplyFsm$LT$EK$GT$::handle_tasks::hb16107e9fe07791f [libtiflash_proxy.so+26499313]
  0x7f6ee3ba22d0    _$LT$raftstore..store..fsm..apply..ApplyPoller$LT$EK$GT$$u20$as$u20$batch_system..batch..PollHandler$LT$raftstore..store..fsm..apply..ApplyFsm$LT$EK$GT$$C$raftstore..store..fsm..apply..ControlFsm$GT$$GT$::handle_normal::hfcc23133d633a8b7 [libtiflash_proxy.so+26510032]
  0x7f6ee36afa1b    batch_system::batch::Poller$LT$N$C$C$C$Handler$GT$::poll::hdf420fe5ef93c365 [libtiflash_proxy.so+21322267]
  0x7f6ee3f0f628    std::sys_common::backtrace::__rust_begin_short_backtrace::h4c6fdb2ef86273be [libtiflash_proxy.so+30103080]
  0x7f6ee35a4b91    core::ops::function::FnOnce::call_once$u7b$$u7b$vtable.shim$u7d$$u7d$::hf53d0a45851da92f [libtiflash_proxy.so+20229009]
  0x7f6ee468cb1a    std::sys::unix::thread::Thread::new::thread_start::hd39c5f08bdcda277 [libtiflash_proxy.so+37956378]
  0x7f6ee1937ea5    start_thread [libpthread.so.0+32421]
  0x7f6ee144a96d    __clone [libc.so.6+1042797]"] [thread_id=117]
[2022/08/18 11:07:07.780 +08:00] [ERROR] [BaseDaemon.cpp:377] [BaseDaemon:########################################] [thread_id=133]

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

3. What did you see instead (Required)

4. What is your TiFlash version? (Required)

master
1b9e714

Metadata

Metadata

Assignees

Labels

affects-6.2component/storagefeature/developingseverity/criticaltype/bugThe issue is confirmed as a bug.

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions