2022-12-23 13:50:27 -05:00
|
|
|
/*
|
|
|
|
* Created by Brett on 23/12/22.
|
|
|
|
* Licensed under GNU General Public License V3.0
|
|
|
|
* See LICENSE file for license detail
|
|
|
|
*/
|
2022-12-26 00:31:00 -05:00
|
|
|
#include <blt/profiling/profiler.h>
|
2023-01-26 00:59:36 -05:00
|
|
|
#include <mutex>
|
|
|
|
#include <vector>
|
|
|
|
#include <blt/std/time.h>
|
|
|
|
#include <blt/std/logging.h>
|
|
|
|
#include <iostream>
|
2023-01-26 12:21:19 -05:00
|
|
|
#include <algorithm>
|
2023-01-27 00:49:44 -05:00
|
|
|
#include <blt/std/format.h>
|
2022-12-26 00:31:00 -05:00
|
|
|
|
2023-01-26 00:59:36 -05:00
|
|
|
namespace blt::profiling {
|
|
|
|
|
|
|
|
// TODO: a better way
|
|
|
|
std::mutex profileLock{};
|
2023-02-14 22:22:48 -05:00
|
|
|
std::unordered_map<std::string, profile> profiles;
|
2023-01-26 00:59:36 -05:00
|
|
|
|
2023-03-04 11:42:24 -05:00
|
|
|
struct IntervalComparable {
|
|
|
|
long difference;
|
|
|
|
std::string name;
|
2023-03-07 18:02:19 -05:00
|
|
|
std::uint64_t total;
|
2023-03-04 11:42:24 -05:00
|
|
|
|
|
|
|
IntervalComparable(long difference, std::string name):
|
2023-03-07 18:02:19 -05:00
|
|
|
difference(difference), name(std::move(name)), total(difference) {}
|
|
|
|
|
|
|
|
IntervalComparable(long difference, std::string name, std::uint64_t total):
|
|
|
|
difference(difference), name(std::move(name)), total(total) {}
|
2023-03-04 11:42:24 -05:00
|
|
|
};
|
2023-01-26 00:59:36 -05:00
|
|
|
|
2023-07-20 21:44:52 -04:00
|
|
|
inline void println(const std::vector<std::string>&& lines, logging::LogLevel level) {
|
2023-02-08 17:22:27 -05:00
|
|
|
auto& logger = logging::getLoggerFromLevel(level);
|
|
|
|
for (const auto& line : lines)
|
2023-03-04 11:52:54 -05:00
|
|
|
logger << line << "\n";
|
2023-01-26 12:21:19 -05:00
|
|
|
}
|
|
|
|
|
2023-03-04 11:42:24 -05:00
|
|
|
/**
|
|
|
|
* Copy-sorts the unordered vector into the ordered vector, min -> max
|
|
|
|
*/
|
|
|
|
inline void orderIntervals(
|
|
|
|
const std::unordered_map<std::string, capture_interval>& unordered,
|
2023-03-07 18:02:19 -05:00
|
|
|
std::vector<IntervalComparable>& ordered, bool history
|
2023-03-04 11:42:24 -05:00
|
|
|
) {
|
|
|
|
// copy
|
2023-03-07 18:02:19 -05:00
|
|
|
for (const auto& i : unordered) {
|
|
|
|
if (history)
|
|
|
|
ordered.emplace_back(i.second.end, i.first, i.second.start);
|
|
|
|
else
|
|
|
|
ordered.emplace_back(i.second.end - i.second.start, i.first);
|
|
|
|
}
|
2023-01-27 00:49:44 -05:00
|
|
|
|
2023-03-04 11:42:24 -05:00
|
|
|
// sort
|
|
|
|
std::sort(
|
|
|
|
ordered.begin(), ordered.end(),
|
|
|
|
[&](const IntervalComparable& c1, const IntervalComparable& c2) -> bool {
|
|
|
|
return c1.difference < c2.difference;
|
2023-02-14 22:28:58 -05:00
|
|
|
}
|
2023-03-04 11:42:24 -05:00
|
|
|
);
|
|
|
|
}
|
|
|
|
|
|
|
|
inline void averageIntervals(
|
2023-03-06 21:29:04 -05:00
|
|
|
const std::unordered_map<std::string, capture_history>& intervals,
|
2023-03-04 11:42:24 -05:00
|
|
|
std::unordered_map<std::string, capture_interval>& averagedIntervals
|
|
|
|
) {
|
2023-03-04 11:46:37 -05:00
|
|
|
// average all intervals
|
2023-03-04 11:42:24 -05:00
|
|
|
for (const auto& i : intervals) {
|
|
|
|
const auto& name = i.first;
|
|
|
|
const auto& interval_vec = i.second;
|
|
|
|
|
2023-03-04 11:46:37 -05:00
|
|
|
// we can exploit how the order func works by supplying the difference into end,
|
2023-03-04 11:42:24 -05:00
|
|
|
// which sorts correctly despite not being a true interval.
|
2023-03-07 18:02:19 -05:00
|
|
|
averagedIntervals.insert(
|
|
|
|
{name, capture_interval{(long)interval_vec.total, (long) (interval_vec.total / interval_vec.count)}}
|
|
|
|
);
|
2023-01-27 00:49:44 -05:00
|
|
|
}
|
|
|
|
}
|
|
|
|
|
2023-03-04 11:52:54 -05:00
|
|
|
void writeProfile(std::ofstream& out, const std::string& profileName, bool averageHistory) {
|
|
|
|
auto& profile = profiles[profileName];
|
|
|
|
const auto& intervals = profile.intervals;
|
2023-03-06 21:29:04 -05:00
|
|
|
const auto& intervals_total = profile.intervals_total;
|
2023-03-04 13:07:35 -05:00
|
|
|
|
|
|
|
std::vector<IntervalComparable> order_rows;
|
2023-03-04 11:52:54 -05:00
|
|
|
std::unordered_map<std::string, capture_interval> averaged_intervals;
|
2023-03-04 13:07:35 -05:00
|
|
|
|
2023-03-04 11:52:54 -05:00
|
|
|
if (averageHistory)
|
2023-03-06 21:29:04 -05:00
|
|
|
averageIntervals(intervals_total, averaged_intervals);
|
2023-03-04 13:07:35 -05:00
|
|
|
|
2023-03-07 18:02:19 -05:00
|
|
|
orderIntervals(averageHistory ? averaged_intervals : intervals, order_rows, averageHistory);
|
2023-03-04 13:07:35 -05:00
|
|
|
|
2023-03-07 18:02:19 -05:00
|
|
|
out << "Order,Count,Interval,Time (ms),Time (ns),Total (ms)\n";
|
2023-03-04 13:07:35 -05:00
|
|
|
int index = 1;
|
|
|
|
for (const auto& row : order_rows) {
|
|
|
|
out << std::to_string(index++) << ","
|
2023-03-06 21:29:04 -05:00
|
|
|
<< std::to_string(averageHistory ? intervals_total.at(row.name).count : 1) << ","
|
2023-03-04 13:07:35 -05:00
|
|
|
<< row.name << ","
|
|
|
|
<< std::to_string((double) row.difference / 1000000.0) << ","
|
2023-03-07 18:02:19 -05:00
|
|
|
<< std::to_string(row.difference) << ","
|
2023-03-07 18:03:05 -05:00
|
|
|
<< std::to_string((double) row.total / 1000000.0) << "\n";
|
2023-03-04 13:07:35 -05:00
|
|
|
}
|
|
|
|
out.flush();
|
2023-01-26 12:21:19 -05:00
|
|
|
}
|
|
|
|
|
2023-03-04 11:42:24 -05:00
|
|
|
void printProfile(
|
2023-07-20 21:44:52 -04:00
|
|
|
const std::string& profileName, logging::LogLevel loggingLevel, bool averageHistory
|
2023-03-04 11:42:24 -05:00
|
|
|
) {
|
2023-02-14 22:28:58 -05:00
|
|
|
auto& profile = profiles[profileName];
|
2023-01-27 09:58:51 -05:00
|
|
|
const auto& intervals = profile.intervals;
|
2023-03-06 21:29:04 -05:00
|
|
|
const auto& intervals_total = profile.intervals_total;
|
2023-02-15 09:50:20 -05:00
|
|
|
|
2023-03-04 13:07:35 -05:00
|
|
|
std::vector<IntervalComparable> ordered_rows;
|
2023-03-04 11:42:24 -05:00
|
|
|
std::unordered_map<std::string, capture_interval> averaged_intervals;
|
2023-02-14 22:32:23 -05:00
|
|
|
|
2023-03-04 11:42:24 -05:00
|
|
|
if (averageHistory)
|
2023-03-06 21:29:04 -05:00
|
|
|
averageIntervals(intervals_total, averaged_intervals);
|
2023-02-15 09:50:20 -05:00
|
|
|
|
2023-03-07 18:02:19 -05:00
|
|
|
orderIntervals(averageHistory ? averaged_intervals : intervals, ordered_rows, averageHistory);
|
2023-02-15 09:50:20 -05:00
|
|
|
|
|
|
|
string::TableFormatter formatter{profileName};
|
2023-01-27 09:58:51 -05:00
|
|
|
formatter.addColumn({"Order"});
|
2023-03-04 13:07:35 -05:00
|
|
|
formatter.addColumn({"Count"});
|
2023-01-27 09:58:51 -05:00
|
|
|
formatter.addColumn({"Interval"});
|
|
|
|
formatter.addColumn({"Time (ms)"});
|
2023-03-04 13:07:35 -05:00
|
|
|
formatter.addColumn({"Time (ns)"});
|
2023-03-07 18:02:19 -05:00
|
|
|
formatter.addColumn({"Total (ms)"});
|
2023-02-15 09:50:20 -05:00
|
|
|
|
2023-01-27 09:58:51 -05:00
|
|
|
int index = 1;
|
2023-03-04 13:07:35 -05:00
|
|
|
for (const auto& row : ordered_rows) {
|
2023-02-15 09:50:20 -05:00
|
|
|
formatter.addRow(
|
2023-03-04 13:07:35 -05:00
|
|
|
{std::to_string(index++),
|
2023-03-06 21:29:04 -05:00
|
|
|
std::to_string(averageHistory ? intervals_total.at(row.name).count : 1),
|
2023-03-04 13:07:35 -05:00
|
|
|
row.name,
|
|
|
|
std::to_string((double) row.difference / 1000000.0),
|
2023-03-07 18:02:19 -05:00
|
|
|
std::to_string(row.difference),
|
2023-03-07 18:03:05 -05:00
|
|
|
std::to_string((double) row.total / 1000000.0)}
|
2023-02-15 09:50:20 -05:00
|
|
|
);
|
2023-01-27 09:58:51 -05:00
|
|
|
}
|
2023-03-04 13:07:35 -05:00
|
|
|
|
2023-03-04 11:52:54 -05:00
|
|
|
println(formatter.createTable(true, true), loggingLevel);
|
2023-01-27 09:58:51 -05:00
|
|
|
}
|
2023-03-04 11:42:24 -05:00
|
|
|
|
|
|
|
// --- small helper functions below ---
|
|
|
|
|
|
|
|
void startInterval(const std::string& profileName, const std::string& intervalName) {
|
|
|
|
std::scoped_lock lock(profileLock);
|
|
|
|
capture_interval interval{};
|
|
|
|
interval.start = system::getCurrentTimeNanoseconds();
|
|
|
|
profiles[profileName].intervals[intervalName] = interval;
|
|
|
|
}
|
|
|
|
|
|
|
|
void endInterval(const std::string& profileName, const std::string& intervalName) {
|
|
|
|
std::scoped_lock lock(profileLock);
|
2023-03-06 21:29:04 -05:00
|
|
|
auto& prof = profiles[profileName];
|
|
|
|
auto& ref = prof.intervals[intervalName];
|
2023-03-07 18:02:19 -05:00
|
|
|
|
2023-03-06 21:29:04 -05:00
|
|
|
ref.end = system::getCurrentTimeNanoseconds();
|
|
|
|
|
|
|
|
auto difference = ref.end - ref.start;
|
|
|
|
auto& href = prof.intervals_total[intervalName];
|
2023-03-07 18:02:19 -05:00
|
|
|
|
2023-03-06 21:29:04 -05:00
|
|
|
href.total += difference;
|
|
|
|
href.count++;
|
2023-03-04 11:42:24 -05:00
|
|
|
}
|
|
|
|
|
|
|
|
void point(const std::string& profileName, const std::string& pointName) {
|
|
|
|
std::scoped_lock lock(profileLock);
|
|
|
|
capture_point point{};
|
|
|
|
point.point = system::getCurrentTimeNanoseconds();
|
|
|
|
point.name = pointName;
|
|
|
|
profiles[profileName].points.push(point);
|
|
|
|
}
|
|
|
|
|
|
|
|
capture_interval getInterval(const std::string& profileName, const std::string& intervalName) {
|
|
|
|
return profiles[profileName].intervals[intervalName];
|
|
|
|
}
|
|
|
|
|
|
|
|
profile getProfile(const std::string& profileName) {
|
|
|
|
return profiles[profileName];
|
|
|
|
}
|
2023-01-27 09:58:51 -05:00
|
|
|
|
2023-01-26 00:59:36 -05:00
|
|
|
void discardProfiles() {
|
|
|
|
profiles = {};
|
|
|
|
}
|
|
|
|
|
|
|
|
void discardIntervals(const std::string& profileName) {
|
|
|
|
profiles[profileName].intervals = {};
|
2023-03-06 21:29:04 -05:00
|
|
|
profiles[profileName].intervals_total = {};
|
2023-01-26 00:59:36 -05:00
|
|
|
}
|
|
|
|
|
|
|
|
void discardPoints(const std::string& profileName) {
|
|
|
|
profiles[profileName].points = {};
|
|
|
|
}
|
2023-02-14 22:06:30 -05:00
|
|
|
|
2022-12-26 00:31:00 -05:00
|
|
|
}
|