LLDB  mainline
Timer.cpp
Go to the documentation of this file.
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 
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();
109 }
110 
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 
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 
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 }
lldb_private::Timer::Category
Definition: Timer.h:25
lldb_private::Timer::Category::m_nanos_total
std::atomic< uint64_t > m_nanos_total
Definition: Timer.h:34
lldb_private::Timer::SetDisplayDepth
static void SetDisplayDepth(uint32_t depth)
Definition: Timer.cpp:111
Signposts
static llvm::ManagedStatic< llvm::SignpostEmitter > Signposts
Allows llvm::Timer to emit signposts when supported.
Definition: Timer.cpp:34
lldb_private::Timer::Category::m_nanos
std::atomic< uint64_t > m_nanos
Definition: Timer.h:33
lldb_private::Timer::g_quiet
static std::atomic< bool > g_quiet
Definition: Timer.h:71
lldb_private::Timer::m_category
Category & m_category
Definition: Timer.h:67
lldb_private::Stream
Definition: Stream.h:28
lldb_private::Timer::Timer
Timer(Category &category, const char *format,...) __attribute__((format(printf
Default constructor.
Definition: Timer.cpp:60
lldb_private::Timer::Category::m_count
std::atomic< uint64_t > m_count
Definition: Timer.h:35
lldb_private::Timer::DumpCategoryTimes
static void DumpCategoryTimes(Stream *s)
Definition: Timer.cpp:138
TIMER_INDENT_AMOUNT
#define TIMER_INDENT_AMOUNT
Definition: Timer.cpp:26
lldb_private::Timer::m_total_start
TimePoint m_total_start
Definition: Timer.h:68
lldb_private::Timer::SetQuiet
static void SetQuiet(bool value)
Definition: Timer.cpp:58
g_categories
static constexpr Log::Category g_categories[]
Definition: ProcessGDBRemoteLog.cpp:17
lldb_private::Timer::~Timer
~Timer()
Destructor.
Definition: Timer.cpp:82
GetTimerStackForCurrentThread
static TimerStack & GetTimerStackForCurrentThread()
Definition: Timer.cpp:43
Timer.h
CategoryMapIteratorSortCriterion
static bool CategoryMapIteratorSortCriterion(const Stats &lhs, const Stats &rhs)
Definition: Timer.cpp:125
lldb_private::Timer::g_display_depth
static std::atomic< unsigned > g_display_depth
Definition: Timer.h:72
uint32_t
lldb_private::Timer::ResetCategoryTimes
static void ResetCategoryTimes()
Definition: Timer.cpp:130
lldb_private::Stream::Printf
size_t Printf(const char *format,...) __attribute__((format(printf
Output printf formatted output to the stream.
Definition: Stream.cpp:107
lldb_private
A class that represents a running process on the host machine.
Definition: SBCommandInterpreterRunOptions.h:16
lldb_private::Timer::m_child_duration
TimePoint::duration m_child_duration
Definition: Timer.h:69
lldb_private::Timer::Category::m_next
std::atomic< Category * > m_next
Definition: Timer.h:36
Stream.h
lldb_private::Timer::Category::GetName
llvm::StringRef GetName()
Definition: Timer.h:28
GetFileMutex
static std::mutex & GetFileMutex()
Definition: Timer.cpp:38
lldb_private::Timer::Category::Category
Category(const char *category_name)
Definition: Timer.cpp:48