1254721Semaste//===-- Timer.cpp -----------------------------------------------*- C++ -*-===// 2254721Semaste// 3254721Semaste// The LLVM Compiler Infrastructure 4254721Semaste// 5254721Semaste// This file is distributed under the University of Illinois Open Source 6254721Semaste// License. See LICENSE.TXT for details. 7254721Semaste// 8254721Semaste//===----------------------------------------------------------------------===// 9254721Semaste#include "lldb/Core/Timer.h" 10254721Semaste 11254721Semaste#include <map> 12254721Semaste#include <vector> 13254721Semaste#include <algorithm> 14254721Semaste 15254721Semaste#include "lldb/Core/Stream.h" 16254721Semaste#include "lldb/Host/Mutex.h" 17263363Semaste#include "lldb/Host/Host.h" 18254721Semaste 19254721Semaste#include <stdio.h> 20254721Semaste 21254721Semasteusing namespace lldb_private; 22254721Semaste 23254721Semaste#define TIMER_INDENT_AMOUNT 2 24254721Semastestatic bool g_quiet = true; 25254721Semasteuint32_t Timer::g_depth = 0; 26254721Semasteuint32_t Timer::g_display_depth = 0; 27254721SemasteFILE * Timer::g_file = NULL; 28254721Semastetypedef std::vector<Timer *> TimerStack; 29254721Semastetypedef std::map<const char *, uint64_t> TimerCategoryMap; 30263363Semastestatic lldb::thread_key_t g_key; 31254721Semaste 32254721Semastestatic Mutex & 33254721SemasteGetCategoryMutex() 34254721Semaste{ 35254721Semaste static Mutex g_category_mutex(Mutex::eMutexTypeNormal); 36254721Semaste return g_category_mutex; 37254721Semaste} 38254721Semaste 39254721Semastestatic TimerCategoryMap & 40254721SemasteGetCategoryMap() 41254721Semaste{ 42254721Semaste static TimerCategoryMap g_category_map; 43254721Semaste return g_category_map; 44254721Semaste} 45254721Semaste 46254721Semaste 47254721Semastestatic TimerStack * 48254721SemasteGetTimerStackForCurrentThread () 49254721Semaste{ 50263363Semaste void *timer_stack = Host::ThreadLocalStorageGet(g_key); 51254721Semaste if (timer_stack == NULL) 52254721Semaste { 53263363Semaste Host::ThreadLocalStorageSet(g_key, new TimerStack); 54263363Semaste timer_stack = Host::ThreadLocalStorageGet(g_key); 55254721Semaste } 56254721Semaste return (TimerStack *)timer_stack; 57254721Semaste} 58254721Semaste 59254721Semastevoid 60254721SemasteThreadSpecificCleanup (void *p) 61254721Semaste{ 62254721Semaste delete (TimerStack *)p; 63254721Semaste} 64254721Semaste 65254721Semastevoid 66254721SemasteTimer::SetQuiet (bool value) 67254721Semaste{ 68254721Semaste g_quiet = value; 69254721Semaste} 70254721Semaste 71254721Semastevoid 72254721SemasteTimer::Initialize () 73254721Semaste{ 74254721Semaste Timer::g_file = stdout; 75263363Semaste g_key = Host::ThreadLocalStorageCreate(ThreadSpecificCleanup); 76254721Semaste} 77254721Semaste 78254721SemasteTimer::Timer (const char *category, const char *format, ...) : 79254721Semaste m_category (category), 80254721Semaste m_total_start (), 81254721Semaste m_timer_start (), 82254721Semaste m_total_ticks (0), 83254721Semaste m_timer_ticks (0) 84254721Semaste{ 85254721Semaste if (g_depth++ < g_display_depth) 86254721Semaste { 87254721Semaste if (g_quiet == false) 88254721Semaste { 89254721Semaste // Indent 90254721Semaste ::fprintf (g_file, "%*s", g_depth * TIMER_INDENT_AMOUNT, ""); 91254721Semaste // Print formatted string 92254721Semaste va_list args; 93254721Semaste va_start (args, format); 94254721Semaste ::vfprintf (g_file, format, args); 95254721Semaste va_end (args); 96254721Semaste 97254721Semaste // Newline 98254721Semaste ::fprintf (g_file, "\n"); 99254721Semaste } 100254721Semaste TimeValue start_time(TimeValue::Now()); 101254721Semaste m_total_start = start_time; 102254721Semaste m_timer_start = start_time; 103254721Semaste TimerStack *stack = GetTimerStackForCurrentThread (); 104254721Semaste if (stack) 105254721Semaste { 106254721Semaste if (stack->empty() == false) 107254721Semaste stack->back()->ChildStarted (start_time); 108254721Semaste stack->push_back(this); 109254721Semaste } 110254721Semaste } 111254721Semaste} 112254721Semaste 113254721Semaste 114254721SemasteTimer::~Timer() 115254721Semaste{ 116254721Semaste if (m_total_start.IsValid()) 117254721Semaste { 118254721Semaste TimeValue stop_time = TimeValue::Now(); 119254721Semaste if (m_total_start.IsValid()) 120254721Semaste { 121254721Semaste m_total_ticks += (stop_time - m_total_start); 122254721Semaste m_total_start.Clear(); 123254721Semaste } 124254721Semaste if (m_timer_start.IsValid()) 125254721Semaste { 126254721Semaste m_timer_ticks += (stop_time - m_timer_start); 127254721Semaste m_timer_start.Clear(); 128254721Semaste } 129254721Semaste 130254721Semaste TimerStack *stack = GetTimerStackForCurrentThread (); 131254721Semaste if (stack) 132254721Semaste { 133254721Semaste assert (stack->back() == this); 134254721Semaste stack->pop_back(); 135254721Semaste if (stack->empty() == false) 136254721Semaste stack->back()->ChildStopped(stop_time); 137254721Semaste } 138254721Semaste 139254721Semaste const uint64_t total_nsec_uint = GetTotalElapsedNanoSeconds(); 140254721Semaste const uint64_t timer_nsec_uint = GetTimerElapsedNanoSeconds(); 141254721Semaste const double total_nsec = total_nsec_uint; 142254721Semaste const double timer_nsec = timer_nsec_uint; 143254721Semaste 144254721Semaste if (g_quiet == false) 145254721Semaste { 146254721Semaste 147254721Semaste ::fprintf (g_file, 148254721Semaste "%*s%.9f sec (%.9f sec)\n", 149254721Semaste (g_depth - 1) *TIMER_INDENT_AMOUNT, "", 150254721Semaste total_nsec / 1000000000.0, 151254721Semaste timer_nsec / 1000000000.0); 152254721Semaste } 153254721Semaste 154254721Semaste // Keep total results for each category so we can dump results. 155254721Semaste Mutex::Locker locker (GetCategoryMutex()); 156254721Semaste TimerCategoryMap &category_map = GetCategoryMap(); 157254721Semaste category_map[m_category] += timer_nsec_uint; 158254721Semaste } 159254721Semaste if (g_depth > 0) 160254721Semaste --g_depth; 161254721Semaste} 162254721Semaste 163254721Semasteuint64_t 164254721SemasteTimer::GetTotalElapsedNanoSeconds() 165254721Semaste{ 166254721Semaste uint64_t total_ticks = m_total_ticks; 167254721Semaste 168254721Semaste // If we are currently running, we need to add the current 169254721Semaste // elapsed time of the running timer... 170254721Semaste if (m_total_start.IsValid()) 171254721Semaste total_ticks += (TimeValue::Now() - m_total_start); 172254721Semaste 173254721Semaste return total_ticks; 174254721Semaste} 175254721Semaste 176254721Semasteuint64_t 177254721SemasteTimer::GetTimerElapsedNanoSeconds() 178254721Semaste{ 179254721Semaste uint64_t timer_ticks = m_timer_ticks; 180254721Semaste 181254721Semaste // If we are currently running, we need to add the current 182254721Semaste // elapsed time of the running timer... 183254721Semaste if (m_timer_start.IsValid()) 184254721Semaste timer_ticks += (TimeValue::Now() - m_timer_start); 185254721Semaste 186254721Semaste return timer_ticks; 187254721Semaste} 188254721Semaste 189254721Semastevoid 190254721SemasteTimer::ChildStarted (const TimeValue& start_time) 191254721Semaste{ 192254721Semaste if (m_timer_start.IsValid()) 193254721Semaste { 194254721Semaste m_timer_ticks += (start_time - m_timer_start); 195254721Semaste m_timer_start.Clear(); 196254721Semaste } 197254721Semaste} 198254721Semaste 199254721Semastevoid 200254721SemasteTimer::ChildStopped (const TimeValue& stop_time) 201254721Semaste{ 202254721Semaste if (!m_timer_start.IsValid()) 203254721Semaste m_timer_start = stop_time; 204254721Semaste} 205254721Semaste 206254721Semastevoid 207254721SemasteTimer::SetDisplayDepth (uint32_t depth) 208254721Semaste{ 209254721Semaste g_display_depth = depth; 210254721Semaste} 211254721Semaste 212254721Semaste 213254721Semaste/* binary function predicate: 214254721Semaste * - returns whether a person is less than another person 215254721Semaste */ 216254721Semastestatic bool 217254721SemasteCategoryMapIteratorSortCriterion (const TimerCategoryMap::const_iterator& lhs, const TimerCategoryMap::const_iterator& rhs) 218254721Semaste{ 219254721Semaste return lhs->second > rhs->second; 220254721Semaste} 221254721Semaste 222254721Semaste 223254721Semastevoid 224254721SemasteTimer::ResetCategoryTimes () 225254721Semaste{ 226254721Semaste Mutex::Locker locker (GetCategoryMutex()); 227254721Semaste TimerCategoryMap &category_map = GetCategoryMap(); 228254721Semaste category_map.clear(); 229254721Semaste} 230254721Semaste 231254721Semastevoid 232254721SemasteTimer::DumpCategoryTimes (Stream *s) 233254721Semaste{ 234254721Semaste Mutex::Locker locker (GetCategoryMutex()); 235254721Semaste TimerCategoryMap &category_map = GetCategoryMap(); 236254721Semaste std::vector<TimerCategoryMap::const_iterator> sorted_iterators; 237254721Semaste TimerCategoryMap::const_iterator pos, end = category_map.end(); 238254721Semaste for (pos = category_map.begin(); pos != end; ++pos) 239254721Semaste { 240254721Semaste sorted_iterators.push_back (pos); 241254721Semaste } 242254721Semaste std::sort (sorted_iterators.begin(), sorted_iterators.end(), CategoryMapIteratorSortCriterion); 243254721Semaste 244254721Semaste const size_t count = sorted_iterators.size(); 245254721Semaste for (size_t i=0; i<count; ++i) 246254721Semaste { 247254721Semaste const double timer_nsec = sorted_iterators[i]->second; 248254721Semaste s->Printf("%.9f sec for %s\n", timer_nsec / 1000000000.0, sorted_iterators[i]->first); 249254721Semaste } 250254721Semaste} 251