138d0632eSPavel Labath //===-- Timer.cpp -----------------------------------------------*- C++ -*-===// 238d0632eSPavel Labath // 32946cd70SChandler Carruth // Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions. 42946cd70SChandler Carruth // See https://llvm.org/LICENSE.txt for license information. 52946cd70SChandler Carruth // SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception 638d0632eSPavel Labath // 738d0632eSPavel Labath //===----------------------------------------------------------------------===// 838d0632eSPavel Labath #include "lldb/Utility/Timer.h" 938d0632eSPavel Labath #include "lldb/Utility/Stream.h" 1038d0632eSPavel Labath 1138d0632eSPavel Labath #include <algorithm> 1238d0632eSPavel Labath #include <map> 1338d0632eSPavel Labath #include <mutex> 14672d2c12SJonas Devlieghere #include <utility> 1538d0632eSPavel Labath #include <vector> 1638d0632eSPavel Labath 17672d2c12SJonas Devlieghere #include <assert.h> 18672d2c12SJonas Devlieghere #include <stdarg.h> 1938d0632eSPavel Labath #include <stdio.h> 2038d0632eSPavel Labath 2138d0632eSPavel Labath using namespace lldb_private; 2238d0632eSPavel Labath 2338d0632eSPavel Labath #define TIMER_INDENT_AMOUNT 2 2438d0632eSPavel Labath 2538d0632eSPavel Labath namespace { 2638d0632eSPavel Labath typedef std::vector<Timer *> TimerStack; 2738d0632eSPavel Labath static std::atomic<Timer::Category *> g_categories; 2838d0632eSPavel Labath } // end of anonymous namespace 2938d0632eSPavel Labath 3038d0632eSPavel Labath std::atomic<bool> Timer::g_quiet(true); 3138d0632eSPavel Labath std::atomic<unsigned> Timer::g_display_depth(0); 3238d0632eSPavel Labath static std::mutex &GetFileMutex() { 3338d0632eSPavel Labath static std::mutex *g_file_mutex_ptr = new std::mutex(); 3438d0632eSPavel Labath return *g_file_mutex_ptr; 3538d0632eSPavel Labath } 3638d0632eSPavel Labath 3738d0632eSPavel Labath static TimerStack &GetTimerStackForCurrentThread() { 3838d0632eSPavel Labath static thread_local TimerStack g_stack; 3938d0632eSPavel Labath return g_stack; 4038d0632eSPavel Labath } 4138d0632eSPavel Labath 4238d0632eSPavel Labath Timer::Category::Category(const char *cat) : m_name(cat) { 4338d0632eSPavel Labath m_nanos.store(0, std::memory_order_release); 4478337420SAntonio Afonso m_nanos_total.store(0, std::memory_order_release); 4578337420SAntonio Afonso m_count.store(0, std::memory_order_release); 4638d0632eSPavel Labath Category *expected = g_categories; 4738d0632eSPavel Labath do { 4838d0632eSPavel Labath m_next = expected; 4938d0632eSPavel Labath } while (!g_categories.compare_exchange_weak(expected, this)); 5038d0632eSPavel Labath } 5138d0632eSPavel Labath 5238d0632eSPavel Labath void Timer::SetQuiet(bool value) { g_quiet = value; } 5338d0632eSPavel Labath 5438d0632eSPavel Labath Timer::Timer(Timer::Category &category, const char *format, ...) 5538d0632eSPavel Labath : m_category(category), m_total_start(std::chrono::steady_clock::now()) { 5638d0632eSPavel Labath TimerStack &stack = GetTimerStackForCurrentThread(); 5738d0632eSPavel Labath 5838d0632eSPavel Labath stack.push_back(this); 5938d0632eSPavel Labath if (g_quiet && stack.size() <= g_display_depth) { 6038d0632eSPavel Labath std::lock_guard<std::mutex> lock(GetFileMutex()); 6138d0632eSPavel Labath 6238d0632eSPavel Labath // Indent 6338d0632eSPavel Labath ::fprintf(stdout, "%*s", int(stack.size() - 1) * TIMER_INDENT_AMOUNT, ""); 6438d0632eSPavel Labath // Print formatted string 6538d0632eSPavel Labath va_list args; 6638d0632eSPavel Labath va_start(args, format); 6738d0632eSPavel Labath ::vfprintf(stdout, format, args); 6838d0632eSPavel Labath va_end(args); 6938d0632eSPavel Labath 7038d0632eSPavel Labath // Newline 7138d0632eSPavel Labath ::fprintf(stdout, "\n"); 7238d0632eSPavel Labath } 7338d0632eSPavel Labath } 7438d0632eSPavel Labath 7538d0632eSPavel Labath Timer::~Timer() { 7638d0632eSPavel Labath using namespace std::chrono; 7738d0632eSPavel Labath 7838d0632eSPavel Labath auto stop_time = steady_clock::now(); 7938d0632eSPavel Labath auto total_dur = stop_time - m_total_start; 8038d0632eSPavel Labath auto timer_dur = total_dur - m_child_duration; 8138d0632eSPavel Labath 8238d0632eSPavel Labath TimerStack &stack = GetTimerStackForCurrentThread(); 8338d0632eSPavel Labath if (g_quiet && stack.size() <= g_display_depth) { 8438d0632eSPavel Labath std::lock_guard<std::mutex> lock(GetFileMutex()); 8538d0632eSPavel Labath ::fprintf(stdout, "%*s%.9f sec (%.9f sec)\n", 8638d0632eSPavel Labath int(stack.size() - 1) * TIMER_INDENT_AMOUNT, "", 8738d0632eSPavel Labath duration<double>(total_dur).count(), 8838d0632eSPavel Labath duration<double>(timer_dur).count()); 8938d0632eSPavel Labath } 9038d0632eSPavel Labath 9138d0632eSPavel Labath assert(stack.back() == this); 9238d0632eSPavel Labath stack.pop_back(); 9338d0632eSPavel Labath if (!stack.empty()) 9438d0632eSPavel Labath stack.back()->ChildDuration(total_dur); 9538d0632eSPavel Labath 9638d0632eSPavel Labath // Keep total results for each category so we can dump results. 9738d0632eSPavel Labath m_category.m_nanos += std::chrono::nanoseconds(timer_dur).count(); 9878337420SAntonio Afonso m_category.m_nanos_total += std::chrono::nanoseconds(total_dur).count(); 9978337420SAntonio Afonso m_category.m_count++; 10038d0632eSPavel Labath } 10138d0632eSPavel Labath 10238d0632eSPavel Labath void Timer::SetDisplayDepth(uint32_t depth) { g_display_depth = depth; } 10338d0632eSPavel Labath 10438d0632eSPavel Labath /* binary function predicate: 10538d0632eSPavel Labath * - returns whether a person is less than another person 10638d0632eSPavel Labath */ 10778337420SAntonio Afonso namespace { 10878337420SAntonio Afonso struct Stats { 10978337420SAntonio Afonso const char *name; 11078337420SAntonio Afonso uint64_t nanos; 11178337420SAntonio Afonso uint64_t nanos_total; 11278337420SAntonio Afonso uint64_t count; 11378337420SAntonio Afonso }; 11478337420SAntonio Afonso } // namespace 11538d0632eSPavel Labath 11678337420SAntonio Afonso static bool CategoryMapIteratorSortCriterion(const Stats &lhs, 11778337420SAntonio Afonso const Stats &rhs) { 11878337420SAntonio Afonso return lhs.nanos > rhs.nanos; 11938d0632eSPavel Labath } 12038d0632eSPavel Labath 12138d0632eSPavel Labath void Timer::ResetCategoryTimes() { 12278337420SAntonio Afonso for (Category *i = g_categories; i; i = i->m_next) { 12338d0632eSPavel Labath i->m_nanos.store(0, std::memory_order_release); 12478337420SAntonio Afonso i->m_nanos_total.store(0, std::memory_order_release); 12578337420SAntonio Afonso i->m_count.store(0, std::memory_order_release); 12678337420SAntonio Afonso } 12738d0632eSPavel Labath } 12838d0632eSPavel Labath 12938d0632eSPavel Labath void Timer::DumpCategoryTimes(Stream *s) { 13078337420SAntonio Afonso std::vector<Stats> sorted; 13138d0632eSPavel Labath for (Category *i = g_categories; i; i = i->m_next) { 13238d0632eSPavel Labath uint64_t nanos = i->m_nanos.load(std::memory_order_acquire); 13378337420SAntonio Afonso if (nanos) { 13478337420SAntonio Afonso uint64_t nanos_total = i->m_nanos_total.load(std::memory_order_acquire); 13578337420SAntonio Afonso uint64_t count = i->m_count.load(std::memory_order_acquire); 13678337420SAntonio Afonso Stats stats{i->m_name, nanos, nanos_total, count}; 13778337420SAntonio Afonso sorted.push_back(stats); 13878337420SAntonio Afonso } 13938d0632eSPavel Labath } 14038d0632eSPavel Labath if (sorted.empty()) 14138d0632eSPavel Labath return; // Later code will break without any elements. 14238d0632eSPavel Labath 14338d0632eSPavel Labath // Sort by time 1449bbba276SJonas Devlieghere llvm::sort(sorted.begin(), sorted.end(), CategoryMapIteratorSortCriterion); 14538d0632eSPavel Labath 14678337420SAntonio Afonso for (const auto &stats : sorted) 147*c8f2efe0SRichard Trieu s->Printf("%.9f sec (total: %.3fs; child: %.3fs; count: %" PRIu64 148*c8f2efe0SRichard Trieu ") for %s\n", 14978337420SAntonio Afonso stats.nanos / 1000000000., stats.nanos_total / 1000000000., 15078337420SAntonio Afonso (stats.nanos_total - stats.nanos) / 1000000000., stats.count, 15178337420SAntonio Afonso stats.name); 15238d0632eSPavel Labath } 153