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