Coverage Report

Created: 2026-03-20 18:20

next uncovered line (L), next uncovered region (R), next uncovered branch (B)
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
3
std::unique_ptr<RuntimeProfile> RuntimeProfile::from_thrift(const TRuntimeProfileTree& node) {
50
3
    if (node.nodes.empty()) {
51
0
        return std::make_unique<RuntimeProfile>("");
52
0
    }
53
3
    TRuntimeProfileNode root_node = node.nodes.front();
54
3
    std::unique_ptr<RuntimeProfile> res = std::make_unique<RuntimeProfile>(root_node.name);
55
3
    res->update(node);
56
3
    return res;
57
3
}
58
59
2.03k
std::unique_ptr<RuntimeProfile> RuntimeProfile::from_proto(const PRuntimeProfileTree& tree) {
60
2.03k
    if (tree.nodes().empty()) {
61
0
        return std::make_unique<RuntimeProfile>("");
62
0
    }
63
64
2.03k
    const PRuntimeProfileNode& root_node = tree.nodes(0);
65
2.03k
    std::unique_ptr<RuntimeProfile> res = std::make_unique<RuntimeProfile>(root_node.name());
66
2.03k
    res->update(tree);
67
2.03k
    return res;
68
2.03k
}
69
70
RuntimeProfile::RuntimeProfile(const std::string& name, bool is_averaged_profile)
71
59.9M
        : _pool(new ObjectPool()),
72
59.9M
          _name(name),
73
59.9M
          _metadata(-1),
74
59.9M
          _timestamp(-1),
75
59.9M
          _is_averaged_profile(is_averaged_profile),
76
59.9M
          _counter_total_time(TUnit::TIME_NS, 0, 3),
77
59.9M
          _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
59.9M
    _counter_map["TotalTime"] = &_counter_total_time;
81
59.9M
}
82
83
60.1M
RuntimeProfile::~RuntimeProfile() = default;
84
85
2
bool RuntimeProfile::Counter::operator==(const Counter& other) const {
86
2
    return _value.load(std::memory_order_relaxed) == other._value.load(std::memory_order_relaxed) &&
87
2
           _type == other._type && _level == other._level;
88
2
}
89
90
19.7k
void RuntimeProfile::merge(const RuntimeProfile* other) {
91
19.7k
    DCHECK(other != nullptr);
92
93
    // Merge this level
94
19.7k
    {
95
19.7k
        CounterMap::iterator dst_iter;
96
19.7k
        CounterMap::const_iterator src_iter;
97
19.7k
        std::lock_guard<std::mutex> l(_counter_map_lock);
98
19.7k
        std::lock_guard<std::mutex> m(other->_counter_map_lock);
99
100
72.4k
        for (src_iter = other->_counter_map.begin(); src_iter != other->_counter_map.end();
101
52.6k
             ++src_iter) {
102
52.6k
            dst_iter = _counter_map.find(src_iter->first);
103
104
52.6k
            if (dst_iter == _counter_map.end()) {
105
32.8k
                _counter_map[src_iter->first] = _pool->add(src_iter->second->clone());
106
32.8k
            } else {
107
19.7k
                DCHECK(dst_iter->second->type() == src_iter->second->type());
108
109
19.7k
                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
19.7k
                } else {
114
19.7k
                    dst_iter->second->update(src_iter->second->value());
115
19.7k
                }
116
19.7k
            }
117
52.6k
        }
118
119
19.7k
        ChildCounterMap::const_iterator child_counter_src_itr;
120
121
19.7k
        for (child_counter_src_itr = other->_child_counter_map.begin();
122
39.5k
             child_counter_src_itr != other->_child_counter_map.end(); ++child_counter_src_itr) {
123
19.7k
            _child_counter_map[child_counter_src_itr->first].insert(
124
19.7k
                    child_counter_src_itr->second.begin(), child_counter_src_itr->second.end());
125
19.7k
        }
126
19.7k
    }
127
128
19.7k
    {
129
19.7k
        std::lock_guard<std::mutex> l(_children_lock);
130
19.7k
        std::lock_guard<std::mutex> m(other->_children_lock);
131
132
        // Recursively merge children with matching names
133
19.8k
        for (int i = 0; i < other->_children.size(); ++i) {
134
16
            RuntimeProfile* other_child = other->_children[i].first;
135
16
            ChildMap::iterator j = _child_map.find(other_child->_name);
136
16
            RuntimeProfile* child = nullptr;
137
138
16
            if (j != _child_map.end()) {
139
10
                child = j->second;
140
10
            } else {
141
6
                child = _pool->add(new RuntimeProfile(other_child->_name));
142
6
                child->_local_time_percent = other_child->_local_time_percent;
143
6
                child->_metadata = other_child->_metadata;
144
6
                child->_timestamp = other_child->_timestamp;
145
6
                bool indent_other_child = other->_children[i].second;
146
6
                _child_map[child->_name] = child;
147
6
                _children.push_back(std::make_pair(child, indent_other_child));
148
6
            }
149
150
16
            child->merge(other_child);
151
16
        }
152
19.7k
    }
153
19.7k
}
154
155
15.4k
void RuntimeProfile::update(const TRuntimeProfileTree& thrift_profile) {
156
15.4k
    int idx = 0;
157
15.4k
    update(thrift_profile.nodes, &idx);
158
15.4k
    DCHECK_EQ(idx, thrift_profile.nodes.size());
159
15.4k
}
160
161
2.04k
void RuntimeProfile::update(const PRuntimeProfileTree& proto_profile) {
162
2.04k
    int idx = 0;
163
2.04k
    update(proto_profile.nodes(), &idx);
164
2.04k
    DCHECK_EQ(idx, proto_profile.nodes_size());
165
2.04k
}
166
167
17.1k
void RuntimeProfile::update(const std::vector<TRuntimeProfileNode>& nodes, int* idx) {
168
17.1k
    DCHECK_LT(*idx, nodes.size());
169
17.1k
    const TRuntimeProfileNode& node = nodes[*idx];
170
17.1k
    {
171
17.1k
        std::lock_guard<std::mutex> l(_counter_map_lock);
172
        // update this level
173
17.1k
        std::map<std::string, Counter*>::iterator dst_iter;
174
175
21.1k
        for (int i = 0; i < node.counters.size(); ++i) {
176
3.98k
            const TCounter& tcounter = node.counters[i];
177
3.98k
            CounterMap::iterator j = _counter_map.find(tcounter.name);
178
179
3.98k
            if (j == _counter_map.end()) {
180
2.90k
                _counter_map[tcounter.name] =
181
2.90k
                        _pool->add(new Counter(tcounter.type, tcounter.value));
182
2.90k
            } else {
183
1.08k
                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
1.08k
                } else {
187
1.08k
                    j->second->set(tcounter.value);
188
1.08k
                }
189
1.08k
            }
190
3.98k
        }
191
192
17.1k
        ChildCounterMap::const_iterator child_counter_src_itr;
193
194
17.1k
        for (child_counter_src_itr = node.child_counters_map.begin();
195
18.4k
             child_counter_src_itr != node.child_counters_map.end(); ++child_counter_src_itr) {
196
1.31k
            _child_counter_map[child_counter_src_itr->first].insert(
197
1.31k
                    child_counter_src_itr->second.begin(), child_counter_src_itr->second.end());
198
1.31k
        }
199
17.1k
    }
200
201
17.1k
    {
202
17.1k
        std::lock_guard<std::mutex> l(_info_strings_lock);
203
17.1k
        const InfoStrings& info_strings = node.info_strings;
204
17.1k
        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
62
            InfoStrings::const_iterator it = info_strings.find(key);
210
62
            DCHECK(it != info_strings.end());
211
62
            InfoStrings::iterator existing = _info_strings.find(key);
212
213
62
            if (existing == _info_strings.end()) {
214
36
                _info_strings.insert(std::make_pair(key, it->second));
215
36
                _info_strings_display_order.push_back(key);
216
36
            } else {
217
26
                _info_strings[key] = it->second;
218
26
            }
219
62
        }
220
17.1k
    }
221
222
17.1k
    ++*idx;
223
17.1k
    {
224
17.1k
        std::lock_guard<std::mutex> l(_children_lock);
225
226
        // update children with matching names; create new ones if they don't match
227
18.8k
        for (int i = 0; i < node.num_children; ++i) {
228
1.70k
            const TRuntimeProfileNode& tchild = nodes[*idx];
229
1.70k
            ChildMap::iterator j = _child_map.find(tchild.name);
230
1.70k
            RuntimeProfile* child = nullptr;
231
232
1.70k
            if (j != _child_map.end()) {
233
568
                child = j->second;
234
1.13k
            } else {
235
1.13k
                child = _pool->add(new RuntimeProfile(tchild.name));
236
1.13k
                child->_metadata = tchild.metadata;
237
1.13k
                child->_timestamp = tchild.timestamp;
238
1.13k
                _child_map[tchild.name] = child;
239
1.13k
                _children.push_back(std::make_pair(child, tchild.indent));
240
1.13k
            }
241
242
1.70k
            child->update(nodes, idx);
243
1.70k
        }
244
17.1k
    }
245
17.1k
}
246
247
void RuntimeProfile::update(const google::protobuf::RepeatedPtrField<PRuntimeProfileNode>& nodes,
248
2.05k
                            int* idx) {
249
2.05k
    DCHECK_LT(*idx, nodes.size());
250
2.05k
    const PRuntimeProfileNode& node = nodes.Get(*idx);
251
252
2.05k
    {
253
2.05k
        std::lock_guard<std::mutex> l(_counter_map_lock);
254
255
2.05k
        for (const auto& pcounter : node.counters()) {
256
20
            const std::string& name = pcounter.name();
257
20
            auto j = _counter_map.find(name);
258
259
20
            if (j == _counter_map.end()) {
260
14
                _counter_map[name] =
261
14
                        _pool->add(new Counter(unit_to_thrift(pcounter.type()), pcounter.value()));
262
14
            } else {
263
6
                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
6
                } else {
267
6
                    j->second->set(pcounter.value());
268
6
                }
269
6
            }
270
20
        }
271
272
2.05k
        for (const auto& kv : node.child_counters_map()) {
273
20
            for (const auto& child_name : kv.second.child_counters()) {
274
20
                _child_counter_map[kv.first].insert(child_name);
275
20
            }
276
14
        }
277
2.05k
    }
278
279
2.05k
    {
280
2.05k
        std::lock_guard<std::mutex> l(_info_strings_lock);
281
2.05k
        const auto& info_map = node.info_strings();
282
283
12.1k
        for (const std::string& key : node.info_strings_display_order()) {
284
12.1k
            auto it = info_map.find(key);
285
12.1k
            DCHECK(it != info_map.end());
286
287
12.1k
            auto existing = _info_strings.find(key);
288
12.1k
            if (existing == _info_strings.end()) {
289
12.1k
                _info_strings.insert(std::make_pair(key, it->second));
290
12.1k
                _info_strings_display_order.push_back(key);
291
12.1k
            } else {
292
1
                _info_strings[key] = it->second;
293
1
            }
294
12.1k
        }
295
2.05k
    }
296
297
2.05k
    ++*idx;
298
299
2.05k
    {
300
2.05k
        std::lock_guard<std::mutex> l(_children_lock);
301
2.06k
        for (int i = 0; i < node.num_children(); ++i) {
302
12
            const PRuntimeProfileNode& pchild = nodes.Get(*idx);
303
12
            RuntimeProfile* child = nullptr;
304
305
12
            auto j = _child_map.find(pchild.name());
306
12
            if (j != _child_map.end()) {
307
5
                child = j->second;
308
7
            } else {
309
7
                child = _pool->add(new RuntimeProfile(pchild.name()));
310
7
                child->_metadata = pchild.metadata();
311
7
                child->_timestamp = pchild.timestamp();
312
7
                _child_map[pchild.name()] = child;
313
7
                _children.emplace_back(child, pchild.indent());
314
7
            }
315
316
12
            child->update(nodes, idx);
317
12
        }
318
2.05k
    }
319
2.05k
}
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
23.1M
RuntimeProfile* RuntimeProfile::create_child(const std::string& name, bool indent, bool prepend) {
381
23.1M
    std::lock_guard<std::mutex> l(_children_lock);
382
18.4E
    DCHECK(_child_map.find(name) == _child_map.end()) << ", name: " << name;
383
23.1M
    RuntimeProfile* child = _pool->add(new RuntimeProfile(name));
384
23.1M
    if (this->is_set_metadata()) {
385
10.0k
        child->set_metadata(this->metadata());
386
10.0k
    }
387
388
23.1M
    if (_children.empty()) {
389
168k
        add_child_unlock(child, indent, nullptr);
390
23.0M
    } else {
391
23.0M
        auto* pos = prepend ? _children.begin()->first : nullptr;
392
23.0M
        add_child_unlock(child, indent, pos);
393
23.0M
    }
394
23.1M
    return child;
395
23.1M
}
396
397
43.9M
void RuntimeProfile::add_child_unlock(RuntimeProfile* child, bool indent, RuntimeProfile* loc) {
398
43.9M
    DCHECK(child != nullptr);
399
43.9M
    _child_map[child->_name] = child;
400
401
43.9M
    if (loc == nullptr) {
402
43.5M
        _children.push_back(std::make_pair(child, indent));
403
43.5M
    } else {
404
18.4E
        for (ChildVector::iterator it = _children.begin(); it != _children.end(); ++it) {
405
566k
            if (it->first == loc) {
406
566k
                _children.insert(it, std::make_pair(child, indent));
407
566k
                return;
408
566k
            }
409
566k
        }
410
18.4E
        DCHECK(false) << "Invalid loc";
411
18.4E
    }
412
43.9M
}
413
414
20.8M
void RuntimeProfile::add_child(RuntimeProfile* child, bool indent, RuntimeProfile* loc) {
415
20.8M
    std::lock_guard<std::mutex> l(_children_lock);
416
20.8M
    add_child_unlock(child, indent, loc);
417
20.8M
}
418
419
172k
RuntimeProfile* RuntimeProfile::get_child(std::string name) {
420
172k
    std::lock_guard<std::mutex> l(_children_lock);
421
172k
    auto it = _child_map.find(name);
422
423
172k
    if (it == _child_map.end()) {
424
2
        return nullptr;
425
2
    }
426
427
172k
    return it->second;
428
172k
}
429
430
4
void RuntimeProfile::get_children(std::vector<RuntimeProfile*>* children) const {
431
4
    children->clear();
432
4
    std::lock_guard<std::mutex> l(_children_lock);
433
434
16
    for (ChildMap::const_iterator i = _child_map.begin(); i != _child_map.end(); ++i) {
435
12
        children->push_back(i->second);
436
12
    }
437
4
}
438
439
0
void RuntimeProfile::get_all_children(std::vector<RuntimeProfile*>* children) {
440
0
    std::lock_guard<std::mutex> l(_children_lock);
441
442
0
    for (ChildMap::iterator i = _child_map.begin(); i != _child_map.end(); ++i) {
443
0
        children->push_back(i->second);
444
0
        i->second->get_all_children(children);
445
0
    }
446
0
}
447
448
62.0M
void RuntimeProfile::add_info_string(const std::string& key, const std::string& value) {
449
62.0M
    std::lock_guard<std::mutex> l(_info_strings_lock);
450
62.0M
    InfoStrings::iterator it = _info_strings.find(key);
451
452
62.0M
    if (it == _info_strings.end()) {
453
28.4M
        _info_strings.insert(std::make_pair(key, value));
454
28.4M
        _info_strings_display_order.push_back(key);
455
33.5M
    } else {
456
33.5M
        it->second = value;
457
33.5M
    }
458
62.0M
}
459
460
12.2k
const std::string* RuntimeProfile::get_info_string(const std::string& key) {
461
12.2k
    std::lock_guard<std::mutex> l(_info_strings_lock);
462
12.2k
    InfoStrings::const_iterator it = _info_strings.find(key);
463
464
12.2k
    if (it == _info_strings.end()) {
465
2
        return nullptr;
466
2
    }
467
468
12.2k
    return &it->second;
469
12.2k
}
470
471
RuntimeProfile::HighWaterMarkCounter* RuntimeProfile::AddHighWaterMarkCounter(
472
        const std::string& name, TUnit::type unit, const std::string& parent_counter_name,
473
28.9M
        int64_t level) {
474
28.9M
    DCHECK_EQ(_is_averaged_profile, false);
475
28.9M
    std::lock_guard<std::mutex> l(_counter_map_lock);
476
28.9M
    if (_counter_map.find(name) != _counter_map.end()) {
477
81
        return reinterpret_cast<RuntimeProfile::HighWaterMarkCounter*>(_counter_map[name]);
478
81
    }
479
28.9M
    DCHECK(parent_counter_name == ROOT_COUNTER ||
480
28.9M
           _counter_map.find(parent_counter_name) != _counter_map.end());
481
28.9M
    RuntimeProfile::HighWaterMarkCounter* counter =
482
28.9M
            _pool->add(new RuntimeProfile::HighWaterMarkCounter(unit, level, parent_counter_name));
483
28.9M
    _counter_map[name] = counter;
484
28.9M
    _child_counter_map[parent_counter_name].insert(name);
485
28.9M
    return counter;
486
28.9M
}
487
488
RuntimeProfile::Counter* RuntimeProfile::add_counter(const std::string& name, TUnit::type type,
489
                                                     const std::string& parent_counter_name,
490
245M
                                                     int64_t level) {
491
245M
    std::lock_guard<std::mutex> l(_counter_map_lock);
492
493
245M
    if (_counter_map.find(name) != _counter_map.end()) {
494
28.7M
        return _counter_map[name];
495
28.7M
    }
496
497
    // Parent counter must already exist.
498
245M
    DCHECK(parent_counter_name == ROOT_COUNTER ||
499
216M
           _counter_map.find(parent_counter_name) != _counter_map.end());
500
501
216M
    Counter* counter = _pool->add(new Counter(type, 0, level));
502
216M
    _counter_map[name] = counter;
503
216M
    _child_counter_map[parent_counter_name].insert(name);
504
216M
    return counter;
505
245M
}
506
507
RuntimeProfile::NonZeroCounter* RuntimeProfile::add_nonzero_counter(
508
        const std::string& name, TUnit::type type, const std::string& parent_counter_name,
509
4.53M
        int64_t level) {
510
4.53M
    std::lock_guard<std::mutex> l(_counter_map_lock);
511
4.53M
    if (_counter_map.find(name) != _counter_map.end()) {
512
0
        DCHECK(dynamic_cast<NonZeroCounter*>(_counter_map[name]));
513
0
        return static_cast<NonZeroCounter*>(_counter_map[name]);
514
0
    }
515
516
4.53M
    DCHECK(parent_counter_name == ROOT_COUNTER ||
517
4.53M
           _counter_map.find(parent_counter_name) != _counter_map.end());
518
4.53M
    NonZeroCounter* counter = _pool->add(new NonZeroCounter(type, level, parent_counter_name));
519
4.53M
    _counter_map[name] = counter;
520
4.53M
    _child_counter_map[parent_counter_name].insert(name);
521
4.53M
    return counter;
522
4.53M
}
523
524
RuntimeProfile::DerivedCounter* RuntimeProfile::add_derived_counter(
525
        const std::string& name, TUnit::type type, const DerivedCounterFunction& counter_fn,
526
815k
        const std::string& parent_counter_name) {
527
815k
    std::lock_guard<std::mutex> l(_counter_map_lock);
528
529
815k
    if (_counter_map.find(name) != _counter_map.end()) {
530
0
        return nullptr;
531
0
    }
532
533
815k
    DerivedCounter* counter = _pool->add(new DerivedCounter(type, counter_fn));
534
815k
    _counter_map[name] = counter;
535
815k
    _child_counter_map[parent_counter_name].insert(name);
536
815k
    return counter;
537
815k
}
538
539
void RuntimeProfile::add_description(const std::string& name, const std::string& description,
540
290k
                                     std::string parent_counter_name) {
541
290k
    std::lock_guard<std::mutex> l(_counter_map_lock);
542
543
290k
    if (_counter_map.find(name) != _counter_map.end()) {
544
0
        Counter* counter = _counter_map[name];
545
0
        if (dynamic_cast<DescriptionEntry*>(counter) != nullptr) {
546
            // Do replace instead of update to avoid data race.
547
0
            _counter_map.erase(name);
548
0
        } else {
549
0
            DCHECK(false) << "Counter type mismatch, name: " << name
550
0
                          << ", type: " << counter->type() << ", description: " << description;
551
0
        }
552
0
    }
553
554
    // Parent counter must already exist.
555
290k
    DCHECK(parent_counter_name == ROOT_COUNTER ||
556
290k
           _counter_map.find(parent_counter_name) != _counter_map.end());
557
290k
    DescriptionEntry* counter = _pool->add(new DescriptionEntry(name, description));
558
290k
    _counter_map[name] = counter;
559
290k
    _child_counter_map[parent_counter_name].insert(name);
560
290k
}
561
562
RuntimeProfile::ConditionCounter* RuntimeProfile::add_conditition_counter(
563
        const std::string& name, TUnit::type type, const ConditionCounterFunction& counter_fn,
564
5.82k
        const std::string& parent_counter_name, int64_t level) {
565
5.82k
    std::lock_guard<std::mutex> l(_counter_map_lock);
566
567
5.82k
    if (_counter_map.find(name) != _counter_map.end()) {
568
1.23k
        RuntimeProfile::ConditionCounter* contition_counter =
569
1.23k
                dynamic_cast<ConditionCounter*>(_counter_map[name]);
570
1.23k
        if (contition_counter == nullptr) {
571
0
            throw doris::Exception(doris::ErrorCode::INTERNAL_ERROR,
572
0
                                   "Failed to add a conditition counter that is duplicate and of a "
573
0
                                   "different type for {}.",
574
0
                                   name);
575
0
        }
576
1.23k
        return contition_counter;
577
1.23k
    }
578
579
4.58k
    ConditionCounter* counter = _pool->add(new ConditionCounter(type, counter_fn, level));
580
4.58k
    _counter_map[name] = counter;
581
4.58k
    _child_counter_map[parent_counter_name].insert(name);
582
4.58k
    return counter;
583
5.82k
}
584
585
503k
RuntimeProfile::Counter* RuntimeProfile::get_counter(const std::string& name) {
586
503k
    std::lock_guard<std::mutex> l(_counter_map_lock);
587
588
503k
    if (_counter_map.find(name) != _counter_map.end()) {
589
160k
        return _counter_map[name];
590
160k
    }
591
592
343k
    return nullptr;
593
503k
}
594
595
0
void RuntimeProfile::get_counters(const std::string& name, std::vector<Counter*>* counters) {
596
0
    Counter* c = get_counter(name);
597
598
0
    if (c != nullptr) {
599
0
        counters->push_back(c);
600
0
    }
601
602
0
    std::lock_guard<std::mutex> l(_children_lock);
603
604
0
    for (int i = 0; i < _children.size(); ++i) {
605
0
        _children[i].first->get_counters(name, counters);
606
0
    }
607
0
}
608
609
// Print the profile:
610
//  1. Profile Name
611
//  2. Info Strings
612
//  3. Counters
613
//  4. Children
614
void RuntimeProfile::pretty_print(std::ostream* s, const std::string& prefix,
615
388
                                  int64_t profile_level) const {
616
388
    std::ostream& stream = *s;
617
618
    // create copy of _counter_map and _child_counter_map so we don't need to hold lock
619
    // while we call value() on the counters
620
388
    CounterMap counter_map;
621
388
    ChildCounterMap child_counter_map;
622
388
    {
623
388
        std::lock_guard<std::mutex> l(_counter_map_lock);
624
388
        counter_map = _counter_map;
625
388
        child_counter_map = _child_counter_map;
626
388
    }
627
628
388
    std::map<std::string, Counter*>::const_iterator total_time = counter_map.find("TotalTime");
629
388
    DCHECK(total_time != counter_map.end());
630
631
388
    stream.flags(std::ios::fixed);
632
388
    stream << prefix << _name << ":";
633
634
388
    if (total_time->second->value() != 0) {
635
0
        stream << "(Active: "
636
0
               << PrettyPrinter::print(total_time->second->value(), total_time->second->type())
637
0
               << ", non-child: " << std::setprecision(2) << _local_time_percent << "%)";
638
0
    }
639
640
388
    stream << std::endl;
641
642
388
    {
643
388
        std::lock_guard<std::mutex> l(_info_strings_lock);
644
388
        for (const std::string& key : _info_strings_display_order) {
645
1
            stream << prefix << "   - " << key << ": " << _info_strings.find(key)->second
646
1
                   << std::endl;
647
1
        }
648
388
    }
649
650
    // Build counter tree and prune by profile_level before printing
651
388
    RuntimeProfileCounterTreeNode counter_tree =
652
388
            RuntimeProfileCounterTreeNode::from_map(counter_map, child_counter_map, ROOT_COUNTER);
653
388
    counter_tree = RuntimeProfileCounterTreeNode::prune_the_tree(counter_tree, profile_level);
654
388
    counter_tree.pretty_print(s, prefix);
655
656
    // create copy of _children so we don't need to hold lock while we call
657
    // pretty_print() on the children
658
388
    ChildVector children;
659
388
    {
660
388
        std::lock_guard<std::mutex> l(_children_lock);
661
388
        children = _children;
662
388
    }
663
664
623
    for (int i = 0; i < children.size(); ++i) {
665
235
        RuntimeProfile* profile = children[i].first;
666
235
        bool indent = children[i].second;
667
235
        profile->pretty_print(s, prefix + (indent ? "  " : ""));
668
235
    }
669
388
}
670
671
27.5k
void RuntimeProfile::to_thrift(TRuntimeProfileTree* tree, int64_t profile_level) {
672
27.5k
    tree->nodes.clear();
673
27.5k
    to_thrift(&tree->nodes, profile_level);
674
27.5k
}
675
676
145k
void RuntimeProfile::to_thrift(std::vector<TRuntimeProfileNode>* nodes, int64_t profile_level) {
677
145k
    size_t index = nodes->size();
678
145k
    nodes->push_back(TRuntimeProfileNode());
679
145k
    TRuntimeProfileNode& node = (*nodes)[index];
680
145k
    node.name = _name;
681
145k
    node.metadata = _metadata;
682
145k
    node.timestamp = _timestamp;
683
145k
    node.indent = true;
684
685
145k
    {
686
145k
        std::lock_guard<std::mutex> l(_counter_map_lock);
687
145k
        RuntimeProfileCounterTreeNode conter_tree = RuntimeProfileCounterTreeNode::from_map(
688
145k
                _counter_map, _child_counter_map, ROOT_COUNTER);
689
145k
        conter_tree = RuntimeProfileCounterTreeNode::prune_the_tree(conter_tree, profile_level);
690
145k
        conter_tree.to_thrift(node.counters, node.child_counters_map);
691
145k
    }
692
693
145k
    {
694
145k
        std::lock_guard<std::mutex> l(_info_strings_lock);
695
145k
        node.info_strings = _info_strings;
696
145k
        node.info_strings_display_order = _info_strings_display_order;
697
145k
    }
698
699
145k
    ChildVector children;
700
145k
    {
701
        // _children may be modified during to_thrift(),
702
        // so we have to lock and copy _children to avoid race condition
703
145k
        std::lock_guard<std::mutex> l(_children_lock);
704
145k
        children = _children;
705
145k
    }
706
145k
    node.num_children = cast_set<int32_t>(children.size());
707
145k
    nodes->reserve(nodes->size() + children.size());
708
709
264k
    for (int i = 0; i < children.size(); ++i) {
710
118k
        size_t child_idx = nodes->size();
711
118k
        children[i].first->to_thrift(nodes, profile_level);
712
        // fix up indentation flag
713
118k
        (*nodes)[child_idx].indent = children[i].second;
714
118k
    }
715
145k
}
716
717
2.03k
void RuntimeProfile::to_proto(PRuntimeProfileTree* tree, int64_t profile_level) {
718
2.03k
    tree->clear_nodes();
719
2.03k
    to_proto(tree->mutable_nodes(), profile_level);
720
2.03k
}
721
722
void RuntimeProfile::to_proto(google::protobuf::RepeatedPtrField<PRuntimeProfileNode>* nodes,
723
2.04k
                              int64_t profile_level) {
724
2.04k
    PRuntimeProfileNode* node = nodes->Add(); // allocate new node
725
2.04k
    node->set_name(_name);
726
2.04k
    node->set_metadata(_metadata);
727
2.04k
    node->set_timestamp(_timestamp);
728
2.04k
    node->set_indent(true);
729
730
2.04k
    {
731
2.04k
        std::lock_guard<std::mutex> l(_counter_map_lock);
732
2.04k
        RuntimeProfileCounterTreeNode counter_tree = RuntimeProfileCounterTreeNode::from_map(
733
2.04k
                _counter_map, _child_counter_map, ROOT_COUNTER);
734
2.04k
        counter_tree = RuntimeProfileCounterTreeNode::prune_the_tree(counter_tree, profile_level);
735
2.04k
        counter_tree.to_proto(node->mutable_counters(), node->mutable_child_counters_map());
736
2.04k
    }
737
738
2.04k
    {
739
2.04k
        std::lock_guard<std::mutex> l(_info_strings_lock);
740
2.04k
        auto* info_map = node->mutable_info_strings();
741
12.1k
        for (const auto& kv : _info_strings) {
742
12.1k
            (*info_map)[kv.first] = kv.second;
743
12.1k
        }
744
12.1k
        for (const auto& key : _info_strings_display_order) {
745
12.1k
            node->add_info_strings_display_order(key);
746
12.1k
        }
747
2.04k
    }
748
749
2.04k
    ChildVector children;
750
2.04k
    {
751
2.04k
        std::lock_guard<std::mutex> l(_children_lock);
752
2.04k
        children = _children;
753
2.04k
    }
754
755
2.04k
    node->set_num_children(cast_set<int32_t>(children.size()));
756
757
2.04k
    for (const auto& child : children) {
758
6
        int child_index = cast_set<int>(nodes->size()); // capture index for indent correction
759
6
        child.first->to_proto(nodes, profile_level);
760
6
        (*nodes)[child_index].set_indent(child.second);
761
6
    }
762
2.04k
}
763
764
int64_t RuntimeProfile::units_per_second(const RuntimeProfile::Counter* total_counter,
765
5.76k
                                         const RuntimeProfile::Counter* timer) {
766
5.76k
    DCHECK(total_counter->type() == TUnit::BYTES || total_counter->type() == TUnit::UNIT);
767
5.76k
    DCHECK(timer->type() == TUnit::TIME_NS);
768
769
5.76k
    if (timer->value() == 0) {
770
5.76k
        return 0;
771
5.76k
    }
772
773
3
    double secs = static_cast<double>(timer->value()) / 1000.0 / 1000.0 / 1000.0;
774
3
    return int64_t(static_cast<double>(total_counter->value()) / secs);
775
5.76k
}
776
777
0
int64_t RuntimeProfile::counter_sum(const std::vector<Counter*>* counters) {
778
0
    int64_t value = 0;
779
780
0
    for (int i = 0; i < counters->size(); ++i) {
781
0
        value += (*counters)[i]->value();
782
0
    }
783
784
0
    return value;
785
0
}
786
787
void RuntimeProfile::print_child_counters(const std::string& prefix,
788
                                          const std::string& counter_name,
789
                                          const CounterMap& counter_map,
790
                                          const ChildCounterMap& child_counter_map,
791
0
                                          std::ostream* s) {
792
0
    auto itr = child_counter_map.find(counter_name);
793
794
0
    if (itr != child_counter_map.end()) {
795
0
        const std::set<std::string>& child_counters = itr->second;
796
0
        for (const std::string& child_counter : child_counters) {
797
0
            auto iter = counter_map.find(child_counter);
798
            DCHECK(iter != counter_map.end());
799
0
            iter->second->pretty_print(s, prefix, iter->first);
800
0
            RuntimeProfile::print_child_counters(prefix + "  ", child_counter, counter_map,
801
0
                                                 child_counter_map, s);
802
0
        }
803
0
    }
804
0
}
805
806
} // namespace doris