/root/doris/be/src/pipeline/pipeline_task.cpp
Line | Count | Source (jump to first uncovered line) |
1 | | // Licensed to the Apache Software Foundation (ASF) under one |
2 | | // or more contributor license agreements. See the NOTICE file |
3 | | // distributed with this work for additional information |
4 | | // regarding copyright ownership. The ASF licenses this file |
5 | | // to you under the Apache License, Version 2.0 (the |
6 | | // "License"); you may not use this file except in compliance |
7 | | // with the License. You may obtain a copy of the License at |
8 | | // |
9 | | // http://www.apache.org/licenses/LICENSE-2.0 |
10 | | // |
11 | | // Unless required by applicable law or agreed to in writing, |
12 | | // software distributed under the License is distributed on an |
13 | | // "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY |
14 | | // KIND, either express or implied. See the License for the |
15 | | // specific language governing permissions and limitations |
16 | | // under the License. |
17 | | |
18 | | #include "pipeline_task.h" |
19 | | |
20 | | #include <fmt/core.h> |
21 | | #include <fmt/format.h> |
22 | | #include <gen_cpp/Metrics_types.h> |
23 | | #include <glog/logging.h> |
24 | | |
25 | | #include <ostream> |
26 | | #include <vector> |
27 | | |
28 | | #include "common/logging.h" |
29 | | #include "common/status.h" |
30 | | #include "pipeline/dependency.h" |
31 | | #include "pipeline/exec/operator.h" |
32 | | #include "pipeline/exec/scan_operator.h" |
33 | | #include "pipeline/pipeline.h" |
34 | | #include "pipeline/pipeline_fragment_context.h" |
35 | | #include "pipeline/task_queue.h" |
36 | | #include "pipeline/task_scheduler.h" |
37 | | #include "runtime/descriptors.h" |
38 | | #include "runtime/exec_env.h" |
39 | | #include "runtime/query_context.h" |
40 | | #include "runtime/thread_context.h" |
41 | | #include "runtime/workload_group/workload_group_manager.h" |
42 | | #include "util/container_util.hpp" |
43 | | #include "util/defer_op.h" |
44 | | #include "util/mem_info.h" |
45 | | #include "util/runtime_profile.h" |
46 | | #include "util/uid_util.h" |
47 | | #include "vec/core/block.h" |
48 | | #include "vec/spill/spill_stream.h" |
49 | | |
50 | | namespace doris { |
51 | | class RuntimeState; |
52 | | } // namespace doris |
53 | | |
54 | | namespace doris::pipeline { |
55 | | |
56 | | PipelineTask::PipelineTask( |
57 | | PipelinePtr& pipeline, uint32_t task_id, RuntimeState* state, |
58 | | PipelineFragmentContext* fragment_context, RuntimeProfile* parent_profile, |
59 | | std::map<int, |
60 | | std::pair<std::shared_ptr<LocalExchangeSharedState>, std::shared_ptr<Dependency>>> |
61 | | le_state_map, |
62 | | int task_idx) |
63 | | : _index(task_id), |
64 | | _pipeline(pipeline), |
65 | | _opened(false), |
66 | | _state(state), |
67 | | _fragment_context(fragment_context), |
68 | | _parent_profile(parent_profile), |
69 | | _operators(pipeline->operators()), |
70 | | _source(_operators.front().get()), |
71 | | _root(_operators.back().get()), |
72 | | _sink(pipeline->sink_shared_pointer()), |
73 | | _le_state_map(std::move(le_state_map)), |
74 | | _task_idx(task_idx), |
75 | | _execution_dep(state->get_query_ctx()->get_execution_dependency()), |
76 | | _memory_sufficient_dependency( |
77 | 36 | state->get_query_ctx()->get_memory_sufficient_dependency()) { |
78 | 36 | _pipeline_task_watcher.start(); |
79 | | |
80 | 36 | auto shared_state = _sink->create_shared_state(); |
81 | 36 | if (shared_state) { |
82 | 5 | _sink_shared_state = shared_state; |
83 | 5 | } |
84 | 36 | } |
85 | | |
86 | | Status PipelineTask::prepare(const std::vector<TScanRangeParams>& scan_range, const int sender_id, |
87 | 5 | const TDataSink& tsink, QueryContext* query_ctx) { |
88 | 5 | DCHECK(_sink); |
89 | 5 | _init_profile(); |
90 | 5 | SCOPED_TIMER(_task_profile->total_time_counter()); |
91 | 5 | SCOPED_CPU_TIMER(_task_cpu_timer); |
92 | 5 | SCOPED_TIMER(_prepare_timer); |
93 | 5 | DBUG_EXECUTE_IF("fault_inject::PipelineXTask::prepare", { |
94 | 5 | Status status = Status::Error<INTERNAL_ERROR>("fault_inject pipeline_task prepare failed"); |
95 | 5 | return status; |
96 | 5 | }); |
97 | 5 | { |
98 | | // set sink local state |
99 | 5 | LocalSinkStateInfo info {_task_idx, _task_profile.get(), |
100 | 5 | sender_id, get_sink_shared_state().get(), |
101 | 5 | _le_state_map, tsink}; |
102 | 5 | RETURN_IF_ERROR(_sink->setup_local_state(_state, info)); |
103 | 5 | } |
104 | | |
105 | 5 | _scan_ranges = scan_range; |
106 | 5 | auto* parent_profile = _state->get_sink_local_state()->profile(); |
107 | | |
108 | 12 | for (int op_idx = _operators.size() - 1; op_idx >= 0; op_idx--) { |
109 | 7 | auto& op = _operators[op_idx]; |
110 | 7 | LocalStateInfo info {parent_profile, _scan_ranges, get_op_shared_state(op->operator_id()), |
111 | 7 | _le_state_map, _task_idx}; |
112 | 7 | RETURN_IF_ERROR(op->setup_local_state(_state, info)); |
113 | 7 | parent_profile = _state->get_local_state(op->operator_id())->profile(); |
114 | 7 | } |
115 | 5 | { |
116 | 5 | std::vector<Dependency*> filter_dependencies; |
117 | 5 | const auto& deps = _state->get_local_state(_source->operator_id())->filter_dependencies(); |
118 | 5 | std::copy(deps.begin(), deps.end(), |
119 | 5 | std::inserter(filter_dependencies, filter_dependencies.end())); |
120 | | |
121 | 5 | std::unique_lock<std::mutex> lc(_dependency_lock); |
122 | 5 | filter_dependencies.swap(_filter_dependencies); |
123 | 5 | } |
124 | 5 | if (query_context()->is_cancelled()) { |
125 | 0 | clear_blocking_state(); |
126 | 0 | } |
127 | 5 | return Status::OK(); |
128 | 5 | } |
129 | | |
130 | 5 | Status PipelineTask::_extract_dependencies() { |
131 | 5 | std::vector<std::vector<Dependency*>> read_dependencies; |
132 | 5 | std::vector<Dependency*> write_dependencies; |
133 | 5 | std::vector<Dependency*> finish_dependencies; |
134 | 5 | read_dependencies.resize(_operators.size()); |
135 | 5 | size_t i = 0; |
136 | 7 | for (auto& op : _operators) { |
137 | 7 | auto result = _state->get_local_state_result(op->operator_id()); |
138 | 7 | if (!result) { |
139 | 0 | return result.error(); |
140 | 0 | } |
141 | 7 | auto* local_state = result.value(); |
142 | 7 | read_dependencies[i] = local_state->dependencies(); |
143 | 7 | auto* fin_dep = local_state->finishdependency(); |
144 | 7 | if (fin_dep) { |
145 | 0 | finish_dependencies.push_back(fin_dep); |
146 | 0 | } |
147 | 7 | i++; |
148 | 7 | } |
149 | 5 | DBUG_EXECUTE_IF("fault_inject::PipelineXTask::_extract_dependencies", { |
150 | 5 | Status status = Status::Error<INTERNAL_ERROR>( |
151 | 5 | "fault_inject pipeline_task _extract_dependencies failed"); |
152 | 5 | return status; |
153 | 5 | }); |
154 | 5 | { |
155 | 5 | auto* local_state = _state->get_sink_local_state(); |
156 | 5 | write_dependencies = local_state->dependencies(); |
157 | 5 | auto* fin_dep = local_state->finishdependency(); |
158 | 5 | if (fin_dep) { |
159 | 5 | finish_dependencies.push_back(fin_dep); |
160 | 5 | } |
161 | 5 | } |
162 | 5 | { |
163 | 5 | std::unique_lock<std::mutex> lc(_dependency_lock); |
164 | 5 | read_dependencies.swap(_read_dependencies); |
165 | 5 | write_dependencies.swap(_write_dependencies); |
166 | 5 | finish_dependencies.swap(_finish_dependencies); |
167 | 5 | } |
168 | 5 | return Status::OK(); |
169 | 5 | } |
170 | | |
171 | 5 | void PipelineTask::_init_profile() { |
172 | 5 | _task_profile = |
173 | 5 | std::make_unique<RuntimeProfile>(fmt::format("PipelineTask (index={})", _index)); |
174 | 5 | _parent_profile->add_child(_task_profile.get(), true, nullptr); |
175 | 5 | _task_cpu_timer = ADD_TIMER(_task_profile, "TaskCpuTime"); |
176 | | |
177 | 5 | static const char* exec_time = "ExecuteTime"; |
178 | 5 | _exec_timer = ADD_TIMER(_task_profile, exec_time); |
179 | 5 | _prepare_timer = ADD_CHILD_TIMER(_task_profile, "PrepareTime", exec_time); |
180 | 5 | _open_timer = ADD_CHILD_TIMER(_task_profile, "OpenTime", exec_time); |
181 | 5 | _get_block_timer = ADD_CHILD_TIMER(_task_profile, "GetBlockTime", exec_time); |
182 | 5 | _get_block_counter = ADD_COUNTER(_task_profile, "GetBlockCounter", TUnit::UNIT); |
183 | 5 | _sink_timer = ADD_CHILD_TIMER(_task_profile, "SinkTime", exec_time); |
184 | 5 | _close_timer = ADD_CHILD_TIMER(_task_profile, "CloseTime", exec_time); |
185 | | |
186 | 5 | _wait_worker_timer = ADD_TIMER_WITH_LEVEL(_task_profile, "WaitWorkerTime", 1); |
187 | | |
188 | 5 | _schedule_counts = ADD_COUNTER(_task_profile, "NumScheduleTimes", TUnit::UNIT); |
189 | 5 | _yield_counts = ADD_COUNTER(_task_profile, "NumYieldTimes", TUnit::UNIT); |
190 | 5 | _core_change_times = ADD_COUNTER(_task_profile, "CoreChangeTimes", TUnit::UNIT); |
191 | 5 | _memory_reserve_times = ADD_COUNTER(_task_profile, "MemoryReserveTimes", TUnit::UNIT); |
192 | 5 | _memory_reserve_failed_times = |
193 | 5 | ADD_COUNTER(_task_profile, "MemoryReserveFailedTimes", TUnit::UNIT); |
194 | 5 | } |
195 | | |
196 | 5 | void PipelineTask::_fresh_profile_counter() { |
197 | 5 | COUNTER_SET(_schedule_counts, (int64_t)_schedule_time); |
198 | 5 | COUNTER_SET(_wait_worker_timer, (int64_t)_wait_worker_watcher.elapsed_time()); |
199 | 5 | } |
200 | | |
201 | 5 | Status PipelineTask::_open() { |
202 | 5 | SCOPED_TIMER(_task_profile->total_time_counter()); |
203 | 5 | SCOPED_CPU_TIMER(_task_cpu_timer); |
204 | 5 | SCOPED_TIMER(_open_timer); |
205 | 5 | _dry_run = _sink->should_dry_run(_state); |
206 | 7 | for (auto& o : _operators) { |
207 | 7 | auto* local_state = _state->get_local_state(o->operator_id()); |
208 | 7 | auto st = local_state->open(_state); |
209 | 7 | DCHECK(st.is<ErrorCode::PIP_WAIT_FOR_RF>() ? !_filter_dependencies.empty() : true) |
210 | 0 | << debug_string(); |
211 | 7 | RETURN_IF_ERROR(st); |
212 | 7 | } |
213 | 5 | RETURN_IF_ERROR(_state->get_sink_local_state()->open(_state)); |
214 | 5 | RETURN_IF_ERROR(_extract_dependencies()); |
215 | 5 | _block = doris::vectorized::Block::create_unique(); |
216 | 5 | DBUG_EXECUTE_IF("fault_inject::PipelineXTask::open", { |
217 | 5 | Status status = Status::Error<INTERNAL_ERROR>("fault_inject pipeline_task open failed"); |
218 | 5 | return status; |
219 | 5 | }); |
220 | 5 | _opened = true; |
221 | 5 | return Status::OK(); |
222 | 5 | } |
223 | | |
224 | 27 | bool PipelineTask::_wait_to_start() { |
225 | | // Before task starting, we should make sure |
226 | | // 1. Execution dependency is ready (which is controlled by FE 2-phase commit) |
227 | | // 2. Runtime filter dependencies are ready |
228 | 27 | _blocked_dep = _execution_dep->is_blocked_by(this); |
229 | 27 | if (_blocked_dep != nullptr) { |
230 | 5 | _blocked_dep->start_watcher(); |
231 | 5 | return true; |
232 | 5 | } |
233 | | |
234 | 22 | for (auto* op_dep : _filter_dependencies) { |
235 | 0 | _blocked_dep = op_dep->is_blocked_by(this); |
236 | 0 | if (_blocked_dep != nullptr) { |
237 | 0 | _blocked_dep->start_watcher(); |
238 | 0 | return true; |
239 | 0 | } |
240 | 0 | } |
241 | 22 | return false; |
242 | 22 | } |
243 | | |
244 | 31 | bool PipelineTask::_is_blocked() { |
245 | 31 | Defer defer([this] { |
246 | 31 | if (_blocked_dep != nullptr) { |
247 | 12 | _task_profile->add_info_string("TaskState", "Blocked"); |
248 | 12 | _task_profile->add_info_string("BlockedByDependency", _blocked_dep->name()); |
249 | 12 | } |
250 | 31 | }); |
251 | | |
252 | 31 | for (auto* spill_dependency : _spill_dependencies) { |
253 | 0 | _blocked_dep = spill_dependency->is_blocked_by(this); |
254 | 0 | if (_blocked_dep != nullptr) { |
255 | 0 | _blocked_dep->start_watcher(); |
256 | 0 | return true; |
257 | 0 | } |
258 | 0 | } |
259 | | |
260 | 31 | _blocked_dep = _memory_sufficient_dependency->is_blocked_by(this); |
261 | 31 | if (_blocked_dep != nullptr) { |
262 | 0 | _blocked_dep->start_watcher(); |
263 | 0 | return true; |
264 | 0 | } |
265 | | |
266 | | // `_dry_run = true` means we do not need data from source operator. |
267 | 31 | if (!_dry_run) { |
268 | 57 | for (int i = _read_dependencies.size() - 1; i >= 0; i--) { |
269 | | // `_read_dependencies` is organized according to operators. For each operator, running condition is met iff all dependencies are ready. |
270 | 39 | for (auto* dep : _read_dependencies[i]) { |
271 | 39 | _blocked_dep = dep->is_blocked_by(this); |
272 | 39 | if (_blocked_dep != nullptr) { |
273 | 11 | _blocked_dep->start_watcher(); |
274 | 11 | return true; |
275 | 11 | } |
276 | 39 | } |
277 | | // If all dependencies are ready for this operator, we can execute this task if no datum is needed from upstream operators. |
278 | 28 | if (!_operators[i]->need_more_input_data(_state)) { |
279 | 2 | break; |
280 | 2 | } |
281 | 28 | } |
282 | 31 | } |
283 | 20 | for (auto* op_dep : _write_dependencies) { |
284 | 20 | _blocked_dep = op_dep->is_blocked_by(this); |
285 | 20 | if (_blocked_dep != nullptr) { |
286 | 1 | _blocked_dep->start_watcher(); |
287 | 1 | return true; |
288 | 1 | } |
289 | 20 | } |
290 | 19 | return false; |
291 | 20 | } |
292 | | |
293 | 17 | Status PipelineTask::execute(bool* eos) { |
294 | 17 | const auto query_id = _state->query_id(); |
295 | 17 | if (_eos) { |
296 | 0 | *eos = true; |
297 | 0 | return Status::OK(); |
298 | 0 | } |
299 | | |
300 | 17 | SCOPED_TIMER(_task_profile->total_time_counter()); |
301 | 17 | SCOPED_TIMER(_exec_timer); |
302 | 17 | SCOPED_ATTACH_TASK(_state); |
303 | | |
304 | 17 | int64_t time_spent = 0; |
305 | 17 | DBUG_EXECUTE_IF("fault_inject::PipelineXTask::execute", { |
306 | 17 | Status status = Status::Error<INTERNAL_ERROR>("fault_inject pipeline_task execute failed"); |
307 | 17 | return status; |
308 | 17 | }); |
309 | 17 | ThreadCpuStopWatch cpu_time_stop_watch; |
310 | 17 | cpu_time_stop_watch.start(); |
311 | 17 | Defer defer {[&]() { |
312 | 17 | if (_task_queue) { |
313 | 17 | _task_queue->update_statistics(this, time_spent); |
314 | 17 | } |
315 | 17 | int64_t delta_cpu_time = cpu_time_stop_watch.elapsed_time(); |
316 | 17 | _task_cpu_timer->update(delta_cpu_time); |
317 | 17 | query_context()->resource_ctx()->cpu_context()->update_cpu_cost_ms(delta_cpu_time); |
318 | 17 | }}; |
319 | 17 | if (_wait_to_start()) { |
320 | 0 | if (config::enable_prefetch_tablet) { |
321 | 0 | RETURN_IF_ERROR(_source->hold_tablets(_state)); |
322 | 0 | } |
323 | 0 | return Status::OK(); |
324 | 0 | } |
325 | | |
326 | | // The status must be runnable |
327 | 17 | if (!_opened && !_fragment_context->is_canceled()) { |
328 | 5 | DBUG_EXECUTE_IF("PipelineTask::execute.open_sleep", { |
329 | 5 | auto required_pipeline_id = |
330 | 5 | DebugPoints::instance()->get_debug_param_or_default<int32_t>( |
331 | 5 | "PipelineTask::execute.open_sleep", "pipeline_id", -1); |
332 | 5 | auto required_task_id = DebugPoints::instance()->get_debug_param_or_default<int32_t>( |
333 | 5 | "PipelineTask::execute.open_sleep", "task_id", -1); |
334 | 5 | if (required_pipeline_id == pipeline_id() && required_task_id == task_id()) { |
335 | 5 | LOG(WARNING) << "PipelineTask::execute.open_sleep sleep 5s"; |
336 | 5 | sleep(5); |
337 | 5 | } |
338 | 5 | }); |
339 | | |
340 | 5 | if (_wake_up_early) { |
341 | 0 | *eos = true; |
342 | 0 | _eos = true; |
343 | 0 | return Status::OK(); |
344 | 0 | } |
345 | 5 | RETURN_IF_ERROR(_open()); |
346 | 5 | } |
347 | | |
348 | 17 | auto set_wake_up_and_dep_ready = [&]() { |
349 | 0 | if (wake_up_early()) { |
350 | 0 | return; |
351 | 0 | } |
352 | 0 | set_wake_up_early(); |
353 | 0 | clear_blocking_state(); |
354 | 0 | }; |
355 | | |
356 | 17 | _task_profile->add_info_string("TaskState", "Runnable"); |
357 | 17 | _task_profile->add_info_string("BlockedByDependency", ""); |
358 | | |
359 | 23 | while (!_fragment_context->is_canceled()) { |
360 | 23 | if (_is_blocked()) { |
361 | 12 | return Status::OK(); |
362 | 12 | } |
363 | | |
364 | | /// When a task is cancelled, |
365 | | /// its blocking state will be cleared and it will transition to a ready state (though it is not truly ready). |
366 | | /// Here, checking whether it is cancelled to prevent tasks in a blocking state from being re-executed. |
367 | 11 | if (_fragment_context->is_canceled()) { |
368 | 0 | break; |
369 | 0 | } |
370 | | |
371 | 11 | if (time_spent > THREAD_TIME_SLICE) { |
372 | 0 | COUNTER_UPDATE(_yield_counts, 1); |
373 | 0 | break; |
374 | 0 | } |
375 | 11 | if (_exec_state == State::NORMAL) { |
376 | 11 | _block->clear_column_data(_root->row_desc().num_materialized_slots()); |
377 | 11 | } |
378 | 11 | auto* block = _block.get(); |
379 | | |
380 | 11 | DBUG_EXECUTE_IF("fault_inject::PipelineXTask::executing", { |
381 | 11 | Status status = |
382 | 11 | Status::Error<INTERNAL_ERROR>("fault_inject pipeline_task executing failed"); |
383 | 11 | return status; |
384 | 11 | }); |
385 | | |
386 | | // `_sink->is_finished(_state)` means sink operator should be finished |
387 | 11 | if (_sink->is_finished(_state)) { |
388 | 0 | set_wake_up_and_dep_ready(); |
389 | 0 | } |
390 | | |
391 | | // `_dry_run` means sink operator need no more data |
392 | 11 | *eos = wake_up_early() || _dry_run; |
393 | 11 | auto workload_group = _state->get_query_ctx()->workload_group(); |
394 | 11 | if (!*eos) { |
395 | 11 | switch (_exec_state) { |
396 | 0 | case State::EOS: |
397 | 0 | *eos = true; |
398 | 0 | [[fallthrough]]; |
399 | 0 | case State::PENDING: { |
400 | 0 | LOG(INFO) << "Query: " << print_id(query_id) << " has pending block, size: " |
401 | 0 | << PrettyPrinter::print_bytes(_block->allocated_bytes()); |
402 | 0 | _exec_state = State::NORMAL; |
403 | 0 | break; |
404 | 0 | } |
405 | 11 | case State::NORMAL: { |
406 | 11 | SCOPED_TIMER(_get_block_timer); |
407 | 11 | if (_state->low_memory_mode()) { |
408 | 0 | _sink->set_low_memory_mode(_state); |
409 | 0 | _root->set_low_memory_mode(_state); |
410 | 0 | } |
411 | 11 | DEFER_RELEASE_RESERVED(); |
412 | 11 | _get_block_counter->update(1); |
413 | 11 | const auto reserve_size = _root->get_reserve_mem_size(_state); |
414 | 11 | _root->reset_reserve_mem_size(_state); |
415 | | |
416 | 11 | if (workload_group && _state->get_query_ctx()->enable_reserve_memory() && |
417 | 11 | reserve_size > 0) { |
418 | 0 | auto st = thread_context()->try_reserve_memory(reserve_size); |
419 | |
|
420 | 0 | COUNTER_UPDATE(_memory_reserve_times, 1); |
421 | 0 | if (!st.ok() && !_state->enable_force_spill()) { |
422 | 0 | COUNTER_UPDATE(_memory_reserve_failed_times, 1); |
423 | 0 | auto sink_revokable_mem_size = _sink->revocable_mem_size(_state); |
424 | 0 | auto debug_msg = fmt::format( |
425 | 0 | "Query: {} , try to reserve: {}, operator name: {}, operator " |
426 | 0 | "id: {}, " |
427 | 0 | "task id: " |
428 | 0 | "{}, root revocable mem size: {}, sink revocable mem size: {}, " |
429 | 0 | "failed: " |
430 | 0 | "{}", |
431 | 0 | print_id(query_id), PrettyPrinter::print_bytes(reserve_size), |
432 | 0 | _root->get_name(), _root->node_id(), _state->task_id(), |
433 | 0 | PrettyPrinter::print_bytes(_root->revocable_mem_size(_state)), |
434 | 0 | PrettyPrinter::print_bytes(sink_revokable_mem_size), |
435 | 0 | st.to_string()); |
436 | | // PROCESS_MEMORY_EXCEEDED error msg alread contains process_mem_log_str |
437 | 0 | if (!st.is<ErrorCode::PROCESS_MEMORY_EXCEEDED>()) { |
438 | 0 | debug_msg += fmt::format(", debug info: {}", |
439 | 0 | GlobalMemoryArbitrator::process_mem_log_str()); |
440 | 0 | } |
441 | 0 | LOG_EVERY_N(INFO, 100) << debug_msg; |
442 | | // If sink has enough revocable memory, trigger revoke memory |
443 | 0 | if (sink_revokable_mem_size >= _state->spill_min_revocable_mem()) { |
444 | 0 | LOG(INFO) << fmt::format( |
445 | 0 | "Query: {} sink: {}, node id: {}, task id: " |
446 | 0 | "{}, revocable mem size: {}", |
447 | 0 | print_id(query_id), _sink->get_name(), _sink->node_id(), |
448 | 0 | _state->task_id(), |
449 | 0 | PrettyPrinter::print_bytes(sink_revokable_mem_size)); |
450 | 0 | ExecEnv::GetInstance()->workload_group_mgr()->add_paused_query( |
451 | 0 | _state->get_query_ctx()->shared_from_this(), reserve_size, st); |
452 | 0 | continue; |
453 | 0 | } else { |
454 | | // If reserve failed, not add this query to paused list, because it is very small, will not |
455 | | // consume a lot of memory. But need set low memory mode to indicate that the system should |
456 | | // not use too much memory. |
457 | 0 | _state->get_query_ctx()->set_low_memory_mode(); |
458 | 0 | } |
459 | 0 | } |
460 | 0 | } |
461 | | |
462 | 11 | RETURN_IF_ERROR(_root->get_block_after_projects(_state, block, eos)); |
463 | 11 | break; |
464 | 11 | } |
465 | 11 | default: |
466 | 0 | __builtin_unreachable(); |
467 | 11 | } |
468 | 11 | } |
469 | | |
470 | 11 | if (!_block->empty() || *eos) { |
471 | 11 | SCOPED_TIMER(_sink_timer); |
472 | 11 | Status status = Status::OK(); |
473 | 11 | DEFER_RELEASE_RESERVED(); |
474 | 11 | COUNTER_UPDATE(_memory_reserve_times, 1); |
475 | 11 | if (_state->get_query_ctx()->enable_reserve_memory() && workload_group && |
476 | 11 | !(wake_up_early() || _dry_run)) { |
477 | 0 | const auto sink_reserve_size = _sink->get_reserve_mem_size(_state, *eos); |
478 | 0 | status = sink_reserve_size != 0 |
479 | 0 | ? thread_context()->try_reserve_memory(sink_reserve_size) |
480 | 0 | : Status::OK(); |
481 | |
|
482 | 0 | auto sink_revocable_mem_size = _sink->revocable_mem_size(_state); |
483 | 0 | if (status.ok() && _state->enable_force_spill() && _sink->is_spillable() && |
484 | 0 | sink_revocable_mem_size >= vectorized::SpillStream::MIN_SPILL_WRITE_BATCH_MEM) { |
485 | 0 | status = Status(ErrorCode::QUERY_MEMORY_EXCEEDED, "Force Spill"); |
486 | 0 | } |
487 | |
|
488 | 0 | if (!status.ok()) { |
489 | 0 | COUNTER_UPDATE(_memory_reserve_failed_times, 1); |
490 | 0 | auto debug_msg = fmt::format( |
491 | 0 | "Query: {} try to reserve: {}, sink name: {}, node id: {}, task id: " |
492 | 0 | "{}, sink revocable mem size: {}, failed: {}", |
493 | 0 | print_id(query_id), PrettyPrinter::print_bytes(sink_reserve_size), |
494 | 0 | _sink->get_name(), _sink->node_id(), _state->task_id(), |
495 | 0 | PrettyPrinter::print_bytes(sink_revocable_mem_size), |
496 | 0 | status.to_string()); |
497 | | // PROCESS_MEMORY_EXCEEDED error msg alread contains process_mem_log_str |
498 | 0 | if (!status.is<ErrorCode::PROCESS_MEMORY_EXCEEDED>()) { |
499 | 0 | debug_msg += fmt::format(", debug info: {}", |
500 | 0 | GlobalMemoryArbitrator::process_mem_log_str()); |
501 | 0 | } |
502 | | // If the operator is not spillable or it is spillable but not has much memory to spill |
503 | | // not need add to paused list, just let it go. |
504 | 0 | if (sink_revocable_mem_size >= |
505 | 0 | vectorized::SpillStream::MIN_SPILL_WRITE_BATCH_MEM) { |
506 | 0 | VLOG_DEBUG << debug_msg; |
507 | 0 | DCHECK(_exec_state == State::NORMAL); |
508 | 0 | _exec_state = *eos ? State::EOS : State::PENDING; |
509 | 0 | ExecEnv::GetInstance()->workload_group_mgr()->add_paused_query( |
510 | 0 | _state->get_query_ctx()->shared_from_this(), sink_reserve_size, |
511 | 0 | status); |
512 | 0 | *eos = false; |
513 | 0 | continue; |
514 | 0 | } else { |
515 | 0 | _state->get_query_ctx()->set_low_memory_mode(); |
516 | 0 | } |
517 | 0 | } |
518 | 0 | } |
519 | | |
520 | 11 | if (*eos) { |
521 | 5 | RETURN_IF_ERROR(close(Status::OK(), false)); |
522 | 5 | } |
523 | | |
524 | 11 | DBUG_EXECUTE_IF("PipelineTask::execute.sink_eos_sleep", { |
525 | 11 | auto required_pipeline_id = |
526 | 11 | DebugPoints::instance()->get_debug_param_or_default<int32_t>( |
527 | 11 | "PipelineTask::execute.sink_eos_sleep", "pipeline_id", -1); |
528 | 11 | auto required_task_id = |
529 | 11 | DebugPoints::instance()->get_debug_param_or_default<int32_t>( |
530 | 11 | "PipelineTask::execute.sink_eos_sleep", "task_id", -1); |
531 | 11 | if (required_pipeline_id == pipeline_id() && required_task_id == task_id()) { |
532 | 11 | LOG(WARNING) << "PipelineTask::execute.sink_eos_sleep sleep 10s"; |
533 | 11 | sleep(10); |
534 | 11 | } |
535 | 11 | }); |
536 | | |
537 | 11 | status = _sink->sink(_state, block, *eos); |
538 | | |
539 | 11 | if (status.is<ErrorCode::END_OF_FILE>()) { |
540 | 0 | set_wake_up_and_dep_ready(); |
541 | 11 | } else if (!status) { |
542 | 0 | return status; |
543 | 0 | } |
544 | | |
545 | 11 | if (*eos) { // just return, the scheduler will do finish work |
546 | 5 | _task_profile->add_info_string("TaskState", "Finished"); |
547 | 5 | _eos = true; |
548 | 5 | return Status::OK(); |
549 | 5 | } |
550 | 11 | } |
551 | 11 | } |
552 | | |
553 | 0 | RETURN_IF_ERROR(get_task_queue()->push_back(this)); |
554 | 0 | return Status::OK(); |
555 | 0 | } |
556 | | |
557 | 0 | void PipelineTask::finalize() { |
558 | 0 | std::unique_lock<std::mutex> lc(_dependency_lock); |
559 | 0 | _finalized = true; |
560 | 0 | _sink_shared_state.reset(); |
561 | 0 | _op_shared_states.clear(); |
562 | 0 | _le_state_map.clear(); |
563 | 0 | } |
564 | | |
565 | 10 | Status PipelineTask::close(Status exec_status, bool close_sink) { |
566 | 10 | int64_t close_ns = 0; |
567 | 10 | Status s; |
568 | 10 | { |
569 | 10 | SCOPED_RAW_TIMER(&close_ns); |
570 | 10 | if (close_sink) { |
571 | 5 | s = _sink->close(_state, exec_status); |
572 | 5 | } |
573 | 14 | for (auto& op : _operators) { |
574 | 14 | auto tem = op->close(_state); |
575 | 14 | if (!tem.ok() && s.ok()) { |
576 | 0 | s = tem; |
577 | 0 | } |
578 | 14 | } |
579 | 10 | } |
580 | 10 | if (_opened) { |
581 | 10 | COUNTER_UPDATE(_close_timer, close_ns); |
582 | 10 | COUNTER_UPDATE(_task_profile->total_time_counter(), close_ns); |
583 | 10 | } |
584 | | |
585 | 10 | if (close_sink && _opened) { |
586 | 5 | _task_profile->add_info_string("WakeUpEarly", wake_up_early() ? "true" : "false"); |
587 | 5 | _fresh_profile_counter(); |
588 | 5 | } |
589 | | |
590 | 10 | if (_task_queue) { |
591 | 10 | _task_queue->update_statistics(this, close_ns); |
592 | 10 | } |
593 | 10 | return s; |
594 | 10 | } |
595 | | |
596 | 0 | std::string PipelineTask::debug_string() { |
597 | 0 | std::unique_lock<std::mutex> lc(_dependency_lock); |
598 | 0 | fmt::memory_buffer debug_string_buffer; |
599 | |
|
600 | 0 | fmt::format_to(debug_string_buffer, "QueryId: {}\n", print_id(query_context()->query_id())); |
601 | 0 | fmt::format_to(debug_string_buffer, "InstanceId: {}\n", |
602 | 0 | print_id(_state->fragment_instance_id())); |
603 | |
|
604 | 0 | auto* cur_blocked_dep = _blocked_dep; |
605 | 0 | auto elapsed = _fragment_context->elapsed_time() / NANOS_PER_SEC; |
606 | 0 | fmt::format_to(debug_string_buffer, |
607 | 0 | "PipelineTask[this = {}, id = {}, open = {}, eos = {}, finish = {}, dry run = " |
608 | 0 | "{}, elapse time = {}s, _wake_up_early = {}], block dependency = {}, is " |
609 | 0 | "running = {}\noperators: ", |
610 | 0 | (void*)this, _index, _opened, _eos, _finalized, _dry_run, elapsed, |
611 | 0 | _wake_up_early.load(), |
612 | 0 | cur_blocked_dep && !_finalized ? cur_blocked_dep->debug_string() : "NULL", |
613 | 0 | is_running()); |
614 | 0 | for (size_t i = 0; i < _operators.size(); i++) { |
615 | 0 | fmt::format_to(debug_string_buffer, "\n{}", |
616 | 0 | _opened && !_finalized ? _operators[i]->debug_string(_state, i) |
617 | 0 | : _operators[i]->debug_string(i)); |
618 | 0 | } |
619 | 0 | fmt::format_to(debug_string_buffer, "\n{}\n", |
620 | 0 | _opened && !_finalized ? _sink->debug_string(_state, _operators.size()) |
621 | 0 | : _sink->debug_string(_operators.size())); |
622 | 0 | if (_finalized) { |
623 | 0 | return fmt::to_string(debug_string_buffer); |
624 | 0 | } |
625 | | |
626 | 0 | size_t i = 0; |
627 | 0 | for (; i < _read_dependencies.size(); i++) { |
628 | 0 | for (size_t j = 0; j < _read_dependencies[i].size(); j++) { |
629 | 0 | fmt::format_to(debug_string_buffer, "{}. {}\n", i, |
630 | 0 | _read_dependencies[i][j]->debug_string(i + 1)); |
631 | 0 | } |
632 | 0 | } |
633 | |
|
634 | 0 | fmt::format_to(debug_string_buffer, "{}. {}\n", i, |
635 | 0 | _memory_sufficient_dependency->debug_string(i++)); |
636 | |
|
637 | 0 | fmt::format_to(debug_string_buffer, "Write Dependency Information: \n"); |
638 | 0 | for (size_t j = 0; j < _write_dependencies.size(); j++, i++) { |
639 | 0 | fmt::format_to(debug_string_buffer, "{}. {}\n", i, |
640 | 0 | _write_dependencies[j]->debug_string(i + 1)); |
641 | 0 | } |
642 | |
|
643 | 0 | fmt::format_to(debug_string_buffer, "\nRuntime Filter Dependency Information: \n"); |
644 | 0 | for (size_t j = 0; j < _filter_dependencies.size(); j++, i++) { |
645 | 0 | fmt::format_to(debug_string_buffer, "{}. {}\n", i, |
646 | 0 | _filter_dependencies[j]->debug_string(i + 1)); |
647 | 0 | } |
648 | |
|
649 | 0 | fmt::format_to(debug_string_buffer, "Finish Dependency Information: \n"); |
650 | 0 | for (size_t j = 0; j < _finish_dependencies.size(); j++, i++) { |
651 | 0 | fmt::format_to(debug_string_buffer, "{}. {}\n", i, |
652 | 0 | _finish_dependencies[j]->debug_string(j + 1)); |
653 | 0 | } |
654 | 0 | return fmt::to_string(debug_string_buffer); |
655 | 0 | } |
656 | | |
657 | 0 | size_t PipelineTask::get_revocable_size() const { |
658 | 0 | if (_finalized || _running || (_eos && _exec_state == State::NORMAL)) { |
659 | 0 | return 0; |
660 | 0 | } |
661 | | |
662 | 0 | return _sink->revocable_mem_size(_state); |
663 | 0 | } |
664 | | |
665 | 0 | Status PipelineTask::revoke_memory(const std::shared_ptr<SpillContext>& spill_context) { |
666 | 0 | if (_finalized) { |
667 | 0 | if (spill_context) { |
668 | 0 | spill_context->on_task_finished(); |
669 | 0 | VLOG_DEBUG << "Query: " << print_id(_state->query_id()) << ", task: " << ((void*)this) |
670 | 0 | << " finalized"; |
671 | 0 | } |
672 | 0 | return Status::OK(); |
673 | 0 | } |
674 | | |
675 | 0 | const auto revocable_size = _sink->revocable_mem_size(_state); |
676 | 0 | if (revocable_size >= vectorized::SpillStream::MIN_SPILL_WRITE_BATCH_MEM) { |
677 | 0 | RETURN_IF_ERROR(_sink->revoke_memory(_state, spill_context)); |
678 | 0 | } else if (spill_context) { |
679 | 0 | spill_context->on_task_finished(); |
680 | 0 | LOG(INFO) << "Query: " << print_id(_state->query_id()) << ", task: " << ((void*)this) |
681 | 0 | << " has not enough data to revoke: " << revocable_size; |
682 | 0 | } |
683 | 0 | return Status::OK(); |
684 | 0 | } |
685 | | |
686 | 17 | void PipelineTask::wake_up() { |
687 | | // call by dependency |
688 | 17 | static_cast<void>(get_task_queue()->push_back(this)); |
689 | 17 | } |
690 | | |
691 | 22 | QueryContext* PipelineTask::query_context() { |
692 | 22 | return _fragment_context->get_query_ctx(); |
693 | 22 | } |
694 | | } // namespace doris::pipeline |