Timer.cpp revision 263363 
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#include "lldb/Host/Host.h"
18
19#include <stdio.h>
20
21using namespace lldb_private;
22
23#define TIMER_INDENT_AMOUNT 2
24static bool g_quiet = true;
25uint32_t Timer::g_depth = 0;
26uint32_t Timer::g_display_depth = 0;
27FILE * Timer::g_file = NULL;
28typedef std::vector<Timer *> TimerStack;
29typedef std::map<const char *, uint64_t> TimerCategoryMap;
30static lldb::thread_key_t g_key;
31
32static Mutex &
33GetCategoryMutex()
34{
35    static Mutex g_category_mutex(Mutex::eMutexTypeNormal);
36    return g_category_mutex;
37}
38
39static TimerCategoryMap &
40GetCategoryMap()
41{
42    static TimerCategoryMap g_category_map;
43    return g_category_map;
44}
45
46
47static TimerStack *
48GetTimerStackForCurrentThread ()
49{
50    void *timer_stack = Host::ThreadLocalStorageGet(g_key);
51    if (timer_stack == NULL)
52    {
53        Host::ThreadLocalStorageSet(g_key, new TimerStack);
54        timer_stack = Host::ThreadLocalStorageGet(g_key);
55    }
56    return (TimerStack *)timer_stack;
57}
58
59void
60ThreadSpecificCleanup (void *p)
61{
62    delete (TimerStack *)p;
63}
64
65void
66Timer::SetQuiet (bool value)
67{
68    g_quiet = value;
69}
70
71void
72Timer::Initialize ()
73{
74    Timer::g_file = stdout;
75    g_key = Host::ThreadLocalStorageCreate(ThreadSpecificCleanup);
76}
77
78Timer::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
114Timer::~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
163uint64_t
164Timer::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
176uint64_t
177Timer::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
189void
190Timer::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
199void
200Timer::ChildStopped (const TimeValue& stop_time)
201{
202    if (!m_timer_start.IsValid())
203        m_timer_start = stop_time;
204}
205
206void
207Timer::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 */
216static bool
217CategoryMapIteratorSortCriterion (const TimerCategoryMap::const_iterator& lhs, const TimerCategoryMap::const_iterator& rhs)
218{
219    return lhs->second > rhs->second;
220}
221
222
223void
224Timer::ResetCategoryTimes ()
225{
226    Mutex::Locker locker (GetCategoryMutex());
227    TimerCategoryMap &category_map = GetCategoryMap();
228    category_map.clear();
229}
230
231void
232Timer::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