/root/doris/be/src/runtime/runtime_profile.cpp
Line | Count | Source |
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 | | // This file is copied from |
18 | | // https://github.com/apache/impala/blob/branch-2.9.0/be/src/util/runtime-profile.cc |
19 | | // and modified by Doris |
20 | | |
21 | | #include "runtime/runtime_profile.h" |
22 | | |
23 | | #include <gen_cpp/RuntimeProfile_types.h> |
24 | | #include <rapidjson/encodings.h> |
25 | | #include <rapidjson/stringbuffer.h> |
26 | | #include <rapidjson/writer.h> |
27 | | |
28 | | #include <algorithm> |
29 | | #include <iomanip> |
30 | | #include <iostream> |
31 | | #include <memory> |
32 | | #include <string> |
33 | | |
34 | | #include "common/logging.h" |
35 | | #include "common/object_pool.h" |
36 | | #include "runtime/runtime_profile_counter_tree_node.h" |
37 | | #ifdef BE_TEST |
38 | | #include "common/status.h" // For ErrorCode |
39 | | #endif |
40 | | |
41 | | namespace doris { |
42 | | #include "common/compile_check_begin.h" |
43 | | // Thread counters name |
44 | | static const std::string THREAD_VOLUNTARY_CONTEXT_SWITCHES = "VoluntaryContextSwitches"; |
45 | | static const std::string THREAD_INVOLUNTARY_CONTEXT_SWITCHES = "InvoluntaryContextSwitches"; |
46 | | |
47 | | const std::string RuntimeProfile::ROOT_COUNTER; |
48 | | |
49 | 6 | std::unique_ptr<RuntimeProfile> RuntimeProfile::from_thrift(const TRuntimeProfileTree& node) { |
50 | 6 | if (node.nodes.empty()) { |
51 | 0 | return std::make_unique<RuntimeProfile>(""); |
52 | 0 | } |
53 | 6 | TRuntimeProfileNode root_node = node.nodes.front(); |
54 | 6 | std::unique_ptr<RuntimeProfile> res = std::make_unique<RuntimeProfile>(root_node.name); |
55 | 6 | res->update(node); |
56 | 6 | return res; |
57 | 6 | } |
58 | | |
59 | 6 | std::unique_ptr<RuntimeProfile> RuntimeProfile::from_proto(const PRuntimeProfileTree& tree) { |
60 | 6 | if (tree.nodes().empty()) { |
61 | 0 | return std::make_unique<RuntimeProfile>(""); |
62 | 0 | } |
63 | | |
64 | 6 | const PRuntimeProfileNode& root_node = tree.nodes(0); |
65 | 6 | std::unique_ptr<RuntimeProfile> res = std::make_unique<RuntimeProfile>(root_node.name()); |
66 | 6 | res->update(tree); |
67 | 6 | return res; |
68 | 6 | } |
69 | | |
70 | | RuntimeProfile::RuntimeProfile(const std::string& name, bool is_averaged_profile) |
71 | 2.48M | : _pool(new ObjectPool()), |
72 | 2.48M | _name(name), |
73 | 2.48M | _metadata(-1), |
74 | 2.48M | _timestamp(-1), |
75 | 2.48M | _is_averaged_profile(is_averaged_profile), |
76 | 2.48M | _counter_total_time(TUnit::TIME_NS, 0, 3), |
77 | 2.48M | _local_time_percent(0) { |
78 | | // TotalTime counter has level3 to disable it from plan profile, because |
79 | | // it contains its child running time, we use exec time instead. |
80 | 2.48M | _counter_map["TotalTime"] = &_counter_total_time; |
81 | 2.48M | } |
82 | | |
83 | 2.48M | RuntimeProfile::~RuntimeProfile() = default; |
84 | | |
85 | 4 | bool RuntimeProfile::Counter::operator==(const Counter& other) const { |
86 | 4 | return _value.load(std::memory_order_relaxed) == other._value.load(std::memory_order_relaxed) && |
87 | 4 | _type == other._type && _level == other._level; |
88 | 4 | } |
89 | | |
90 | 48 | void RuntimeProfile::merge(const RuntimeProfile* other) { |
91 | 48 | DCHECK(other != nullptr); |
92 | | |
93 | | // Merge this level |
94 | 48 | { |
95 | 48 | CounterMap::iterator dst_iter; |
96 | 48 | CounterMap::const_iterator src_iter; |
97 | 48 | std::lock_guard<std::mutex> l(_counter_map_lock); |
98 | 48 | std::lock_guard<std::mutex> m(other->_counter_map_lock); |
99 | | |
100 | 136 | for (src_iter = other->_counter_map.begin(); src_iter != other->_counter_map.end(); |
101 | 88 | ++src_iter) { |
102 | 88 | dst_iter = _counter_map.find(src_iter->first); |
103 | | |
104 | 88 | if (dst_iter == _counter_map.end()) { |
105 | 16 | _counter_map[src_iter->first] = _pool->add(src_iter->second->clone()); |
106 | 72 | } else { |
107 | 72 | DCHECK(dst_iter->second->type() == src_iter->second->type()); |
108 | | |
109 | 72 | if (dst_iter->second->type() == TUnit::DOUBLE_VALUE) { |
110 | 0 | double new_val = |
111 | 0 | dst_iter->second->double_value() + src_iter->second->double_value(); |
112 | 0 | dst_iter->second->set(new_val); |
113 | 72 | } else { |
114 | 72 | dst_iter->second->update(src_iter->second->value()); |
115 | 72 | } |
116 | 72 | } |
117 | 88 | } |
118 | | |
119 | 48 | ChildCounterMap::const_iterator child_counter_src_itr; |
120 | | |
121 | 48 | for (child_counter_src_itr = other->_child_counter_map.begin(); |
122 | 84 | child_counter_src_itr != other->_child_counter_map.end(); ++child_counter_src_itr) { |
123 | 36 | _child_counter_map[child_counter_src_itr->first].insert( |
124 | 36 | child_counter_src_itr->second.begin(), child_counter_src_itr->second.end()); |
125 | 36 | } |
126 | 48 | } |
127 | | |
128 | 48 | { |
129 | 48 | std::lock_guard<std::mutex> l(_children_lock); |
130 | 48 | std::lock_guard<std::mutex> m(other->_children_lock); |
131 | | |
132 | | // Recursively merge children with matching names |
133 | 80 | for (int i = 0; i < other->_children.size(); ++i) { |
134 | 32 | RuntimeProfile* other_child = other->_children[i].first; |
135 | 32 | ChildMap::iterator j = _child_map.find(other_child->_name); |
136 | 32 | RuntimeProfile* child = nullptr; |
137 | | |
138 | 32 | if (j != _child_map.end()) { |
139 | 20 | child = j->second; |
140 | 20 | } else { |
141 | 12 | child = _pool->add(new RuntimeProfile(other_child->_name)); |
142 | 12 | child->_local_time_percent = other_child->_local_time_percent; |
143 | 12 | child->_metadata = other_child->_metadata; |
144 | 12 | child->_timestamp = other_child->_timestamp; |
145 | 12 | bool indent_other_child = other->_children[i].second; |
146 | 12 | _child_map[child->_name] = child; |
147 | 12 | _children.push_back(std::make_pair(child, indent_other_child)); |
148 | 12 | } |
149 | | |
150 | 32 | child->merge(other_child); |
151 | 32 | } |
152 | 48 | } |
153 | 48 | } |
154 | | |
155 | 18 | void RuntimeProfile::update(const TRuntimeProfileTree& thrift_profile) { |
156 | 18 | int idx = 0; |
157 | 18 | update(thrift_profile.nodes, &idx); |
158 | 18 | DCHECK_EQ(idx, thrift_profile.nodes.size()); |
159 | 18 | } |
160 | | |
161 | 18 | void RuntimeProfile::update(const PRuntimeProfileTree& proto_profile) { |
162 | 18 | int idx = 0; |
163 | 18 | update(proto_profile.nodes(), &idx); |
164 | 18 | DCHECK_EQ(idx, proto_profile.nodes_size()); |
165 | 18 | } |
166 | | |
167 | 42 | void RuntimeProfile::update(const std::vector<TRuntimeProfileNode>& nodes, int* idx) { |
168 | 42 | DCHECK_LT(*idx, nodes.size()); |
169 | 42 | const TRuntimeProfileNode& node = nodes[*idx]; |
170 | 42 | { |
171 | 42 | std::lock_guard<std::mutex> l(_counter_map_lock); |
172 | | // update this level |
173 | 42 | std::map<std::string, Counter*>::iterator dst_iter; |
174 | | |
175 | 82 | for (int i = 0; i < node.counters.size(); ++i) { |
176 | 40 | const TCounter& tcounter = node.counters[i]; |
177 | 40 | CounterMap::iterator j = _counter_map.find(tcounter.name); |
178 | | |
179 | 40 | if (j == _counter_map.end()) { |
180 | 28 | _counter_map[tcounter.name] = |
181 | 28 | _pool->add(new Counter(tcounter.type, tcounter.value)); |
182 | 28 | } else { |
183 | 12 | if (j->second->type() != tcounter.type) { |
184 | 0 | LOG(ERROR) << "Cannot update counters with the same name (" << j->first |
185 | 0 | << ") but different types."; |
186 | 12 | } else { |
187 | 12 | j->second->set(tcounter.value); |
188 | 12 | } |
189 | 12 | } |
190 | 40 | } |
191 | | |
192 | 42 | ChildCounterMap::const_iterator child_counter_src_itr; |
193 | | |
194 | 42 | for (child_counter_src_itr = node.child_counters_map.begin(); |
195 | 70 | child_counter_src_itr != node.child_counters_map.end(); ++child_counter_src_itr) { |
196 | 28 | _child_counter_map[child_counter_src_itr->first].insert( |
197 | 28 | child_counter_src_itr->second.begin(), child_counter_src_itr->second.end()); |
198 | 28 | } |
199 | 42 | } |
200 | | |
201 | 42 | { |
202 | 42 | std::lock_guard<std::mutex> l(_info_strings_lock); |
203 | 42 | const InfoStrings& info_strings = node.info_strings; |
204 | 42 | for (const std::string& key : node.info_strings_display_order) { |
205 | | // Look for existing info strings and update in place. If there |
206 | | // are new strings, add them to the end of the display order. |
207 | | // TODO: Is nodes.info_strings always a superset of |
208 | | // _info_strings? If so, can just copy the display order. |
209 | 8 | InfoStrings::const_iterator it = info_strings.find(key); |
210 | 8 | DCHECK(it != info_strings.end()); |
211 | 8 | InfoStrings::iterator existing = _info_strings.find(key); |
212 | | |
213 | 8 | if (existing == _info_strings.end()) { |
214 | 6 | _info_strings.insert(std::make_pair(key, it->second)); |
215 | 6 | _info_strings_display_order.push_back(key); |
216 | 6 | } else { |
217 | 2 | _info_strings[key] = it->second; |
218 | 2 | } |
219 | 8 | } |
220 | 42 | } |
221 | | |
222 | 42 | ++*idx; |
223 | 42 | { |
224 | 42 | std::lock_guard<std::mutex> l(_children_lock); |
225 | | |
226 | | // update children with matching names; create new ones if they don't match |
227 | 66 | for (int i = 0; i < node.num_children; ++i) { |
228 | 24 | const TRuntimeProfileNode& tchild = nodes[*idx]; |
229 | 24 | ChildMap::iterator j = _child_map.find(tchild.name); |
230 | 24 | RuntimeProfile* child = nullptr; |
231 | | |
232 | 24 | if (j != _child_map.end()) { |
233 | 10 | child = j->second; |
234 | 14 | } else { |
235 | 14 | child = _pool->add(new RuntimeProfile(tchild.name)); |
236 | 14 | child->_metadata = tchild.metadata; |
237 | 14 | child->_timestamp = tchild.timestamp; |
238 | 14 | _child_map[tchild.name] = child; |
239 | 14 | _children.push_back(std::make_pair(child, tchild.indent)); |
240 | 14 | } |
241 | | |
242 | 24 | child->update(nodes, idx); |
243 | 24 | } |
244 | 42 | } |
245 | 42 | } |
246 | | |
247 | | void RuntimeProfile::update(const google::protobuf::RepeatedPtrField<PRuntimeProfileNode>& nodes, |
248 | 42 | int* idx) { |
249 | 42 | DCHECK_LT(*idx, nodes.size()); |
250 | 42 | const PRuntimeProfileNode& node = nodes.Get(*idx); |
251 | | |
252 | 42 | { |
253 | 42 | std::lock_guard<std::mutex> l(_counter_map_lock); |
254 | | |
255 | 42 | for (const auto& pcounter : node.counters()) { |
256 | 40 | const std::string& name = pcounter.name(); |
257 | 40 | auto j = _counter_map.find(name); |
258 | | |
259 | 40 | if (j == _counter_map.end()) { |
260 | 28 | _counter_map[name] = |
261 | 28 | _pool->add(new Counter(unit_to_thrift(pcounter.type()), pcounter.value())); |
262 | 28 | } else { |
263 | 12 | if (unit_to_proto(j->second->type()) != pcounter.type()) { |
264 | 0 | LOG(ERROR) << "Cannot update counters with the same name (" << name |
265 | 0 | << ") but different types."; |
266 | 12 | } else { |
267 | 12 | j->second->set(pcounter.value()); |
268 | 12 | } |
269 | 12 | } |
270 | 40 | } |
271 | | |
272 | 42 | for (const auto& kv : node.child_counters_map()) { |
273 | 40 | for (const auto& child_name : kv.second.child_counters()) { |
274 | 40 | _child_counter_map[kv.first].insert(child_name); |
275 | 40 | } |
276 | 28 | } |
277 | 42 | } |
278 | | |
279 | 42 | { |
280 | 42 | std::lock_guard<std::mutex> l(_info_strings_lock); |
281 | 42 | const auto& info_map = node.info_strings(); |
282 | | |
283 | 42 | for (const std::string& key : node.info_strings_display_order()) { |
284 | 8 | auto it = info_map.find(key); |
285 | 8 | DCHECK(it != info_map.end()); |
286 | | |
287 | 8 | auto existing = _info_strings.find(key); |
288 | 8 | if (existing == _info_strings.end()) { |
289 | 6 | _info_strings.insert(std::make_pair(key, it->second)); |
290 | 6 | _info_strings_display_order.push_back(key); |
291 | 6 | } else { |
292 | 2 | _info_strings[key] = it->second; |
293 | 2 | } |
294 | 8 | } |
295 | 42 | } |
296 | | |
297 | 42 | ++*idx; |
298 | | |
299 | 42 | { |
300 | 42 | std::lock_guard<std::mutex> l(_children_lock); |
301 | 66 | for (int i = 0; i < node.num_children(); ++i) { |
302 | 24 | const PRuntimeProfileNode& pchild = nodes.Get(*idx); |
303 | 24 | RuntimeProfile* child = nullptr; |
304 | | |
305 | 24 | auto j = _child_map.find(pchild.name()); |
306 | 24 | if (j != _child_map.end()) { |
307 | 10 | child = j->second; |
308 | 14 | } else { |
309 | 14 | child = _pool->add(new RuntimeProfile(pchild.name())); |
310 | 14 | child->_metadata = pchild.metadata(); |
311 | 14 | child->_timestamp = pchild.timestamp(); |
312 | 14 | _child_map[pchild.name()] = child; |
313 | 14 | _children.emplace_back(child, pchild.indent()); |
314 | 14 | } |
315 | | |
316 | 24 | child->update(nodes, idx); |
317 | 24 | } |
318 | 42 | } |
319 | 42 | } |
320 | | |
321 | 0 | void RuntimeProfile::divide(int n) { |
322 | 0 | DCHECK_GT(n, 0); |
323 | 0 | std::map<std::string, Counter*>::iterator iter; |
324 | 0 | { |
325 | 0 | std::lock_guard<std::mutex> l(_counter_map_lock); |
326 | |
|
327 | 0 | for (iter = _counter_map.begin(); iter != _counter_map.end(); ++iter) { |
328 | 0 | if (iter->second->type() == TUnit::DOUBLE_VALUE) { |
329 | 0 | iter->second->set(iter->second->double_value() / n); |
330 | 0 | } else { |
331 | 0 | int64_t value = iter->second->_value.load(); |
332 | 0 | value = value / n; |
333 | 0 | iter->second->_value.store(value); |
334 | 0 | } |
335 | 0 | } |
336 | 0 | } |
337 | 0 | { |
338 | 0 | std::lock_guard<std::mutex> l(_children_lock); |
339 | |
|
340 | 0 | for (ChildMap::iterator i = _child_map.begin(); i != _child_map.end(); ++i) { |
341 | 0 | i->second->divide(n); |
342 | 0 | } |
343 | 0 | } |
344 | 0 | } |
345 | | |
346 | 0 | void RuntimeProfile::clear_children() { |
347 | 0 | std::lock_guard<std::mutex> l(_children_lock); |
348 | 0 | _children.clear(); |
349 | 0 | } |
350 | | |
351 | 0 | void RuntimeProfile::compute_time_in_profile() { |
352 | 0 | compute_time_in_profile(total_time_counter()->value()); |
353 | 0 | } |
354 | | |
355 | 0 | void RuntimeProfile::compute_time_in_profile(int64_t total) { |
356 | 0 | if (total == 0) { |
357 | 0 | return; |
358 | 0 | } |
359 | | |
360 | | // Add all the total times in all the children |
361 | 0 | int64_t total_child_time = 0; |
362 | 0 | std::lock_guard<std::mutex> l(_children_lock); |
363 | |
|
364 | 0 | for (int i = 0; i < _children.size(); ++i) { |
365 | 0 | total_child_time += _children[i].first->total_time_counter()->value(); |
366 | 0 | } |
367 | |
|
368 | 0 | int64_t local_time = total_time_counter()->value() - total_child_time; |
369 | | // Counters have some margin, set to 0 if it was negative. |
370 | 0 | local_time = std::max<int64_t>(0L, local_time); |
371 | 0 | _local_time_percent = static_cast<double>(local_time) / static_cast<double>(total); |
372 | 0 | _local_time_percent = std::min(1.0, _local_time_percent) * 100; |
373 | | |
374 | | // Recurse on children |
375 | 0 | for (int i = 0; i < _children.size(); ++i) { |
376 | 0 | _children[i].first->compute_time_in_profile(total); |
377 | 0 | } |
378 | 0 | } |
379 | | |
380 | 262 | RuntimeProfile* RuntimeProfile::create_child(const std::string& name, bool indent, bool prepend) { |
381 | 262 | std::lock_guard<std::mutex> l(_children_lock); |
382 | 262 | DCHECK(_child_map.find(name) == _child_map.end()) << ", name: " << name; |
383 | 262 | RuntimeProfile* child = _pool->add(new RuntimeProfile(name)); |
384 | 262 | if (this->is_set_metadata()) { |
385 | 0 | child->set_metadata(this->metadata()); |
386 | 0 | } |
387 | | |
388 | 262 | if (_children.empty()) { |
389 | 172 | add_child_unlock(child, indent, nullptr); |
390 | 172 | } else { |
391 | 90 | auto* pos = prepend ? _children.begin()->first : nullptr; |
392 | 90 | add_child_unlock(child, indent, pos); |
393 | 90 | } |
394 | 262 | return child; |
395 | 262 | } |
396 | | |
397 | | RuntimeProfile* RuntimeProfile::get_or_create_child(const std::string& name, bool indent, |
398 | 65 | bool prepend) { |
399 | 65 | std::lock_guard<std::mutex> l(_children_lock); |
400 | 65 | auto it = _child_map.find(name); |
401 | 65 | if (it != _child_map.end()) { |
402 | 62 | return it->second; |
403 | 62 | } |
404 | | |
405 | 3 | RuntimeProfile* child = _pool->add(new RuntimeProfile(name)); |
406 | 3 | if (this->is_set_metadata()) { |
407 | 0 | child->set_metadata(this->metadata()); |
408 | 0 | } |
409 | 3 | auto* location = !_children.empty() && prepend ? _children.front().first : nullptr; |
410 | 3 | add_child_unlock(child, indent, location); |
411 | 3 | return child; |
412 | 65 | } |
413 | | |
414 | 581k | void RuntimeProfile::add_child_unlock(RuntimeProfile* child, bool indent, RuntimeProfile* loc) { |
415 | 581k | DCHECK(child != nullptr); |
416 | 581k | _child_map[child->_name] = child; |
417 | | |
418 | 581k | if (loc == nullptr) { |
419 | 581k | _children.push_back(std::make_pair(child, indent)); |
420 | 581k | } else { |
421 | 74 | for (ChildVector::iterator it = _children.begin(); it != _children.end(); ++it) { |
422 | 74 | if (it->first == loc) { |
423 | 74 | _children.insert(it, std::make_pair(child, indent)); |
424 | 74 | return; |
425 | 74 | } |
426 | 74 | } |
427 | 74 | DCHECK(false) << "Invalid loc"; |
428 | 0 | } |
429 | 581k | } |
430 | | |
431 | 580k | void RuntimeProfile::add_child(RuntimeProfile* child, bool indent, RuntimeProfile* loc) { |
432 | 580k | std::lock_guard<std::mutex> l(_children_lock); |
433 | 580k | add_child_unlock(child, indent, loc); |
434 | 580k | } |
435 | | |
436 | 1.54k | RuntimeProfile* RuntimeProfile::get_child(std::string name) { |
437 | 1.54k | std::lock_guard<std::mutex> l(_children_lock); |
438 | 1.54k | auto it = _child_map.find(name); |
439 | | |
440 | 1.54k | if (it == _child_map.end()) { |
441 | 4 | return nullptr; |
442 | 4 | } |
443 | | |
444 | 1.53k | return it->second; |
445 | 1.54k | } |
446 | | |
447 | 10 | void RuntimeProfile::get_children(std::vector<RuntimeProfile*>* children) const { |
448 | 10 | children->clear(); |
449 | 10 | std::lock_guard<std::mutex> l(_children_lock); |
450 | | |
451 | 36 | for (ChildMap::const_iterator i = _child_map.begin(); i != _child_map.end(); ++i) { |
452 | 26 | children->push_back(i->second); |
453 | 26 | } |
454 | 10 | } |
455 | | |
456 | 0 | void RuntimeProfile::get_all_children(std::vector<RuntimeProfile*>* children) { |
457 | 0 | std::lock_guard<std::mutex> l(_children_lock); |
458 | |
|
459 | 0 | for (ChildMap::iterator i = _child_map.begin(); i != _child_map.end(); ++i) { |
460 | 0 | children->push_back(i->second); |
461 | 0 | i->second->get_all_children(children); |
462 | 0 | } |
463 | 0 | } |
464 | | |
465 | 1.15M | void RuntimeProfile::add_info_string(const std::string& key, const std::string& value) { |
466 | 1.15M | std::lock_guard<std::mutex> l(_info_strings_lock); |
467 | 1.15M | InfoStrings::iterator it = _info_strings.find(key); |
468 | | |
469 | 1.15M | if (it == _info_strings.end()) { |
470 | 1.15M | _info_strings.insert(std::make_pair(key, value)); |
471 | 1.15M | _info_strings_display_order.push_back(key); |
472 | 1.15M | } else { |
473 | 348 | it->second = value; |
474 | 348 | } |
475 | 1.15M | } |
476 | | |
477 | 68 | const std::string* RuntimeProfile::get_info_string(const std::string& key) { |
478 | 68 | std::lock_guard<std::mutex> l(_info_strings_lock); |
479 | 68 | InfoStrings::const_iterator it = _info_strings.find(key); |
480 | | |
481 | 68 | if (it == _info_strings.end()) { |
482 | 4 | return nullptr; |
483 | 4 | } |
484 | | |
485 | 64 | return &it->second; |
486 | 68 | } |
487 | | |
488 | | RuntimeProfile::HighWaterMarkCounter* RuntimeProfile::AddHighWaterMarkCounter( |
489 | | const std::string& name, TUnit::type unit, const std::string& parent_counter_name, |
490 | 242k | int64_t level) { |
491 | 242k | DCHECK_EQ(_is_averaged_profile, false); |
492 | 242k | std::lock_guard<std::mutex> l(_counter_map_lock); |
493 | 242k | if (_counter_map.find(name) != _counter_map.end()) { |
494 | 170 | return reinterpret_cast<RuntimeProfile::HighWaterMarkCounter*>(_counter_map[name]); |
495 | 170 | } |
496 | 242k | DCHECK(parent_counter_name == ROOT_COUNTER || |
497 | 242k | _counter_map.find(parent_counter_name) != _counter_map.end()); |
498 | 242k | RuntimeProfile::HighWaterMarkCounter* counter = |
499 | 242k | _pool->add(new RuntimeProfile::HighWaterMarkCounter(unit, level, parent_counter_name)); |
500 | 242k | _counter_map[name] = counter; |
501 | 242k | _child_counter_map[parent_counter_name].insert(name); |
502 | 242k | return counter; |
503 | 242k | } |
504 | | |
505 | | RuntimeProfile::Counter* RuntimeProfile::add_counter(const std::string& name, TUnit::type type, |
506 | | const std::string& parent_counter_name, |
507 | 8.07M | int64_t level) { |
508 | 8.07M | std::lock_guard<std::mutex> l(_counter_map_lock); |
509 | | |
510 | 8.07M | if (_counter_map.find(name) != _counter_map.end()) { |
511 | 43.0k | return _counter_map[name]; |
512 | 43.0k | } |
513 | | |
514 | | // Parent counter must already exist. |
515 | 8.07M | DCHECK(parent_counter_name == ROOT_COUNTER || |
516 | 8.03M | _counter_map.find(parent_counter_name) != _counter_map.end()); |
517 | | |
518 | 8.03M | Counter* counter = _pool->add(new Counter(type, 0, level)); |
519 | 8.03M | _counter_map[name] = counter; |
520 | 8.03M | _child_counter_map[parent_counter_name].insert(name); |
521 | 8.03M | return counter; |
522 | 8.07M | } |
523 | | |
524 | | RuntimeProfile::NonZeroCounter* RuntimeProfile::add_nonzero_counter( |
525 | | const std::string& name, TUnit::type type, const std::string& parent_counter_name, |
526 | 64 | int64_t level) { |
527 | 64 | std::lock_guard<std::mutex> l(_counter_map_lock); |
528 | 64 | if (_counter_map.find(name) != _counter_map.end()) { |
529 | 0 | DCHECK(dynamic_cast<NonZeroCounter*>(_counter_map[name])); |
530 | 0 | return static_cast<NonZeroCounter*>(_counter_map[name]); |
531 | 0 | } |
532 | | |
533 | 64 | DCHECK(parent_counter_name == ROOT_COUNTER || |
534 | 64 | _counter_map.find(parent_counter_name) != _counter_map.end()); |
535 | 64 | NonZeroCounter* counter = _pool->add(new NonZeroCounter(type, level, parent_counter_name)); |
536 | 64 | _counter_map[name] = counter; |
537 | 64 | _child_counter_map[parent_counter_name].insert(name); |
538 | 64 | return counter; |
539 | 64 | } |
540 | | |
541 | | RuntimeProfile::DerivedCounter* RuntimeProfile::add_derived_counter( |
542 | | const std::string& name, TUnit::type type, const DerivedCounterFunction& counter_fn, |
543 | 16 | const std::string& parent_counter_name) { |
544 | 16 | std::lock_guard<std::mutex> l(_counter_map_lock); |
545 | | |
546 | 16 | if (_counter_map.find(name) != _counter_map.end()) { |
547 | 0 | return nullptr; |
548 | 0 | } |
549 | | |
550 | 16 | DerivedCounter* counter = _pool->add(new DerivedCounter(type, counter_fn)); |
551 | 16 | _counter_map[name] = counter; |
552 | 16 | _child_counter_map[parent_counter_name].insert(name); |
553 | 16 | return counter; |
554 | 16 | } |
555 | | |
556 | | void RuntimeProfile::add_description(const std::string& name, const std::string& description, |
557 | 144k | std::string parent_counter_name) { |
558 | 144k | std::lock_guard<std::mutex> l(_counter_map_lock); |
559 | | |
560 | 144k | if (_counter_map.find(name) != _counter_map.end()) { |
561 | 0 | Counter* counter = _counter_map[name]; |
562 | 0 | if (dynamic_cast<DescriptionEntry*>(counter) != nullptr) { |
563 | | // Do replace instead of update to avoid data race. |
564 | 0 | _counter_map.erase(name); |
565 | 0 | } else { |
566 | 0 | DCHECK(false) << "Counter type mismatch, name: " << name |
567 | 0 | << ", type: " << counter->type() << ", description: " << description; |
568 | 0 | } |
569 | 0 | } |
570 | | |
571 | | // Parent counter must already exist. |
572 | 144k | DCHECK(parent_counter_name == ROOT_COUNTER || |
573 | 144k | _counter_map.find(parent_counter_name) != _counter_map.end()); |
574 | 144k | DescriptionEntry* counter = _pool->add(new DescriptionEntry(name, description)); |
575 | 144k | _counter_map[name] = counter; |
576 | 144k | _child_counter_map[parent_counter_name].insert(name); |
577 | 144k | } |
578 | | |
579 | | RuntimeProfile::ConditionCounter* RuntimeProfile::add_conditition_counter( |
580 | | const std::string& name, TUnit::type type, const ConditionCounterFunction& counter_fn, |
581 | 6 | const std::string& parent_counter_name, int64_t level) { |
582 | 6 | std::lock_guard<std::mutex> l(_counter_map_lock); |
583 | | |
584 | 6 | if (_counter_map.find(name) != _counter_map.end()) { |
585 | 0 | RuntimeProfile::ConditionCounter* contition_counter = |
586 | 0 | dynamic_cast<ConditionCounter*>(_counter_map[name]); |
587 | 0 | if (contition_counter == nullptr) { |
588 | 0 | throw doris::Exception(doris::ErrorCode::INTERNAL_ERROR, |
589 | 0 | "Failed to add a conditition counter that is duplicate and of a " |
590 | 0 | "different type for {}.", |
591 | 0 | name); |
592 | 0 | } |
593 | 0 | return contition_counter; |
594 | 0 | } |
595 | | |
596 | 6 | ConditionCounter* counter = _pool->add(new ConditionCounter(type, counter_fn, level)); |
597 | 6 | _counter_map[name] = counter; |
598 | 6 | _child_counter_map[parent_counter_name].insert(name); |
599 | 6 | return counter; |
600 | 6 | } |
601 | | |
602 | 13.5k | RuntimeProfile::Counter* RuntimeProfile::get_counter(const std::string& name) { |
603 | 13.5k | std::lock_guard<std::mutex> l(_counter_map_lock); |
604 | | |
605 | 13.5k | if (_counter_map.find(name) != _counter_map.end()) { |
606 | 12.3k | return _counter_map[name]; |
607 | 12.3k | } |
608 | | |
609 | 1.18k | return nullptr; |
610 | 13.5k | } |
611 | | |
612 | 0 | void RuntimeProfile::get_counters(const std::string& name, std::vector<Counter*>* counters) { |
613 | 0 | Counter* c = get_counter(name); |
614 | |
|
615 | 0 | if (c != nullptr) { |
616 | 0 | counters->push_back(c); |
617 | 0 | } |
618 | |
|
619 | 0 | std::lock_guard<std::mutex> l(_children_lock); |
620 | |
|
621 | 0 | for (int i = 0; i < _children.size(); ++i) { |
622 | 0 | _children[i].first->get_counters(name, counters); |
623 | 0 | } |
624 | 0 | } |
625 | | |
626 | | // Print the profile: |
627 | | // 1. Profile Name |
628 | | // 2. Info Strings |
629 | | // 3. Counters |
630 | | // 4. Children |
631 | | void RuntimeProfile::pretty_print(std::ostream* s, const std::string& prefix, |
632 | 254 | int64_t profile_level) const { |
633 | 254 | std::ostream& stream = *s; |
634 | | |
635 | | // create copy of _counter_map and _child_counter_map so we don't need to hold lock |
636 | | // while we call value() on the counters |
637 | 254 | CounterMap counter_map; |
638 | 254 | ChildCounterMap child_counter_map; |
639 | 254 | { |
640 | 254 | std::lock_guard<std::mutex> l(_counter_map_lock); |
641 | 254 | counter_map = _counter_map; |
642 | 254 | child_counter_map = _child_counter_map; |
643 | 254 | } |
644 | | |
645 | 254 | std::map<std::string, Counter*>::const_iterator total_time = counter_map.find("TotalTime"); |
646 | 254 | DCHECK(total_time != counter_map.end()); |
647 | | |
648 | 254 | stream.flags(std::ios::fixed); |
649 | 254 | stream << prefix << _name << ":"; |
650 | | |
651 | 254 | if (total_time->second->value() != 0) { |
652 | 0 | stream << "(Active: " |
653 | 0 | << PrettyPrinter::print(total_time->second->value(), total_time->second->type()) |
654 | 0 | << ", non-child: " << std::setprecision(2) << _local_time_percent << "%)"; |
655 | 0 | } |
656 | | |
657 | 254 | stream << std::endl; |
658 | | |
659 | 254 | { |
660 | 254 | std::lock_guard<std::mutex> l(_info_strings_lock); |
661 | 254 | for (const std::string& key : _info_strings_display_order) { |
662 | 2 | stream << prefix << " - " << key << ": " << _info_strings.find(key)->second |
663 | 2 | << std::endl; |
664 | 2 | } |
665 | 254 | } |
666 | | |
667 | 254 | RuntimeProfile::print_child_counters(prefix, ROOT_COUNTER, counter_map, child_counter_map, s); |
668 | | |
669 | | // create copy of _children so we don't need to hold lock while we call |
670 | | // pretty_print() on the children |
671 | 254 | ChildVector children; |
672 | 254 | { |
673 | 254 | std::lock_guard<std::mutex> l(_children_lock); |
674 | 254 | children = _children; |
675 | 254 | } |
676 | | |
677 | 426 | for (int i = 0; i < children.size(); ++i) { |
678 | 172 | RuntimeProfile* profile = children[i].first; |
679 | 172 | bool indent = children[i].second; |
680 | 172 | profile->pretty_print(s, prefix + (indent ? " " : "")); |
681 | 172 | } |
682 | 254 | } |
683 | | |
684 | 479 | void RuntimeProfile::to_thrift(TRuntimeProfileTree* tree, int64_t profile_level) { |
685 | 479 | tree->nodes.clear(); |
686 | 479 | to_thrift(&tree->nodes, profile_level); |
687 | 479 | } |
688 | | |
689 | 495 | void RuntimeProfile::to_thrift(std::vector<TRuntimeProfileNode>* nodes, int64_t profile_level) { |
690 | 495 | size_t index = nodes->size(); |
691 | 495 | nodes->push_back(TRuntimeProfileNode()); |
692 | 495 | TRuntimeProfileNode& node = (*nodes)[index]; |
693 | 495 | node.name = _name; |
694 | 495 | node.metadata = _metadata; |
695 | 495 | node.timestamp = _timestamp; |
696 | 495 | node.indent = true; |
697 | | |
698 | 495 | { |
699 | 495 | std::lock_guard<std::mutex> l(_counter_map_lock); |
700 | 495 | RuntimeProfileCounterTreeNode conter_tree = RuntimeProfileCounterTreeNode::from_map( |
701 | 495 | _counter_map, _child_counter_map, ROOT_COUNTER); |
702 | 495 | conter_tree = RuntimeProfileCounterTreeNode::prune_the_tree(conter_tree, profile_level); |
703 | 495 | conter_tree.to_thrift(node.counters, node.child_counters_map); |
704 | 495 | } |
705 | | |
706 | 495 | { |
707 | 495 | std::lock_guard<std::mutex> l(_info_strings_lock); |
708 | 495 | node.info_strings = _info_strings; |
709 | 495 | node.info_strings_display_order = _info_strings_display_order; |
710 | 495 | } |
711 | | |
712 | 495 | ChildVector children; |
713 | 495 | { |
714 | | // _children may be modified during to_thrift(), |
715 | | // so we have to lock and copy _children to avoid race condition |
716 | 495 | std::lock_guard<std::mutex> l(_children_lock); |
717 | 495 | children = _children; |
718 | 495 | } |
719 | 495 | node.num_children = cast_set<int32_t>(children.size()); |
720 | 495 | nodes->reserve(nodes->size() + children.size()); |
721 | | |
722 | 507 | for (int i = 0; i < children.size(); ++i) { |
723 | 12 | size_t child_idx = nodes->size(); |
724 | 12 | children[i].first->to_thrift(nodes, profile_level); |
725 | | // fix up indentation flag |
726 | 12 | (*nodes)[child_idx].indent = children[i].second; |
727 | 12 | } |
728 | 495 | } |
729 | | |
730 | 10 | void RuntimeProfile::to_proto(PRuntimeProfileTree* tree, int64_t profile_level) { |
731 | 10 | tree->clear_nodes(); |
732 | 10 | to_proto(tree->mutable_nodes(), profile_level); |
733 | 10 | } |
734 | | |
735 | | void RuntimeProfile::to_proto(google::protobuf::RepeatedPtrField<PRuntimeProfileNode>* nodes, |
736 | 22 | int64_t profile_level) { |
737 | 22 | PRuntimeProfileNode* node = nodes->Add(); // allocate new node |
738 | 22 | node->set_name(_name); |
739 | 22 | node->set_metadata(_metadata); |
740 | 22 | node->set_timestamp(_timestamp); |
741 | 22 | node->set_indent(true); |
742 | | |
743 | 22 | { |
744 | 22 | std::lock_guard<std::mutex> l(_counter_map_lock); |
745 | 22 | RuntimeProfileCounterTreeNode counter_tree = RuntimeProfileCounterTreeNode::from_map( |
746 | 22 | _counter_map, _child_counter_map, ROOT_COUNTER); |
747 | 22 | counter_tree = RuntimeProfileCounterTreeNode::prune_the_tree(counter_tree, profile_level); |
748 | 22 | counter_tree.to_proto(node->mutable_counters(), node->mutable_child_counters_map()); |
749 | 22 | } |
750 | | |
751 | 22 | { |
752 | 22 | std::lock_guard<std::mutex> l(_info_strings_lock); |
753 | 22 | auto* info_map = node->mutable_info_strings(); |
754 | 22 | for (const auto& kv : _info_strings) { |
755 | 6 | (*info_map)[kv.first] = kv.second; |
756 | 6 | } |
757 | 22 | for (const auto& key : _info_strings_display_order) { |
758 | 6 | node->add_info_strings_display_order(key); |
759 | 6 | } |
760 | 22 | } |
761 | | |
762 | 22 | ChildVector children; |
763 | 22 | { |
764 | 22 | std::lock_guard<std::mutex> l(_children_lock); |
765 | 22 | children = _children; |
766 | 22 | } |
767 | | |
768 | 22 | node->set_num_children(cast_set<int32_t>(children.size())); |
769 | | |
770 | 22 | for (const auto& child : children) { |
771 | 12 | int child_index = cast_set<int>(nodes->size()); // capture index for indent correction |
772 | 12 | child.first->to_proto(nodes, profile_level); |
773 | 12 | (*nodes)[child_index].set_indent(child.second); |
774 | 12 | } |
775 | 22 | } |
776 | | |
777 | | int64_t RuntimeProfile::units_per_second(const RuntimeProfile::Counter* total_counter, |
778 | 6 | const RuntimeProfile::Counter* timer) { |
779 | 6 | DCHECK(total_counter->type() == TUnit::BYTES || total_counter->type() == TUnit::UNIT); |
780 | 6 | DCHECK(timer->type() == TUnit::TIME_NS); |
781 | | |
782 | 6 | if (timer->value() == 0) { |
783 | 0 | return 0; |
784 | 0 | } |
785 | | |
786 | 6 | double secs = static_cast<double>(timer->value()) / 1000.0 / 1000.0 / 1000.0; |
787 | 6 | return int64_t(static_cast<double>(total_counter->value()) / secs); |
788 | 6 | } |
789 | | |
790 | 0 | int64_t RuntimeProfile::counter_sum(const std::vector<Counter*>* counters) { |
791 | 0 | int64_t value = 0; |
792 | |
|
793 | 0 | for (int i = 0; i < counters->size(); ++i) { |
794 | 0 | value += (*counters)[i]->value(); |
795 | 0 | } |
796 | |
|
797 | 0 | return value; |
798 | 0 | } |
799 | | |
800 | | void RuntimeProfile::print_child_counters(const std::string& prefix, |
801 | | const std::string& counter_name, |
802 | | const CounterMap& counter_map, |
803 | | const ChildCounterMap& child_counter_map, |
804 | 1.04k | std::ostream* s) { |
805 | 1.04k | auto itr = child_counter_map.find(counter_name); |
806 | | |
807 | 1.04k | if (itr != child_counter_map.end()) { |
808 | 200 | const std::set<std::string>& child_counters = itr->second; |
809 | 794 | for (const std::string& child_counter : child_counters) { |
810 | 794 | auto iter = counter_map.find(child_counter); |
811 | | DCHECK(iter != counter_map.end()); |
812 | 794 | iter->second->pretty_print(s, prefix, iter->first); |
813 | 794 | RuntimeProfile::print_child_counters(prefix + " ", child_counter, counter_map, |
814 | 794 | child_counter_map, s); |
815 | 794 | } |
816 | 200 | } |
817 | 1.04k | } |
818 | | |
819 | | } // namespace doris |