1 //===-- Timer.cpp -----------------------------------------------*- C++ -*-===//
2 //
3 // The LLVM Compiler Infrastructure
4 //
5 // This file is distributed under the University of Illinois Open Source
6 // License. See LICENSE.TXT for details.
7 //
8 //===----------------------------------------------------------------------===//
9 #include "lldb/Core/Timer.h"
10
11 #include <map>
12 #include <vector>
13 #include <algorithm>
14
15 #include "lldb/Core/Stream.h"
16 #include "lldb/Host/Mutex.h"
17
18 #include <stdio.h>
19
20 using namespace lldb_private;
21
22 #define TIMER_INDENT_AMOUNT 2
23 static bool g_quiet = true;
24 uint32_t Timer::g_depth = 0;
25 uint32_t Timer::g_display_depth = 0;
26 FILE * Timer::g_file = NULL;
27 typedef std::vector<Timer *> TimerStack;
28 typedef std::map<const char *, uint64_t> TimerCategoryMap;
29 static pthread_key_t g_key;
30
31 static Mutex &
GetCategoryMutex()32 GetCategoryMutex()
33 {
34 static Mutex g_category_mutex(Mutex::eMutexTypeNormal);
35 return g_category_mutex;
36 }
37
38 static TimerCategoryMap &
GetCategoryMap()39 GetCategoryMap()
40 {
41 static TimerCategoryMap g_category_map;
42 return g_category_map;
43 }
44
45
46 static TimerStack *
GetTimerStackForCurrentThread()47 GetTimerStackForCurrentThread ()
48 {
49 void *timer_stack = ::pthread_getspecific (g_key);
50 if (timer_stack == NULL)
51 {
52 ::pthread_setspecific (g_key, new TimerStack);
53 timer_stack = ::pthread_getspecific (g_key);
54 }
55 return (TimerStack *)timer_stack;
56 }
57
58 void
ThreadSpecificCleanup(void * p)59 ThreadSpecificCleanup (void *p)
60 {
61 delete (TimerStack *)p;
62 }
63
64 void
SetQuiet(bool value)65 Timer::SetQuiet (bool value)
66 {
67 g_quiet = value;
68 }
69
70 void
Initialize()71 Timer::Initialize ()
72 {
73 Timer::g_file = stdout;
74 ::pthread_key_create (&g_key, ThreadSpecificCleanup);
75
76 }
77
Timer(const char * category,const char * format,...)78 Timer::Timer (const char *category, const char *format, ...) :
79 m_category (category),
80 m_total_start (),
81 m_timer_start (),
82 m_total_ticks (0),
83 m_timer_ticks (0)
84 {
85 if (g_depth++ < g_display_depth)
86 {
87 if (g_quiet == false)
88 {
89 // Indent
90 ::fprintf (g_file, "%*s", g_depth * TIMER_INDENT_AMOUNT, "");
91 // Print formatted string
92 va_list args;
93 va_start (args, format);
94 ::vfprintf (g_file, format, args);
95 va_end (args);
96
97 // Newline
98 ::fprintf (g_file, "\n");
99 }
100 TimeValue start_time(TimeValue::Now());
101 m_total_start = start_time;
102 m_timer_start = start_time;
103 TimerStack *stack = GetTimerStackForCurrentThread ();
104 if (stack)
105 {
106 if (stack->empty() == false)
107 stack->back()->ChildStarted (start_time);
108 stack->push_back(this);
109 }
110 }
111 }
112
113
~Timer()114 Timer::~Timer()
115 {
116 if (m_total_start.IsValid())
117 {
118 TimeValue stop_time = TimeValue::Now();
119 if (m_total_start.IsValid())
120 {
121 m_total_ticks += (stop_time - m_total_start);
122 m_total_start.Clear();
123 }
124 if (m_timer_start.IsValid())
125 {
126 m_timer_ticks += (stop_time - m_timer_start);
127 m_timer_start.Clear();
128 }
129
130 TimerStack *stack = GetTimerStackForCurrentThread ();
131 if (stack)
132 {
133 assert (stack->back() == this);
134 stack->pop_back();
135 if (stack->empty() == false)
136 stack->back()->ChildStopped(stop_time);
137 }
138
139 const uint64_t total_nsec_uint = GetTotalElapsedNanoSeconds();
140 const uint64_t timer_nsec_uint = GetTimerElapsedNanoSeconds();
141 const double total_nsec = total_nsec_uint;
142 const double timer_nsec = timer_nsec_uint;
143
144 if (g_quiet == false)
145 {
146
147 ::fprintf (g_file,
148 "%*s%.9f sec (%.9f sec)\n",
149 (g_depth - 1) *TIMER_INDENT_AMOUNT, "",
150 total_nsec / 1000000000.0,
151 timer_nsec / 1000000000.0);
152 }
153
154 // Keep total results for each category so we can dump results.
155 Mutex::Locker locker (GetCategoryMutex());
156 TimerCategoryMap &category_map = GetCategoryMap();
157 category_map[m_category] += timer_nsec_uint;
158 }
159 if (g_depth > 0)
160 --g_depth;
161 }
162
163 uint64_t
GetTotalElapsedNanoSeconds()164 Timer::GetTotalElapsedNanoSeconds()
165 {
166 uint64_t total_ticks = m_total_ticks;
167
168 // If we are currently running, we need to add the current
169 // elapsed time of the running timer...
170 if (m_total_start.IsValid())
171 total_ticks += (TimeValue::Now() - m_total_start);
172
173 return total_ticks;
174 }
175
176 uint64_t
GetTimerElapsedNanoSeconds()177 Timer::GetTimerElapsedNanoSeconds()
178 {
179 uint64_t timer_ticks = m_timer_ticks;
180
181 // If we are currently running, we need to add the current
182 // elapsed time of the running timer...
183 if (m_timer_start.IsValid())
184 timer_ticks += (TimeValue::Now() - m_timer_start);
185
186 return timer_ticks;
187 }
188
189 void
ChildStarted(const TimeValue & start_time)190 Timer::ChildStarted (const TimeValue& start_time)
191 {
192 if (m_timer_start.IsValid())
193 {
194 m_timer_ticks += (start_time - m_timer_start);
195 m_timer_start.Clear();
196 }
197 }
198
199 void
ChildStopped(const TimeValue & stop_time)200 Timer::ChildStopped (const TimeValue& stop_time)
201 {
202 if (!m_timer_start.IsValid())
203 m_timer_start = stop_time;
204 }
205
206 void
SetDisplayDepth(uint32_t depth)207 Timer::SetDisplayDepth (uint32_t depth)
208 {
209 g_display_depth = depth;
210 }
211
212
213 /* binary function predicate:
214 * - returns whether a person is less than another person
215 */
216 static bool
CategoryMapIteratorSortCriterion(const TimerCategoryMap::const_iterator & lhs,const TimerCategoryMap::const_iterator & rhs)217 CategoryMapIteratorSortCriterion (const TimerCategoryMap::const_iterator& lhs, const TimerCategoryMap::const_iterator& rhs)
218 {
219 return lhs->second > rhs->second;
220 }
221
222
223 void
ResetCategoryTimes()224 Timer::ResetCategoryTimes ()
225 {
226 Mutex::Locker locker (GetCategoryMutex());
227 TimerCategoryMap &category_map = GetCategoryMap();
228 category_map.clear();
229 }
230
231 void
DumpCategoryTimes(Stream * s)232 Timer::DumpCategoryTimes (Stream *s)
233 {
234 Mutex::Locker locker (GetCategoryMutex());
235 TimerCategoryMap &category_map = GetCategoryMap();
236 std::vector<TimerCategoryMap::const_iterator> sorted_iterators;
237 TimerCategoryMap::const_iterator pos, end = category_map.end();
238 for (pos = category_map.begin(); pos != end; ++pos)
239 {
240 sorted_iterators.push_back (pos);
241 }
242 std::sort (sorted_iterators.begin(), sorted_iterators.end(), CategoryMapIteratorSortCriterion);
243
244 const size_t count = sorted_iterators.size();
245 for (size_t i=0; i<count; ++i)
246 {
247 const double timer_nsec = sorted_iterators[i]->second;
248 s->Printf("%.9f sec for %s\n", timer_nsec / 1000000000.0, sorted_iterators[i]->first);
249 }
250 }
251