Coverage Report

Created: 2026-07-29 12:34

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