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