diff --git a/libs/util/source/profiler.cpp b/libs/util/source/profiler.cpp index 8721186d..9bc4ebde 100644 --- a/libs/util/source/profiler.cpp +++ b/libs/util/source/profiler.cpp @@ -33,6 +33,42 @@ namespace psemek::util static thread_local profiler_tree * current = nullptr; + struct pretty_impl + { + double value; + }; + + pretty_impl pretty(double value) + { + return {value}; + } + + std::ostream & operator << (std::ostream & os, pretty_impl p) + { + char const * suf[] = + { + "ns", + "us", + "ms", + "s", + }; + + double s = 1e-9; + + for (std::size_t i = 0; i < 4; ++i) + { + if (p.value < (s * 1000.0) || i == 3) + { + os << (p.value / s) << ' ' << suf[i]; + return os; + } + + s *= 1000.0; + } + + return os; + } + void dump_impl(profiler_tree const & node, std::size_t depth) { std::size_t max_name_length = 0; @@ -42,9 +78,13 @@ namespace psemek::util for (auto const & c : node.children) { + auto const & stat = c.second.execution_time; log::info() << std::string(depth * 2, ' ') << std::setw(max_name_length + 3) << std::left << std::setfill(' ') << c.first - << util::pretty(std::chrono::duration{c.second.execution_time.mean()}, std::chrono::microseconds{}) - << " (" << c.second.execution_time.count() << " calls)"; + << " avg " << pretty(stat.mean()) + << " 25% " << pretty(stat.percentile(0.25)) + << " 50% " << pretty(stat.percentile(0.50)) + << " 75% " << pretty(stat.percentile(0.75)) + << " (" << stat.count() << " calls)"; dump_impl(c.second, depth + 1); } }