/root/doris/be/src/util/trace.h
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 | | #pragma once |
18 | | |
19 | | #include <butil/macros.h> |
20 | | |
21 | | // If this scope times out, make a simple trace. |
22 | | // It will log the cost time only. |
23 | | // Timeout is chrono duration struct, eg: 5ms, 100 * 1s. |
24 | | #define SCOPED_SIMPLE_TRACE_IF_TIMEOUT(timeout) \ |
25 | 1.35M | SCOPED_SIMPLE_TRACE_TO_STREAM_IF_TIMEOUT(timeout, LOG(WARNING)) |
26 | | |
27 | | // If this scope times out, then put simple trace to the stream. |
28 | | // Timeout is chrono duration struct, eg: 5ms, 100 * 1s. |
29 | | // For example: |
30 | | // |
31 | | // std::string tag = "[foo]"; |
32 | | // SCOPED_SIMPLE_TRACE_TO_STREAM_IF_TIMEOUT(5s, LOG(INFO) << tag); |
33 | | // |
34 | | #define SCOPED_SIMPLE_TRACE_TO_STREAM_IF_TIMEOUT(timeout, stream) \ |
35 | 1.35M | using namespace std::chrono_literals; \ |
36 | 1.35M | auto VARNAME_LINENUM(scoped_simple_trace) = doris::MonotonicMicros(); \ |
37 | 1.35M | Defer trace_defer = [&] { \ |
38 | 1.35M | auto VARNAME_LINENUM(timeout_us) = \ |
39 | 1.35M | std::chrono::duration_cast<std::chrono::microseconds>(timeout).count(); \ |
40 | 1.35M | auto VARNAME_LINENUM(cost_us) = \ |
41 | 1.35M | doris::MonotonicMicros() - VARNAME_LINENUM(scoped_simple_trace); \ |
42 | 1.35M | if (VARNAME_LINENUM(cost_us) >= VARNAME_LINENUM(timeout_us)) { \ |
43 | 0 | stream << "Simple trace cost(us): " << VARNAME_LINENUM(cost_us); \ |
44 | 0 | } \ |
45 | 1.35M | }; compaction.cpp:_ZZN5doris15CompactionMixin14modify_rowsetsEvENK3$_1clEv Line | Count | Source | 37 | 67 | Defer trace_defer = [&] { \ | 38 | 67 | auto VARNAME_LINENUM(timeout_us) = \ | 39 | 67 | std::chrono::duration_cast<std::chrono::microseconds>(timeout).count(); \ | 40 | 67 | auto VARNAME_LINENUM(cost_us) = \ | 41 | 67 | doris::MonotonicMicros() - VARNAME_LINENUM(scoped_simple_trace); \ | 42 | 67 | if (VARNAME_LINENUM(cost_us) >= VARNAME_LINENUM(timeout_us)) { \ | 43 | 0 | stream << "Simple trace cost(us): " << VARNAME_LINENUM(cost_us); \ | 44 | 0 | } \ | 45 | 67 | }; |
compaction.cpp:_ZZN5doris15CompactionMixin14modify_rowsetsEvENK3$_2clEv Line | Count | Source | 37 | 18 | Defer trace_defer = [&] { \ | 38 | 18 | auto VARNAME_LINENUM(timeout_us) = \ | 39 | 18 | std::chrono::duration_cast<std::chrono::microseconds>(timeout).count(); \ | 40 | 18 | auto VARNAME_LINENUM(cost_us) = \ | 41 | 18 | doris::MonotonicMicros() - VARNAME_LINENUM(scoped_simple_trace); \ | 42 | 18 | if (VARNAME_LINENUM(cost_us) >= VARNAME_LINENUM(timeout_us)) { \ | 43 | 0 | stream << "Simple trace cost(us): " << VARNAME_LINENUM(cost_us); \ | 44 | 0 | } \ | 45 | 18 | }; |
Unexecuted instantiation: cold_data_compaction.cpp:_ZZN5doris18ColdDataCompaction14modify_rowsetsEvENK3$_0clEv rowset.cpp:_ZZN5doris6Rowset11clear_cacheEvENK3$_0clEv Line | Count | Source | 37 | 187k | Defer trace_defer = [&] { \ | 38 | 187k | auto VARNAME_LINENUM(timeout_us) = \ | 39 | 187k | std::chrono::duration_cast<std::chrono::microseconds>(timeout).count(); \ | 40 | 187k | auto VARNAME_LINENUM(cost_us) = \ | 41 | 187k | doris::MonotonicMicros() - VARNAME_LINENUM(scoped_simple_trace); \ | 42 | 187k | if (VARNAME_LINENUM(cost_us) >= VARNAME_LINENUM(timeout_us)) { \ | 43 | 0 | stream << "Simple trace cost(us): " << VARNAME_LINENUM(cost_us); \ | 44 | 0 | } \ | 45 | 187k | }; |
rowset.cpp:_ZZN5doris6Rowset11clear_cacheEvENK3$_1clEv Line | Count | Source | 37 | 187k | Defer trace_defer = [&] { \ | 38 | 187k | auto VARNAME_LINENUM(timeout_us) = \ | 39 | 187k | std::chrono::duration_cast<std::chrono::microseconds>(timeout).count(); \ | 40 | 187k | auto VARNAME_LINENUM(cost_us) = \ | 41 | 187k | doris::MonotonicMicros() - VARNAME_LINENUM(scoped_simple_trace); \ | 42 | 187k | if (VARNAME_LINENUM(cost_us) >= VARNAME_LINENUM(timeout_us)) { \ | 43 | 0 | stream << "Simple trace cost(us): " << VARNAME_LINENUM(cost_us); \ | 44 | 0 | } \ | 45 | 187k | }; |
Unexecuted instantiation: schema_change.cpp:_ZZN5doris15SchemaChangeJob24_do_process_alter_tabletERKNS_17TAlterTabletReqV2EENK3$_2clEv Unexecuted instantiation: schema_change.cpp:_ZZN5doris15SchemaChangeJob24_do_process_alter_tabletERKNS_17TAlterTabletReqV2EENK3$_3clEv Unexecuted instantiation: schema_change.cpp:_ZZZN5doris15SchemaChangeJob27_convert_historical_rowsetsERKNS_18SchemaChangeParamsEPlENK3$_0clEvENKUlvE_clEv Unexecuted instantiation: schema_change.cpp:_ZZN5doris15SchemaChangeJob33_calc_delete_bitmap_for_mow_tableElENK3$_0clEv tablet.cpp:_ZZN5doris6Tablet10add_rowsetESt10shared_ptrINS_6RowsetEEENK3$_0clEv Line | Count | Source | 37 | 6.15k | Defer trace_defer = [&] { \ | 38 | 6.15k | auto VARNAME_LINENUM(timeout_us) = \ | 39 | 6.15k | std::chrono::duration_cast<std::chrono::microseconds>(timeout).count(); \ | 40 | 6.15k | auto VARNAME_LINENUM(cost_us) = \ | 41 | 6.15k | doris::MonotonicMicros() - VARNAME_LINENUM(scoped_simple_trace); \ | 42 | 6.15k | if (VARNAME_LINENUM(cost_us) >= VARNAME_LINENUM(timeout_us)) { \ | 43 | 0 | stream << "Simple trace cost(us): " << VARNAME_LINENUM(cost_us); \ | 44 | 0 | } \ | 45 | 6.15k | }; |
tablet.cpp:_ZZN5doris6Tablet14add_inc_rowsetERKSt10shared_ptrINS_6RowsetEEENK3$_0clEv Line | Count | Source | 37 | 11.2k | Defer trace_defer = [&] { \ | 38 | 11.2k | auto VARNAME_LINENUM(timeout_us) = \ | 39 | 11.2k | std::chrono::duration_cast<std::chrono::microseconds>(timeout).count(); \ | 40 | 11.2k | auto VARNAME_LINENUM(cost_us) = \ | 41 | 11.2k | doris::MonotonicMicros() - VARNAME_LINENUM(scoped_simple_trace); \ | 42 | 11.2k | if (VARNAME_LINENUM(cost_us) >= VARNAME_LINENUM(timeout_us)) { \ | 43 | 0 | stream << "Simple trace cost(us): " << VARNAME_LINENUM(cost_us); \ | 44 | 0 | } \ | 45 | 11.2k | }; |
tablet.cpp:_ZZN5doris6Tablet27delete_expired_stale_rowsetEvENK3$_0clEv Line | Count | Source | 37 | 901k | Defer trace_defer = [&] { \ | 38 | 901k | auto VARNAME_LINENUM(timeout_us) = \ | 39 | 901k | std::chrono::duration_cast<std::chrono::microseconds>(timeout).count(); \ | 40 | 901k | auto VARNAME_LINENUM(cost_us) = \ | 41 | 901k | doris::MonotonicMicros() - VARNAME_LINENUM(scoped_simple_trace); \ | 42 | 901k | if (VARNAME_LINENUM(cost_us) >= VARNAME_LINENUM(timeout_us)) { \ | 43 | 0 | stream << "Simple trace cost(us): " << VARNAME_LINENUM(cost_us); \ | 44 | 0 | } \ | 45 | 901k | }; |
tablet.cpp:_ZZN5doris6Tablet26calculate_cumulative_pointEvENK3$_0clEv Line | Count | Source | 37 | 51.3k | Defer trace_defer = [&] { \ | 38 | 51.3k | auto VARNAME_LINENUM(timeout_us) = \ | 39 | 51.3k | std::chrono::duration_cast<std::chrono::microseconds>(timeout).count(); \ | 40 | 51.3k | auto VARNAME_LINENUM(cost_us) = \ | 41 | 51.3k | doris::MonotonicMicros() - VARNAME_LINENUM(scoped_simple_trace); \ | 42 | 51.3k | if (VARNAME_LINENUM(cost_us) >= VARNAME_LINENUM(timeout_us)) { \ | 43 | 0 | stream << "Simple trace cost(us): " << VARNAME_LINENUM(cost_us); \ | 44 | 0 | } \ | 45 | 51.3k | }; |
tablet.cpp:_ZZN5doris6Tablet14_cooldown_dataESt10shared_ptrINS_6RowsetEEENK3$_1clEv Line | Count | Source | 37 | 5 | Defer trace_defer = [&] { \ | 38 | 5 | auto VARNAME_LINENUM(timeout_us) = \ | 39 | 5 | std::chrono::duration_cast<std::chrono::microseconds>(timeout).count(); \ | 40 | 5 | auto VARNAME_LINENUM(cost_us) = \ | 41 | 5 | doris::MonotonicMicros() - VARNAME_LINENUM(scoped_simple_trace); \ | 42 | 5 | if (VARNAME_LINENUM(cost_us) >= VARNAME_LINENUM(timeout_us)) { \ | 43 | 0 | stream << "Simple trace cost(us): " << VARNAME_LINENUM(cost_us); \ | 44 | 0 | } \ | 45 | 5 | }; |
tablet.cpp:_ZZN5doris6Tablet14_cooldown_dataESt10shared_ptrINS_6RowsetEEENK3$_2clEv Line | Count | Source | 37 | 5 | Defer trace_defer = [&] { \ | 38 | 5 | auto VARNAME_LINENUM(timeout_us) = \ | 39 | 5 | std::chrono::duration_cast<std::chrono::microseconds>(timeout).count(); \ | 40 | 5 | auto VARNAME_LINENUM(cost_us) = \ | 41 | 5 | doris::MonotonicMicros() - VARNAME_LINENUM(scoped_simple_trace); \ | 42 | 5 | if (VARNAME_LINENUM(cost_us) >= VARNAME_LINENUM(timeout_us)) { \ | 43 | 0 | stream << "Simple trace cost(us): " << VARNAME_LINENUM(cost_us); \ | 44 | 0 | } \ | 45 | 5 | }; |
Unexecuted instantiation: tablet.cpp:_ZZN5doris6Tablet23_follow_cooldowned_dataEvENK3$_0clEv Unexecuted instantiation: tablet.cpp:_ZZN5doris6Tablet23_follow_cooldowned_dataEvENK3$_1clEv Unexecuted instantiation: tablet.cpp:_ZZN5doris6Tablet25update_max_version_schemaERKSt10shared_ptrINS_12TabletSchemaEEENK3$_0clEv tablet.cpp:_ZZN5doris6Tablet11clear_cacheEvENK3$_0clEv Line | Count | Source | 37 | 6.55k | Defer trace_defer = [&] { \ | 38 | 6.55k | auto VARNAME_LINENUM(timeout_us) = \ | 39 | 6.55k | std::chrono::duration_cast<std::chrono::microseconds>(timeout).count(); \ | 40 | 6.55k | auto VARNAME_LINENUM(cost_us) = \ | 41 | 6.55k | doris::MonotonicMicros() - VARNAME_LINENUM(scoped_simple_trace); \ | 42 | 6.55k | if (VARNAME_LINENUM(cost_us) >= VARNAME_LINENUM(timeout_us)) { \ | 43 | 0 | stream << "Simple trace cost(us): " << VARNAME_LINENUM(cost_us); \ | 44 | 0 | } \ | 45 | 6.55k | }; |
Unexecuted instantiation: full_compaction.cpp:_ZZN5doris14FullCompaction14modify_rowsetsEvENK3$_0clEv tablet_manager.cpp:_ZZN5doris13TabletManager12_drop_tabletEllbbbENK3$_1clEv Line | Count | Source | 37 | 1.15k | Defer trace_defer = [&] { \ | 38 | 1.15k | auto VARNAME_LINENUM(timeout_us) = \ | 39 | 1.15k | std::chrono::duration_cast<std::chrono::microseconds>(timeout).count(); \ | 40 | 1.15k | auto VARNAME_LINENUM(cost_us) = \ | 41 | 1.15k | doris::MonotonicMicros() - VARNAME_LINENUM(scoped_simple_trace); \ | 42 | 1.15k | if (VARNAME_LINENUM(cost_us) >= VARNAME_LINENUM(timeout_us)) { \ | 43 | 0 | stream << "Simple trace cost(us): " << VARNAME_LINENUM(cost_us); \ | 44 | 0 | } \ | 45 | 1.15k | }; |
Unexecuted instantiation: engine_clone_task.cpp:_ZZN5doris15EngineCloneTask13_finish_cloneEPNS_6TabletERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEElbENK3$_2clEv index_builder.cpp:_ZZN5doris12IndexBuilder14modify_rowsetsEPKNS_6Merger10StatisticsEENK3$_1clEv Line | Count | Source | 37 | 1 | Defer trace_defer = [&] { \ | 38 | 1 | auto VARNAME_LINENUM(timeout_us) = \ | 39 | 1 | std::chrono::duration_cast<std::chrono::microseconds>(timeout).count(); \ | 40 | 1 | auto VARNAME_LINENUM(cost_us) = \ | 41 | 1 | doris::MonotonicMicros() - VARNAME_LINENUM(scoped_simple_trace); \ | 42 | 1 | if (VARNAME_LINENUM(cost_us) >= VARNAME_LINENUM(timeout_us)) { \ | 43 | 0 | stream << "Simple trace cost(us): " << VARNAME_LINENUM(cost_us); \ | 44 | 0 | } \ | 45 | 1 | }; |
pad_rowset_action.cpp:_ZZN5doris15PadRowsetAction11_pad_rowsetEPNS_6TabletERKNS_7VersionEENK3$_0clEv Line | Count | Source | 37 | 1 | Defer trace_defer = [&] { \ | 38 | 1 | auto VARNAME_LINENUM(timeout_us) = \ | 39 | 1 | std::chrono::duration_cast<std::chrono::microseconds>(timeout).count(); \ | 40 | 1 | auto VARNAME_LINENUM(cost_us) = \ | 41 | 1 | doris::MonotonicMicros() - VARNAME_LINENUM(scoped_simple_trace); \ | 42 | 1 | if (VARNAME_LINENUM(cost_us) >= VARNAME_LINENUM(timeout_us)) { \ | 43 | 0 | stream << "Simple trace cost(us): " << VARNAME_LINENUM(cost_us); \ | 44 | 0 | } \ | 45 | 1 | }; |
|