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.

Sign up for GitHub

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

Jump to bottom

tiflash crash frequently with error of HandleWriteRaftCmd failed #5648

Closed
lilinghai opened this issue Aug 18, 2022 · 1 comment
Closed

tiflash crash frequently with error of HandleWriteRaftCmd failed #5648

lilinghai opened this issue Aug 18, 2022 · 1 comment
Assignees
@CalvinNeo
Labels
affects-6.2 component/storage feature/developing severity/critical type/bug The issue is confirmed as a bug.

Comments

@lilinghai
Copy link

lilinghai commented Aug 18, 2022 •
edited by JaySon-Huang
Loading

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
@lilinghai lilinghai added the type/bug The issue is confirmed as a bug. label Aug 18, 2022
@flowbehappy flowbehappy assigned breezewish and CalvinNeo and unassigned breezewish Sep 8, 2022
@flowbehappy flowbehappy mentioned this issue Sep 8, 2022
Closed
@CalvinNeo CalvinNeo mentioned this issue Sep 9, 2022
Merged
12 tasks
@breezewish
Copy link
Member

Should be fixed in pingcap/tidb-engine-ext#165.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@CalvinNeo CalvinNeo

Labels
affects-6.2 component/storage feature/developing severity/critical type/bug The issue is confirmed as a bug.
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
6 participants
@breezewish @flowbehappy @jebter @CalvinNeo @lilinghai @ti-chi-bot