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