diff --git a/src/lib/utility/tracing.cpp b/src/lib/utility/tracing.cpp index a314c57e..9540d623 100644 --- a/src/lib/utility/tracing.cpp +++ b/src/lib/utility/tracing.cpp @@ -1,6 +1,6 @@ #include "utility/tracing.h" -#include "utility/utility.h" +#include std::shared_ptr Tracer::s_instance; Id Tracer::s_nextTraceId = 0; @@ -15,26 +15,28 @@ Tracer* Tracer::getInstance() return s_instance.get(); } -TraceEvent* Tracer::startEvent(const std::string& eventName) +std::shared_ptr Tracer::startEvent(const std::string& eventName) { std::lock_guard lock(m_mutex); - std::thread::id id = std::this_thread::get_id(); + const std::thread::id id = std::this_thread::get_id(); + std::shared_ptr event = std::make_shared(eventName, s_nextTraceId++, m_startedEvents[id].size()); - m_events[id].push_back(event); m_startedEvents[id].push(event.get()); - return event.get(); + return event; } -void Tracer::finishEvent(TraceEvent* event) +void Tracer::finishEvent(std::shared_ptr event) { std::lock_guard lock(m_mutex); - std::thread::id id = std::this_thread::get_id(); + const std::thread::id id = std::this_thread::get_id(); + m_startedEvents[id].pop(); + m_events[id].push_back(event); } void Tracer::printTraces() @@ -52,7 +54,7 @@ void Tracer::printTraces() std::cout << "TRACING: Trace events are still running." << std::endl; return; } - else if (!m_events.size()) + else if (m_events.empty()) { std::cout << "TRACING: No trace events collected." << std::endl; return; @@ -108,7 +110,7 @@ void Tracer::printTraces() { for (const std::shared_ptr& event : p.second) { - std::string name = event->eventName + event->functionName + event->locationName; + const std::string name = event->eventName + event->functionName + event->locationName; std::pair::iterator, bool> p = accumulatedEvents.emplace(name, AccumulatedTraceEvent()); @@ -129,11 +131,11 @@ void Tracer::printTraces() } std::multiset> sortedEvents( - [](const AccumulatedTraceEvent& a, const AccumulatedTraceEvent& b) - { - return a.time > b.time; - } + std::function> sortedEvents( + [](const AccumulatedTraceEvent& a, const AccumulatedTraceEvent& b) + { + return a.time > b.time; + } ); for (const std::pair& p : accumulatedEvents) @@ -166,18 +168,111 @@ Tracer::Tracer() } -ScopedTrace::ScopedTrace( - const std::string& eventName, const std::string& fileName, int lineNumber, const std::string& functionName) -{ - m_event = Tracer::getInstance()->startEvent(eventName); - m_event->functionName = functionName; - m_event->locationName = FilePath(fileName).fileName() + ":" + std::to_string(lineNumber); +std::shared_ptr AccumulatingTracer::s_instance; +Id AccumulatingTracer::s_nextTraceId = 0; - m_TimeStamp = utility::durationStart(); +AccumulatingTracer* AccumulatingTracer::getInstance() +{ + if (!s_instance) + { + s_instance = std::shared_ptr(new AccumulatingTracer()); + } + + return s_instance.get(); } -ScopedTrace::~ScopedTrace() +std::shared_ptr AccumulatingTracer::startEvent(const std::string& eventName) +{ + std::lock_guard lock(m_mutex); + + const std::thread::id id = std::this_thread::get_id(); + + std::shared_ptr event = + std::make_shared(eventName, s_nextTraceId++, m_startedEvents[id].size()); + + m_startedEvents[id].push(event.get()); + + return event; +} + +void AccumulatingTracer::finishEvent(std::shared_ptr event) +{ + std::lock_guard lock(m_mutex); + + const std::thread::id id = std::this_thread::get_id(); + + m_startedEvents[id].pop(); + + const std::string name = event->eventName + event->functionName + event->locationName; + + std::pair::iterator, bool> p = + m_accumulatedEvents.emplace(name, AccumulatedTraceEvent()); + + AccumulatedTraceEvent* acc = &p.first->second; + if (p.second) + { + acc->event = TraceEvent(*(event.get())); + acc->time = event->time; + acc->count = 1; + } + else + { + acc->time += event->time; + acc->count++; + } +} + +void AccumulatingTracer::printTraces() +{ + std::lock_guard lock(m_mutex); + + for (auto& p : m_startedEvents) + { + if (!p.second.empty()) + { + std::cout << "TRACING: Trace events are still running." << std::endl; + } + } + + std::cout << "\nREPORT:\n\n"; + std::cout << " time count name function"; + std::cout << " location\n"; + std::cout << "-----------------------------------------------------------------"; + std::cout << "------------------------------------------------------------\n"; + + std::multiset> sortedEvents( + [](const AccumulatedTraceEvent& a, const AccumulatedTraceEvent& b) + { + return a.time > b.time; + } + ); + + for (const std::pair& p : m_accumulatedEvents) + { + sortedEvents.insert(p.second); + } + + for (const AccumulatedTraceEvent& acc : sortedEvents) + { + std::cout.width(8); + std::cout << std::right << std::setprecision(3) << std::fixed << acc.time; + + std::cout.width(10); + std::cout << acc.count << " "; + + std::cout.width(25); + std::cout << std::left << acc.event.eventName; + + std::cout.width(50); + std::cout << (acc.event.functionName + "()") << acc.event.locationName << std::endl; + } + + std::cout << std::endl; + + m_accumulatedEvents.clear(); +} + +AccumulatingTracer::AccumulatingTracer() { - m_event->time = utility::duration(m_TimeStamp); - Tracer::getInstance()->finishEvent(m_event); } diff --git a/src/lib/utility/tracing.h b/src/lib/utility/tracing.h index 025b8deb..1e9d423a 100644 --- a/src/lib/utility/tracing.h +++ b/src/lib/utility/tracing.h @@ -3,6 +3,7 @@ // #define TRACING_ENABLED +// #define USE_ACCUMULATED_TRACING #include @@ -11,10 +12,19 @@ #include "utility/TimeStamp.h" #include "utility/types.h" +#include "utility/utility.h" struct TraceEvent { public: + TraceEvent() + : eventName("") + , id(0) + , depth(0) + , time(0.0f) + { + } + TraceEvent(const std::string& eventName, Id id, size_t depth) : eventName(eventName) , id(id) @@ -23,9 +33,9 @@ public: { } - const std::string eventName; - const Id id; - const size_t depth; + std::string eventName; + Id id; + size_t depth; std::string functionName; std::string locationName; @@ -39,8 +49,8 @@ class Tracer public: static Tracer* getInstance(); - TraceEvent* startEvent(const std::string& eventName); - void finishEvent(TraceEvent* event); + std::shared_ptr startEvent(const std::string& eventName); + void finishEvent(std::shared_ptr event); void printTraces(); @@ -49,8 +59,8 @@ private: static Id s_nextTraceId; Tracer(); - Tracer(const Tracer&); - void operator=(const Tracer&); + Tracer(const Tracer&) = delete; + void operator=(const Tracer&) = delete; std::map>> m_events; std::map> m_startedEvents; @@ -59,6 +69,39 @@ private: }; +class AccumulatingTracer +{ +public: + static AccumulatingTracer* getInstance(); + + std::shared_ptr startEvent(const std::string& eventName); + void finishEvent(std::shared_ptr event); + + void printTraces(); + +private: + struct AccumulatedTraceEvent + { + TraceEvent event; + size_t count; + float time; + }; + + static std::shared_ptr s_instance; + static Id s_nextTraceId; + + AccumulatingTracer(); + AccumulatingTracer(const AccumulatingTracer&) = delete; + void operator=(const AccumulatingTracer&) = delete; + + std::map m_accumulatedEvents; + std::map> m_startedEvents; + + std::mutex m_mutex; +}; + + +template class ScopedTrace { public: @@ -66,17 +109,45 @@ public: ~ScopedTrace(); private: - TraceEvent* m_event; - TimeStamp m_TimeStamp; + std::shared_ptr m_event; + TimeStamp m_timeStamp; }; +template +ScopedTrace::ScopedTrace( + const std::string& eventName, const std::string& fileName, int lineNumber, const std::string& functionName) +{ + m_event = TracerType::getInstance()->startEvent(eventName); + m_event->functionName = functionName; + m_event->locationName = FilePath(fileName).fileName() + ":" + std::to_string(lineNumber); + + m_timeStamp = utility::durationStart(); +} + +template +ScopedTrace::~ScopedTrace() +{ + m_event->time = utility::duration(m_timeStamp); + TracerType::getInstance()->finishEvent(m_event); +} + #ifdef TRACING_ENABLED - #define TRACE(__name__) \ - ScopedTrace __trace__(std::string(__name__), __FILE__, __LINE__, __FUNCTION__) + #ifdef USE_ACCUMULATED_TRACING + #define TRACE(__name__) \ + ScopedTrace __trace__(std::string(__name__), __FILE__, __LINE__, __FUNCTION__) - #define PRINT_TRACES() \ - Tracer::getInstance()->printTraces() + #define PRINT_TRACES() \ + AccumulatingTracer::getInstance()->printTraces() + #else + #define TRACE(__name__) \ + ScopedTrace __trace__(std::string(__name__), __FILE__, __LINE__, __FUNCTION__) + + #define PRINT_TRACES() \ + Tracer::getInstance()->printTraces() + #endif + + #else #define TRACE(__name__) #define PRINT_TRACES()