1 //===-- Timer.cpp ---------------------------------------------------------===//
2 //
3 // Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
4 // See https://llvm.org/LICENSE.txt for license information.
5 // SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
6 //
7 //===----------------------------------------------------------------------===//
8 #include "lldb/Utility/Timer.h"
9 #include "lldb/Utility/Stream.h"
10
11 #include <algorithm>
12 #include <map>
13 #include <mutex>
14 #include <utility>
15 #include <vector>
16
17 #include <assert.h>
18 #include <inttypes.h>
19 #include <stdarg.h>
20 #include <stdio.h>
21
22 using namespace lldb_private;
23
24 #define TIMER_INDENT_AMOUNT 2
25
26 namespace {
27 typedef std::vector<Timer *> TimerStack;
28 static std::atomic<Timer::Category *> g_categories;
29 } // end of anonymous namespace
30
31 std::atomic<bool> Timer::g_quiet(true);
32 std::atomic<unsigned> Timer::g_display_depth(0);
GetFileMutex()33 static std::mutex &GetFileMutex() {
34 static std::mutex *g_file_mutex_ptr = new std::mutex();
35 return *g_file_mutex_ptr;
36 }
37
GetTimerStackForCurrentThread()38 static TimerStack &GetTimerStackForCurrentThread() {
39 static thread_local TimerStack g_stack;
40 return g_stack;
41 }
42
Category(const char * cat)43 Timer::Category::Category(const char *cat) : m_name(cat) {
44 m_nanos.store(0, std::memory_order_release);
45 m_nanos_total.store(0, std::memory_order_release);
46 m_count.store(0, std::memory_order_release);
47 Category *expected = g_categories;
48 do {
49 m_next = expected;
50 } while (!g_categories.compare_exchange_weak(expected, this));
51 }
52
SetQuiet(bool value)53 void Timer::SetQuiet(bool value) { g_quiet = value; }
54
Timer(Timer::Category & category,const char * format,...)55 Timer::Timer(Timer::Category &category, const char *format, ...)
56 : m_category(category), m_total_start(std::chrono::steady_clock::now()) {
57 TimerStack &stack = GetTimerStackForCurrentThread();
58
59 stack.push_back(this);
60 if (g_quiet && stack.size() <= g_display_depth) {
61 std::lock_guard<std::mutex> lock(GetFileMutex());
62
63 // Indent
64 ::fprintf(stdout, "%*s", int(stack.size() - 1) * TIMER_INDENT_AMOUNT, "");
65 // Print formatted string
66 va_list args;
67 va_start(args, format);
68 ::vfprintf(stdout, format, args);
69 va_end(args);
70
71 // Newline
72 ::fprintf(stdout, "\n");
73 }
74 }
75
~Timer()76 Timer::~Timer() {
77 using namespace std::chrono;
78
79 auto stop_time = steady_clock::now();
80 auto total_dur = stop_time - m_total_start;
81 auto timer_dur = total_dur - m_child_duration;
82
83 TimerStack &stack = GetTimerStackForCurrentThread();
84 if (g_quiet && stack.size() <= g_display_depth) {
85 std::lock_guard<std::mutex> lock(GetFileMutex());
86 ::fprintf(stdout, "%*s%.9f sec (%.9f sec)\n",
87 int(stack.size() - 1) * TIMER_INDENT_AMOUNT, "",
88 duration<double>(total_dur).count(),
89 duration<double>(timer_dur).count());
90 }
91
92 assert(stack.back() == this);
93 stack.pop_back();
94 if (!stack.empty())
95 stack.back()->ChildDuration(total_dur);
96
97 // Keep total results for each category so we can dump results.
98 m_category.m_nanos += std::chrono::nanoseconds(timer_dur).count();
99 m_category.m_nanos_total += std::chrono::nanoseconds(total_dur).count();
100 m_category.m_count++;
101 }
102
SetDisplayDepth(uint32_t depth)103 void Timer::SetDisplayDepth(uint32_t depth) { g_display_depth = depth; }
104
105 /* binary function predicate:
106 * - returns whether a person is less than another person
107 */
108 namespace {
109 struct Stats {
110 const char *name;
111 uint64_t nanos;
112 uint64_t nanos_total;
113 uint64_t count;
114 };
115 } // namespace
116
CategoryMapIteratorSortCriterion(const Stats & lhs,const Stats & rhs)117 static bool CategoryMapIteratorSortCriterion(const Stats &lhs,
118 const Stats &rhs) {
119 return lhs.nanos > rhs.nanos;
120 }
121
ResetCategoryTimes()122 void Timer::ResetCategoryTimes() {
123 for (Category *i = g_categories; i; i = i->m_next) {
124 i->m_nanos.store(0, std::memory_order_release);
125 i->m_nanos_total.store(0, std::memory_order_release);
126 i->m_count.store(0, std::memory_order_release);
127 }
128 }
129
DumpCategoryTimes(Stream * s)130 void Timer::DumpCategoryTimes(Stream *s) {
131 std::vector<Stats> sorted;
132 for (Category *i = g_categories; i; i = i->m_next) {
133 uint64_t nanos = i->m_nanos.load(std::memory_order_acquire);
134 if (nanos) {
135 uint64_t nanos_total = i->m_nanos_total.load(std::memory_order_acquire);
136 uint64_t count = i->m_count.load(std::memory_order_acquire);
137 Stats stats{i->m_name, nanos, nanos_total, count};
138 sorted.push_back(stats);
139 }
140 }
141 if (sorted.empty())
142 return; // Later code will break without any elements.
143
144 // Sort by time
145 llvm::sort(sorted.begin(), sorted.end(), CategoryMapIteratorSortCriterion);
146
147 for (const auto &stats : sorted)
148 s->Printf("%.9f sec (total: %.3fs; child: %.3fs; count: %" PRIu64
149 ") for %s\n",
150 stats.nanos / 1000000000., stats.nanos_total / 1000000000.,
151 (stats.nanos_total - stats.nanos) / 1000000000., stats.count,
152 stats.name);
153 }
154