MPPTask failed to be cancel for a simple limit query
Open
Nobody has claimed this yet.
affects-6.5
component/compute
report/customer
type/bug
- Dominant language
- C++
- Stars
- 1k
- Forks
- 423
- Avg merge
- 1d 15h
- Merged PRs (30d)
- 24
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)
3. What did you see instead (Required)
The query is something like
select t.* from t where id=1234 limit 0, 101;
There are two tiflash, only one tiflash meet this problem.
[2025/08/11 14:25:54.046 +08:00] [INFO] [mpp_gather.go:83] ["Dispatch mpp task"] [timestamp=460034815828164615] [ID=1] [address=10.33.56.172:12256] [plan="Table(efi_voucherdtl_entry2025)->Sel([eq(cast(x.y.z, double BINARY), 1.686365039e+09)])->Limit->Send(-1, )"]
[2025/08/11 14:25:54.046 +08:00] [INFO] [mpp_gather.go:83] ["Dispatch mpp task"] [timestamp=460034815828164615] [ID=2] [address=30.88.0.4:12256] [plan="Table(efi_voucherdtl_entry2025)->Sel([eq(cast(x.y.z, double BINARY), 1.686365039e+09)])->Limit->Send(-1, )"]
[2025/08/11 14:25:55.073 +08:00] [WARN] [mpp.go:396] ["establish mpp connection meet error and cannot retry"] [error="rpc error: code = Canceled desc = context canceled"] [timestamp=460034815828164615] [task=2]
[2025/08/11 14:25:55.379 +08:00] [ERROR] [session.go:2671] ["Authentication failed with reason: 1"] [user=m] [host=30.88.47.245] ["auth user"=m] ["auth host"=%]
[2025/08/11 14:25:54.047 +08:00] [INFO] [FlashService.cpp:235] ["Handling mpp dispatch request, task meta: start_ts: 460034815828164615\ntask_id: 2\naddress: \"30.88.0.4:12256\"\n"] [source=FlashService] [thread_id=25842]
[2025/08/11 14:25:54.050 +08:00] [INFO] [FlashService.cpp:291] ["Handling establish mpp connection request: sender_meta {\n start_ts: 460034815828164615\n task_id: 2\n address: \"30.88.0.4:12256\"\n}\nreceiver_meta {\n start_ts: 460034815828164615\n task_id: -1\n}\n"] [source=FlashService] [thread_id=721]
[2025/08/11 14:25:54.079 +08:00] [INFO] [DeltaMergeStore.cpp:1602] ["Segment read tasks build done, cost=0ms sorted_ranges=39 n_tasks_before_split=38 n_tasks_final=38 n_ranges_final=76"] [source="table_id=102865 MPP<query:460034815828164615,task:2> table_id=102865"] [thread_id=775]
[2025/08/11 14:25:54.079 +08:00] [INFO] [DeltaMergeStore.cpp:999] ["Read create segment snapshot done, keep_order=false dt_enable_read_thread=true enable_read_thread=true"] [source="table_id=102865 MPP<query:460034815828164615,task:2> table_id=102865"] [thread_id=775]
[2025/08/11 14:25:54.081 +08:00] [INFO] [DeltaMergeStore.cpp:1052] ["Read create stream done, pool_id=40200105 num_streams=24"] [source="table_id=102865 MPP<query:460034815828164615,task:2> table_id=102865"] [thread_id=775]
[2025/08/11 14:25:54.082 +08:00] [INFO] [DeltaMergeStore.cpp:1602] ["Segment read tasks build done, cost=0ms sorted_ranges=2 n_tasks_before_split=1 n_tasks_final=1 n_ranges_final=1"] [source="table_id=102849 MPP<query:460034815828164615,task:2> table_id=102849"] [thread_id=775]
[2025/08/11 14:25:54.082 +08:00] [INFO] [DeltaMergeStore.cpp:999] ["Read create segment snapshot done, keep_order=false dt_enable_read_thread=true enable_read_thread=true"] [source="table_id=102849 MPP<query:460034815828164615,task:2> table_id=102849"] [thread_id=775]
[2025/08/11 14:25:54.082 +08:00] [INFO] [DeltaMergeStore.cpp:1052] ["Read create stream done, pool_id=40200106 num_streams=1"] [source="table_id=102849 MPP<query:460034815828164615,task:2> table_id=102849"] [thread_id=775]
[2025/08/11 14:25:54.082 +08:00] [INFO] [DeltaMergeStore.cpp:1602] ["Segment read tasks build done, cost=0ms sorted_ranges=2 n_tasks_before_split=1 n_tasks_final=1 n_ranges_final=1"] [source="table_id=16909 MPP<query:460034815828164615,task:2> table_id=16909"] [thread_id=775]
[2025/08/11 14:25:54.082 +08:00] [INFO] [DeltaMergeStore.cpp:999] ["Read create segment snapshot done, keep_order=false dt_enable_read_thread=true enable_read_thread=true"] [source="table_id=16909 MPP<query:460034815828164615,task:2> table_id=16909"] [thread_id=775]
[2025/08/11 14:25:54.082 +08:00] [INFO] [DeltaMergeStore.cpp:1052] ["Read create stream done, pool_id=40200107 num_streams=1"] [source="table_id=16909 MPP<query:460034815828164615,task:2> table_id=16909"] [thread_id=775]
[2025/08/11 14:25:54.082 +08:00] [INFO] [DeltaMergeStore.cpp:1602] ["Segment read tasks build done, cost=0ms sorted_ranges=1 n_tasks_before_split=1 n_tasks_final=1 n_ranges_final=1"] [source="table_id=102833 MPP<query:460034815828164615,task:2> table_id=102833"] [thread_id=775]
[2025/08/11 14:25:54.082 +08:00] [INFO] [DeltaMergeStore.cpp:999] ["Read create segment snapshot done, keep_order=false dt_enable_read_thread=true enable_read_thread=true"] [source="table_id=102833 MPP<query:460034815828164615,task:2> table_id=102833"] [thread_id=775]
[2025/08/11 14:25:54.082 +08:00] [INFO] [DeltaMergeStore.cpp:1052] ["Read create stream done, pool_id=40200108 num_streams=1"] [source="table_id=102833 MPP<query:460034815828164615,task:2> table_id=102833"] [thread_id=775]
[2025/08/11 14:25:54.083 +08:00] [INFO] [DeltaMergeStore.cpp:1602] ["Segment read tasks build done, cost=0ms sorted_ranges=1 n_tasks_before_split=1 n_tasks_final=1 n_ranges_final=1"] [source="table_id=16893 MPP<query:460034815828164615,task:2> table_id=16893"] [thread_id=775]
[2025/08/11 14:25:54.083 +08:00] [INFO] [DeltaMergeStore.cpp:999] ["Read create segment snapshot done, keep_order=false dt_enable_read_thread=true enable_read_thread=true"] [source="table_id=16893 MPP<query:460034815828164615,task:2> table_id=16893"] [thread_id=775]
[2025/08/11 14:25:54.083 +08:00] [INFO] [DeltaMergeStore.cpp:1052] ["Read create stream done, pool_id=40200109 num_streams=1"] [source="table_id=16893 MPP<query:460034815828164615,task:2> table_id=16893"] [thread_id=775]
[2025/08/11 14:25:54.084 +08:00] [INFO] [DeltaMergeStore.cpp:1602] ["Segment read tasks build done, cost=0ms sorted_ranges=149 n_tasks_before_split=103 n_tasks_final=103 n_ranges_final=216"] [source="table_id=16885 MPP<query:460034815828164615,task:2> table_id=16885"] [thread_id=775]
[2025/08/11 14:25:54.084 +08:00] [INFO] [DeltaMergeStore.cpp:999] ["Read create segment snapshot done, keep_order=false dt_enable_read_thread=true enable_read_thread=true"] [source="table_id=16885 MPP<query:460034815828164615,task:2> table_id=16885"] [thread_id=775]
[2025/08/11 14:25:54.086 +08:00] [INFO] [DeltaMergeStore.cpp:1052] ["Read create stream done, pool_id=40200110 num_streams=24"] [source="table_id=16885 MPP<query:460034815828164615,task:2> table_id=16885"] [thread_id=775]
[2025/08/11 14:25:54.161 +08:00] [INFO] [executeQuery.cpp:439] ["Query pipeline:\nUnion: <for mpp>\n ExchangeSender x 24\n Expression: <final projection>\n SharedQuery: <restore concurrency>\n Limit, limit = 101\n Union: <for partial limit>\n Limit x 24, limit = 101\n Expression: <table scan schema projection>\n Expression: <projection after push down filter>\n Filter: <push down filter>\n Multiplex\n UnorderedInputStream x 52\n"] [source=MPP<query:460034815828164615,task:2>] [thread_id=775]
[2025/08/11 14:25:54.161 +08:00] [INFO] [MinTSOScheduler.cpp:271] ["min_tso query is updated from 18446744073709551615 to 460034815828164615 when directly schedule it, used threads = 0, 0 active and 0 waiting queries."] [thread_id=775]
[2025/08/11 14:25:54.161 +08:00] [INFO] [MPPTask.cpp:374] ["task starts running, time cost in schedule: 0 ms, time cost in preprocess 111 ms"] [source=MPP<query:460034815828164615,task:2>] [thread_id=775]
[2025/08/11 14:25:55.073 +08:00] [INFO] [FlashService.cpp:363] ["cancel mpp task request: meta {\n start_ts: 460034815828164615\n}\n"] [source=FlashService] [thread_id=25538]
[2025/08/11 14:25:55.073 +08:00] [WARN] [MPPTaskManager.cpp:152] ["Begin to abort query: 460034815828164615, abort type: ONCANCELLATION, reason: Receive cancel request from TiDB"] [thread_id=25538]
[2025/08/11 14:25:55.073 +08:00] [INFO] [MinTSOScheduler.cpp:271] ["min_tso query is updated from 460034815828164615 to 18446744073709551615 when cancelling it, used threads = 50, 0 active and 0 waiting queries."] [thread_id=25538]
[2025/08/11 14:25:55.073 +08:00] [WARN] [MPPTaskManager.cpp:195] ["Remaining task in query 460034815828164615 are: MPP<query:460034815828164615,task:2> "] [thread_id=25538]
[2025/08/11 14:25:55.073 +08:00] [WARN] [MPPTask.cpp:478] ["Begin abort task: MPP<query:460034815828164615,task:2>, abort type: ONCANCELLATION"] [source=MPP<query:460034815828164615,task:2>] [thread_id=25538]
[2025/08/11 14:25:55.073 +08:00] [INFO] [EstablishCall.cpp:215] ["connection for tunnel2+-1 cost 1022 ms, including 0 ms to waiting task."] [source="MPP<query:460034815828164615,task:2> tunnel2+-1"] [thread_id=2010]
[2025/08/11 14:25:55.073 +08:00] [WARN] [MPPTask.cpp:507] ["Finish abort task from running"] [source=MPP<query:460034815828164615,task:2>] [thread_id=25538]
[2025/08/11 14:25:55.073 +08:00] [WARN] [MPPTaskManager.cpp:207] ["Finish abort query: 460034815828164615"] [thread_id=25538]
[2025/08/11 14:25:55.074 +08:00] [INFO] [MPPTask.cpp:388] ["mpp task finish execute, success: false, status: CANCELLED"] [source=MPP<query:460034815828164615,task:2>] [thread_id=775]
[2025/08/11 14:25:55.074 +08:00] [INFO] [MPPTaskStatistics.cpp:126] ["{\"query_tso\":460034815828164615,\"task_id\":2,\"is_root\":true,\"sender_executor_id\":\"ExchangeSender_20\",\"executors\":[{\"id\":\"ExchangeSender_20\",\"type\":\"ExchangeSender\",\"children\":[\"Limit_19\"],\"outbound_rows\":8,\"outbound_blocks\":2,\"outbound_bytes\":14456,\"execution_time_ns\":912010069,\"partition_num\":1,\"sender_target_task_ids\":[-1],\"exchange_type\":\"PassThrough\",\"connection_details\":[{\"tunnel_id\":\"tunnel2+-1\",\"sender_target_task_id\":-1,\"sender_target_host\":\"10.33.58.75:38168\",\"is_local\":false,\"packets\":0,\"bytes\":0}]},{\"id\":\"Limit_19\",\"type\":\"Limit\",\"children\":[\"Selection_18\"],\"outbound_rows\":8,\"outbound_blocks\":2,\"outbound_bytes\":14456,\"execution_time_ns\":783008645},{\"id\":\"Selection_18\",\"type\":\"Selection\",\"children\":[\"TableFullScan_17\"],\"outbound_rows\":8,\"outbound_blocks\":2,\"outbound_bytes\":14456,\"execution_time_ns\":783008645},{\"id\":\"TableFullScan_17\",\"type\":\"TableScan\",\"children\":[],\"outbound_rows\":3145728,\"outbound_blocks\":48,\"outbound_bytes\":5769682933,\"execution_time_ns\":891009837,\"connection_details\":[{\"is_local\":true,\"packets\":0,\"bytes\":5769682933},{\"is_local\":false,\"packets\":0,\"bytes\":0}],\"scan_details\":{\"create_inputstream_time\":\"253ms\",\"create_snapshot_time\":\"0ms\",\"delta_bytes\":489102486,\"delta_rows\":257823,\"dmfile_read_time\":\"19391ms\",\"dmfile_scan_rows\":6281260,\"dmfile_skip_rows\":499712,\"mvcc_input_bytes\":7346526167,\"mvcc_input_rows\":3999231,\"mvcc_output_rows\":3999231,\"num_columns\":177,\"num_read_tasks\":145,\"num_segments\":145}}],\"host\":\"30.88.0.4:12256\",\"task_init_timestamp\":1754893554047884000,\"task_start_timestamp\":1754893554161757000,\"task_end_timestamp\":1754893555074697000,\"compile_start_timestamp\":1754893554049800000,\"compile_end_timestamp\":1754893554161725000,\"read_wait_index_start_timestamp\":1754893554051886000,\"read_wait_index_end_timestamp\":1754893554076808000,\"local_input_bytes\":5769682933,\"remote_input_bytes\":0,\"output_bytes\":14456,\"status\":\"CANCELLED\",\"error_message\":\"Receive cancel request from TiDB\",\"working_time\":0,\"memory_peak\":0}"] [source="mpp_task_tracing MPP<query:460034815828164615,task:2>"] [thread_id=775]
[2025/08/11 14:25:55.074 +08:00] [INFO] [MPPTask.cpp:74] ["finish MPPTask: MPP<query:460034815828164615,task:2>"] [source=MPP<query:460034815828164615,task:2>] [thread_id=775]
[2025/08/11 14:25:55.085 +08:00] [ERROR] [Exception.cpp:93] ["virtual DB::SharedQueryBlockInputStream::~SharedQueryBlockInputStream(): Code: 0, e.displayText() = DB::Exception: Query was cancelled, e.what() = DB::Exception, Stack trace:\n\n\n 0x17620ce\tDB::Exception::Exception(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, int) [tiflash+24518862]\n \tdbms/src/Common/Exception.h:46\n 0x1872d7e\tDB::SharedQueryBlockInputStream::waitThread() [tiflash+25636222]\n \tdbms/src/DataStreams/SharedQueryBlockInputStream.h:183\n 0x18722ea\tDB::SharedQueryBlockInputStream::readSuffix() [tiflash+25633514]\n \tdbms/src/DataStreams/SharedQueryBlockInputStream.h:86\n 0x18723ac\tDB::SharedQueryBlockInputStream::~SharedQueryBlockInputStream() [tiflash+25633708]\n \tdbms/src/DataStreams/SharedQueryBlockInputStream.h:54\n 0x1838f1e\tDB::IBlockInputStream::~IBlockInputStream() [tiflash+25399070]\n \tdbms/src/DataStreams/IBlockInputStream.h:111\n 0x1838f1e\tDB::IBlockInputStream::~IBlockInputStream() [tiflash+25399070]\n \tdbms/src/DataStreams/IBlockInputStream.h:111\n 0x1838f1e\tDB::IBlockInputStream::~IBlockInputStream() [tiflash+25399070]\n \tdbms/src/DataStreams/IBlockInputStream.h:111\n 0x6e5c31c\tDB::UnionBlockInputStream<(DB::StreamUnionMode)0, true>::~UnionBlockInputStream() [tiflash+115720988]\n \tdbms/src/DataStreams/UnionBlockInputStream.h:135\n 0x67b1330\tstd::__1::__shared_ptr_emplace<DB::ProcessListEntry, std::__1::allocator<DB::ProcessListEntry> >::__on_zero_shared() [tiflash+108729136]\n \t/usr/local/bin/../include/c++/v1/__memory/shared_ptr.h:315\n 0x63d0daa\tDB::DAGContext::~DAGContext() [tiflash+104664490]\n \tdbms/src/Flash/Coprocessor/DAGContext.h:126\n 0x6e9a6db\tDB::MPPTask::~MPPTask() [tiflash+115975899]\n \tdbms/src/Flash/Mpp/MPPTask.cpp:75\n 0x6e93d27\tstd::__1::__shared_ptr_pointer<DB::MPPTask*, std::__1::shared_ptr<DB::MPPTask>::__shared_ptr_default_delete<DB::MPPTask, DB::MPPTask>, std::__1::allocator<DB::MPPTask> >::__on_zero_shared() [tiflash+115948839]\n \t/usr/local/bin/../include/c++/v1/__memory/shared_ptr.h:267\n 0x6ea27c1\tstd::__1::__function::__func<DB::MPPTask::run()::$_13, std::__1::allocator<DB::MPPTask::run()::$_13>, void ()>::destroy() [tiflash+116008897]\n \t/usr/local/bin/../include/c++/v1/__functional/function.h:327\n 0x1847df4\tDB::ExecutableTask<auto DB::wrapInvocable<std::__1::function<void ()> >(bool, std::__1::function<void ()>&&)::'lambda'()>::~ExecutableTask() [tiflash+25460212]\n \tdbms/src/Common/ExecutableTask.h:46\n 0x184af48\tDB::DynamicThreadPool::executeTask(std::__1::unique_ptr<DB::IExecutableTask, std::__1::default_delete<DB::IExecutableTask> >&) [tiflash+25472840]\n \tdbms/src/Common/DynamicThreadPool.cpp:102\n 0x184a590\tDB::DynamicThreadPool::fixedWork(unsigned long) [tiflash+25470352]\n \tdbms/src/Common/DynamicThreadPool.cpp:115\n 0x184b682\tvoid* std::__1::__thread_proxy<std::__1::tuple<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct> >, std::__1::thread DB::ThreadFactory::newThread<void (DB::DynamicThreadPool::*)(unsigned long), DB::DynamicThreadPool*, unsigned long&>(bool, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, void (DB::DynamicThreadPool::*&&)(unsigned long), DB::DynamicThreadPool*&&, unsigned long&)::'lambda'(auto&&...), DB::DynamicThreadPool*, unsigned long> >(void*) [tiflash+25474690]\n \t/usr/local/bin/../include/c++/v1/thread:291\n 0x7fe86b3d9ea5\tstart_thread [libpthread.so.0+32421]\n 0x7fe86a7de96d\t__clone [libc.so.6+1042797]"] [source="Limit MPP<query:460034815828164615,task:2>"] [thread_id=775]
[2025/08/11 14:36:42.400 +08:00] [WARN] [PageDirectory.cpp:1608] ["Meet a stale snapshot [thread id=775] [tracing id=MPP<query:460034815828164615,task:2> table_id=102865] [seq=2162921] [alive time(s)=648.320648822]"] [source=__global__.meta] [thread_id=24]
[2025/08/11 14:36:42.400 +08:00] [WARN] [PageDirectory.cpp:1608] ["Meet a stale snapshot [thread id=775] [tracing id=MPP<query:460034815828164615,task:2> table_id=102849] [seq=2162921] [alive time(s)=648.317918479]"] [source=__global__.meta] [thread_id=24]
[2025/08/11 14:36:42.400 +08:00] [WARN] [PageDirectory.cpp:1608] ["Meet a stale snapshot [thread id=775] [tracing id=MPP<query:460034815828164615,task:2> table_id=16909] [seq=2162921] [alive time(s)=648.31763543]"] [source=__global__.meta] [thread_id=24]
4. What is your TiFlash version? (Required)
v6.5.7
Contributor guide
No contributing guide indexed for this repository
First steps
- Read the whole issue, then the project's contributing guide.
- Comment on the issue to say you are picking it up — it saves two people doing the same work.
- Fork the repository and make your change on a branch.
- Open a pull request that references the issue number.
Research direction
Start by tracing the cancellation flow through FlashService.cpp, MPPTaskManager.cpp, MPPTask.cpp, EstablishCall.cpp, and the related mpp_gather.go and mpp.go log points. Reproduce the simple LIMIT query with the supplied two-TiFlash setup, then determine why the task is cancelled and verify that cancellation behaves correctly without the reported failure.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- cpp, sql
- Domain
- databases, distributed-systems
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Needs clarification
- Newbie friendliness
- 30/100