refactor profiler
code is now much more clean -removed ugly nested loops -used functions to reduce code clutter and duplcation removed redundant functions cleaned up sort and improved namesv1
Brett
parent
b6cf11505b
commit
811cdff8d1
|
|
@ -12,9 +12,10 @@
|
|||
#include <vector>
|
||||
#include <unordered_map>
|
||||
#include <blt/std/logging.h>
|
||||
#include <fstream>
|
||||
|
||||
/**
|
||||
* Defines several disableable macros (#define BLT_DISABLE_PROFILING). If you do not use these macros profiling will not be disableable
|
||||
* Defines several disableable macros (#define BLT_DISABLE_PROFILING). If you do not use these macros profiling cannot be disabled!
|
||||
*/
|
||||
|
||||
namespace blt::profiling {
|
||||
|
|
@ -42,18 +43,18 @@ namespace blt::profiling {
|
|||
|
||||
capture_interval getInterval(const std::string& profileName, const std::string& intervalName);
|
||||
|
||||
std::vector<capture_interval> getAllIntervals(const std::string& profileName, const std::string& intervalName);
|
||||
std::vector<capture_interval> getAllIntervals(
|
||||
const std::string& profileName, const std::string& intervalName
|
||||
);
|
||||
|
||||
profile getProfile(const std::string& profileName);
|
||||
|
||||
void printProfile(
|
||||
const std::string& profileName, blt::logging::LOG_LEVEL loggingLevel = logging::NONE, bool averageHistory = false,
|
||||
bool ignoreNegatives = true
|
||||
const std::string& profileName, logging::LOG_LEVEL loggingLevel = logging::NONE,
|
||||
bool averageHistory = false, bool ignoreNegatives = true
|
||||
);
|
||||
|
||||
void printOrderedProfile(
|
||||
const std::string& profileName, logging::LOG_LEVEL loggingLevel = logging::NONE, bool averageHistory = false, bool ignoreNegatives = true
|
||||
);
|
||||
void writeProfile(std::ofstream& out, const std::string& profileName);
|
||||
|
||||
void discardProfiles();
|
||||
|
||||
|
|
@ -66,7 +67,8 @@ namespace blt::profiling {
|
|||
std::string m_Profile;
|
||||
std::string m_Interval;
|
||||
public:
|
||||
scoped_interval(std::string profile, std::string interval): m_Profile(std::move(profile)), m_Interval(std::move(interval)) {
|
||||
scoped_interval(std::string profile, std::string interval):
|
||||
m_Profile(std::move(profile)), m_Interval(std::move(interval)) {
|
||||
blt::profiling::startInterval(m_Profile, m_Interval);
|
||||
}
|
||||
|
||||
|
|
@ -82,15 +84,31 @@ namespace blt::profiling {
|
|||
#define BLT_START_INTERVAL(profileName, intervalName)
|
||||
#define BLT_END_INTERVAL(profileName, intervalName)
|
||||
#define BLT_POINT(profileName, pointName)
|
||||
#define BLT_PRINT_PROFILE(profileName, ...)
|
||||
#define BLT_PRINT_ORDERED(profileName, ...)
|
||||
#define BLT_WRITE_ORDERED(profileName, ...)
|
||||
#else
|
||||
/**
|
||||
* Starts an interval to be measured, when ended the row will be added to the specified profile.
|
||||
*/
|
||||
#define BLT_START_INTERVAL(profileName, intervalName) blt::profiling::startInterval(profileName, intervalName)
|
||||
/**
|
||||
* Ends an interval, adds the interval to the profile.
|
||||
*/
|
||||
#define BLT_END_INTERVAL(profileName, intervalName) blt::profiling::endInterval(profileName, intervalName)
|
||||
/**
|
||||
* Measures this exact point in time.
|
||||
*/
|
||||
#define BLT_POINT(profileName, pointName) blt::profiling::point(profileName, pointName)
|
||||
/**
|
||||
* Prints the profile order from least time to most time.
|
||||
* @param profileName the profile to print
|
||||
* @param loggingLevel blt::logging::LOG_LEVEL to log with (default: NONE)
|
||||
* @param averageHistory use the historical collection of interval rows in an average or just the latest? (default: false)
|
||||
* @param ignoreNegatives ignore negative time values (default: true)
|
||||
*/
|
||||
#define BLT_PRINT_PROFILE(profileName, ...) blt::profiling::printProfile(profileName, ##__VA_ARGS__)
|
||||
#define BLT_PRINT_ORDERED(profileName, ...) blt::profiling::printOrderedProfile(profileName, ##__VA_ARGS__)
|
||||
/**
|
||||
* writes the profile to an output stream, ordered from least time to most time, in CSV format.
|
||||
*/
|
||||
#define BLT_WRITE_PROFILE(stream, profileName) blt::profiling::writeProfile(stream, profileName, true)
|
||||
#endif
|
||||
|
||||
#define BLT_INTERVAL_START(profileName, intervalName) BLT_START_INTERVAL(profileName, intervalName)
|
||||
#define BLT_INTERVAL_END(profileName, intervalName) BLT_END_INTERVAL(profileName, intervalName)
|
||||
|
|
@ -18,6 +18,109 @@ namespace blt::profiling {
|
|||
std::mutex profileLock{};
|
||||
std::unordered_map<std::string, profile> profiles;
|
||||
|
||||
struct IntervalComparable {
|
||||
long difference;
|
||||
std::string name;
|
||||
|
||||
IntervalComparable(long difference, std::string name):
|
||||
difference(difference), name(std::move(name)) {}
|
||||
};
|
||||
|
||||
inline void print(const std::vector<std::string>& lines, logging::LOG_LEVEL level) {
|
||||
auto& logger = logging::getLoggerFromLevel(level);
|
||||
for (const auto& line : lines)
|
||||
logger << line;
|
||||
}
|
||||
|
||||
/**
|
||||
* Copy-sorts the unordered vector into the ordered vector, min -> max
|
||||
*/
|
||||
inline void orderIntervals(
|
||||
const std::unordered_map<std::string, capture_interval>& unordered,
|
||||
std::vector<IntervalComparable>& ordered
|
||||
) {
|
||||
// copy
|
||||
for (const auto& i : unordered)
|
||||
ordered.emplace_back(i.second.end - i.second.start, i.first);
|
||||
|
||||
// sort
|
||||
std::sort(
|
||||
ordered.begin(), ordered.end(),
|
||||
[&](const IntervalComparable& c1, const IntervalComparable& c2) -> bool {
|
||||
return c1.difference < c2.difference;
|
||||
}
|
||||
);
|
||||
}
|
||||
|
||||
inline void averageIntervals(
|
||||
const std::unordered_map<std::string, std::vector<capture_interval>>& intervals,
|
||||
std::unordered_map<std::string, capture_interval>& averagedIntervals
|
||||
) {
|
||||
for (const auto& i : intervals) {
|
||||
const auto& name = i.first;
|
||||
const auto& interval_vec = i.second;
|
||||
long total_difference = 0;
|
||||
|
||||
for (const auto& value : interval_vec)
|
||||
total_difference += value.end - value.start;
|
||||
|
||||
total_difference /= (long)interval_vec.size();
|
||||
|
||||
std::string new_name = "(";
|
||||
new_name += std::to_string(interval_vec.size());
|
||||
new_name += ") ";
|
||||
new_name += name;
|
||||
|
||||
// can exploit how the order func works by supplying the difference into end,
|
||||
// which sorts correctly despite not being a true interval.
|
||||
averagedIntervals.insert({new_name, capture_interval{0, total_difference}});
|
||||
}
|
||||
}
|
||||
|
||||
void writeProfile(std::ofstream& out, const std::string& profileName, bool ordered) {
|
||||
|
||||
}
|
||||
|
||||
void printProfile(
|
||||
const std::string& profileName, logging::LOG_LEVEL loggingLevel, bool averageHistory,
|
||||
bool ignoreNegatives
|
||||
) {
|
||||
auto& profile = profiles[profileName];
|
||||
const auto& intervals = profile.intervals;
|
||||
const auto& points = profile.points;
|
||||
|
||||
std::vector<IntervalComparable> ordered_vector;
|
||||
std::unordered_map<std::string, capture_interval> averaged_intervals;
|
||||
|
||||
if (averageHistory)
|
||||
averageIntervals(profile.historicalIntervals, averaged_intervals);
|
||||
|
||||
orderIntervals(averageHistory ? averaged_intervals : intervals, ordered_vector);
|
||||
|
||||
string::TableFormatter formatter{profileName};
|
||||
formatter.addColumn({"Order"});
|
||||
formatter.addColumn({"Interval"});
|
||||
formatter.addColumn({"Time (ns)"});
|
||||
formatter.addColumn({"Time (ms)"});
|
||||
|
||||
int index = 1;
|
||||
for (const auto& interval : ordered_vector) {
|
||||
formatter.addRow(
|
||||
{std::to_string(index++), interval.name, std::to_string(interval.difference),
|
||||
std::to_string((double)interval.difference / 1000000.0)}
|
||||
);
|
||||
}
|
||||
|
||||
std::vector<std::string> updatedLines;
|
||||
const auto& lines = formatter.createTable(true, true);
|
||||
for (const auto& line : lines)
|
||||
updatedLines.emplace_back(line + "\n");
|
||||
|
||||
print(updatedLines, loggingLevel);
|
||||
}
|
||||
|
||||
// --- small helper functions below ---
|
||||
|
||||
void startInterval(const std::string& profileName, const std::string& intervalName) {
|
||||
std::scoped_lock lock(profileLock);
|
||||
capture_interval interval{};
|
||||
|
|
@ -28,7 +131,9 @@ namespace blt::profiling {
|
|||
void endInterval(const std::string& profileName, const std::string& intervalName) {
|
||||
std::scoped_lock lock(profileLock);
|
||||
profiles[profileName].intervals[intervalName].end = system::getCurrentTimeNanoseconds();
|
||||
profiles[profileName].historicalIntervals[intervalName].push_back(profiles[profileName].intervals[intervalName]);
|
||||
profiles[profileName].historicalIntervals[intervalName].push_back(
|
||||
profiles[profileName].intervals[intervalName]
|
||||
);
|
||||
}
|
||||
|
||||
void point(const std::string& profileName, const std::string& pointName) {
|
||||
|
|
@ -47,121 +152,6 @@ namespace blt::profiling {
|
|||
return profiles[profileName];
|
||||
}
|
||||
|
||||
inline void print(const std::vector<std::string>& lines, logging::LOG_LEVEL level) {
|
||||
auto& logger = logging::getLoggerFromLevel(level);
|
||||
for (const auto& line : lines)
|
||||
logger << line;
|
||||
}
|
||||
|
||||
void printProfile(const std::string& profileName, blt::logging::LOG_LEVEL loggingLevel, bool averageHistory, bool ignoreNegatives) {
|
||||
string::TableFormatter formatter{profileName};
|
||||
formatter.addColumn({"Interval"});
|
||||
formatter.addColumn({"Time (ns)"});
|
||||
formatter.addColumn({"Time (ms)"});
|
||||
|
||||
auto& profile = profiles[profileName];
|
||||
const auto& intervals = profile.intervals;
|
||||
const auto& points = profile.points;
|
||||
|
||||
for (const auto& interval : intervals) {
|
||||
if (averageHistory) {
|
||||
const auto& history = profile.historicalIntervals[interval.first];
|
||||
long total_difference = 0;
|
||||
for (const auto& h_interval : history) {
|
||||
const auto difference = h_interval.end - h_interval.start;
|
||||
if (ignoreNegatives && difference < 0)
|
||||
continue;
|
||||
total_difference += difference;
|
||||
}
|
||||
total_difference /= (long) history.size();
|
||||
std::string name = "(";
|
||||
name += std::to_string(history.size());
|
||||
name += ") ";
|
||||
name += interval.first;
|
||||
formatter.addRow({name, std::to_string(total_difference), std::to_string((double) total_difference / 1000000.0)});
|
||||
} else {
|
||||
const auto difference = interval.second.end - interval.second.start;
|
||||
if (ignoreNegatives && difference < 0)
|
||||
continue;
|
||||
formatter.addRow({interval.first, std::to_string(difference), std::to_string((double) difference / 1000000.0)});
|
||||
}
|
||||
}
|
||||
|
||||
std::vector<std::string> updatedLines;
|
||||
const auto& lines = formatter.createTable(true, true);
|
||||
for (const auto& line : lines)
|
||||
updatedLines.emplace_back(line + "\n");
|
||||
|
||||
print(updatedLines, loggingLevel);
|
||||
}
|
||||
|
||||
struct timeOrderContainer {
|
||||
long difference;
|
||||
std::string name;
|
||||
|
||||
timeOrderContainer(long difference, std::string name): difference(difference), name(std::move(name)) {}
|
||||
};
|
||||
|
||||
inline bool timeCompare(const timeOrderContainer& container1, const timeOrderContainer& container2) {
|
||||
return container1.difference < container2.difference;
|
||||
}
|
||||
|
||||
void printOrderedProfile(const std::string& profileName, logging::LOG_LEVEL loggingLevel, bool averageHistory, bool ignoreNegatives) {
|
||||
auto& profile = profiles[profileName];
|
||||
const auto& intervals = profile.intervals;
|
||||
const auto& points = profile.points;
|
||||
|
||||
std::vector<timeOrderContainer> unorderedIntervalVector;
|
||||
|
||||
// TODO: refactor to reduce nesting
|
||||
|
||||
for (const auto& interval : intervals) {
|
||||
if (averageHistory) {
|
||||
const auto& history = profile.historicalIntervals[interval.first];
|
||||
long total_difference = 0;
|
||||
for (const auto& h_interval : history) {
|
||||
const auto difference = h_interval.end - h_interval.start;
|
||||
if (ignoreNegatives && difference < 0)
|
||||
continue;
|
||||
total_difference += difference;
|
||||
}
|
||||
total_difference /= (long) history.size();
|
||||
std::string name = "(";
|
||||
name += std::to_string(history.size());
|
||||
name += ") ";
|
||||
name += interval.first;
|
||||
unorderedIntervalVector.emplace_back(total_difference, name);
|
||||
} else {
|
||||
const auto difference = interval.second.end - interval.second.start;
|
||||
if (ignoreNegatives && difference < 0)
|
||||
continue;
|
||||
unorderedIntervalVector.emplace_back(difference, interval.first);
|
||||
}
|
||||
}
|
||||
|
||||
std::sort(unorderedIntervalVector.begin(), unorderedIntervalVector.end(), timeCompare);
|
||||
|
||||
string::TableFormatter formatter{profileName};
|
||||
formatter.addColumn({"Order"});
|
||||
formatter.addColumn({"Interval"});
|
||||
formatter.addColumn({"Time (ns)"});
|
||||
formatter.addColumn({"Time (ms)"});
|
||||
|
||||
int index = 1;
|
||||
for (const auto& interval : unorderedIntervalVector) {
|
||||
formatter.addRow(
|
||||
{std::to_string(index++), interval.name, std::to_string(interval.difference), std::to_string(interval.difference / 1000000.0)}
|
||||
);
|
||||
}
|
||||
|
||||
std::vector<std::string> updatedLines;
|
||||
const auto& lines = formatter.createTable(true, true);
|
||||
for (const auto& line : lines)
|
||||
updatedLines.emplace_back(line + "\n");
|
||||
|
||||
print(updatedLines, loggingLevel);
|
||||
}
|
||||
|
||||
void discardProfiles() {
|
||||
profiles = {};
|
||||
}
|
||||
|
|
@ -175,7 +165,10 @@ namespace blt::profiling {
|
|||
profiles[profileName].points = {};
|
||||
}
|
||||
|
||||
std::vector<capture_interval> getAllIntervals(const std::string& profileName, const std::string& intervalName) {
|
||||
std::vector<capture_interval> getAllIntervals(
|
||||
const std::string& profileName, const std::string& intervalName
|
||||
) {
|
||||
return profiles[profileName].historicalIntervals[intervalName];
|
||||
}
|
||||
|
||||
}
|
||||
|
|
@ -112,11 +112,11 @@ inline void nbt_read_tests(){
|
|||
BLT_INFO("NBT Block %s Stream Correctly? %s;\n", size_str.c_str(), nbt_block_large_correct ? "True" : "False");
|
||||
}
|
||||
|
||||
BLT_PRINT_ORDERED("nbt read");
|
||||
BLT_PRINT_PROFILE("nbt read");
|
||||
BLT_TRACE("{BLANK_LINE}");
|
||||
BLT_PRINT_ORDERED("nbt read block");
|
||||
BLT_PRINT_PROFILE("nbt read block");
|
||||
BLT_TRACE("{BLANK_LINE}");
|
||||
BLT_PRINT_ORDERED("nbt read individual");
|
||||
BLT_PRINT_PROFILE("nbt read individual");
|
||||
|
||||
delete[] read_buffer;
|
||||
delete[] read_block_buffer;
|
||||
|
|
@ -177,9 +177,9 @@ inline void nbt_write_tests(){
|
|||
BLT_INFO("NBT %s Individual Write Correctly? %s;\n", size_str.c_str(), results ? "True" : "False");
|
||||
}
|
||||
|
||||
BLT_PRINT_ORDERED("nbt write individual");
|
||||
BLT_PRINT_PROFILE("nbt write individual");
|
||||
BLT_TRACE("");
|
||||
BLT_PRINT_ORDERED("nbt write block");
|
||||
BLT_PRINT_PROFILE("nbt write block");
|
||||
}
|
||||
|
||||
inline void nbt_tests(){
|
||||
|
|
|
|||
|
|
@ -40,8 +40,6 @@ static void runProfilingAndTableTests() {
|
|||
|
||||
BLT_PRINT_PROFILE("Help", blt::logging::LOG_LEVEL::TRACE);
|
||||
BLT_TRACE("");
|
||||
BLT_PRINT_ORDERED("Help", blt::logging::LOG_LEVEL::TRACE);
|
||||
BLT_TRACE("");
|
||||
|
||||
blt::string::TableFormatter formatter;
|
||||
formatter.addColumn(blt::string::TableColumn{"Test1"});
|
||||
|
|
|
|||
|
|
@ -8,10 +8,109 @@
|
|||
#define BLT_TESTS_QUEUE_TESTS_H
|
||||
|
||||
#include <queue>
|
||||
#include <blt/std/queue.h>
|
||||
#include <blt/std/logging.h>
|
||||
#include <blt/profiling/profiler.h>
|
||||
#include <array>
|
||||
#include <blt/std/random.h>
|
||||
|
||||
static inline void test_queues(){
|
||||
std::array<int, 100000> values{};
|
||||
|
||||
std::queue<int> base_queue{};
|
||||
blt::flat_queue<int> blt_flat_queue{};
|
||||
blt::flat_stack<int> blt_flat_stack{};
|
||||
blt::node_queue<int> blt_node_queue{};
|
||||
|
||||
static inline void fill_queues(){
|
||||
BLT_START_INTERVAL("Insert", "std::queue");
|
||||
for (const auto& value : values)
|
||||
base_queue.push(value);
|
||||
BLT_END_INTERVAL("Insert", "std::queue");
|
||||
|
||||
BLT_START_INTERVAL("Insert", "blt::flat_queue");
|
||||
for (const auto& value : values)
|
||||
blt_flat_queue.push(value);
|
||||
BLT_END_INTERVAL("Insert", "blt::flat_queue");
|
||||
|
||||
BLT_START_INTERVAL("Insert", "blt::flat_stack");
|
||||
for (const auto& value : values)
|
||||
blt_flat_stack.push(value);
|
||||
BLT_END_INTERVAL("Insert", "blt::flat_stack");
|
||||
|
||||
BLT_START_INTERVAL("Insert", "blt::node_queue");
|
||||
for (const auto& value : values)
|
||||
blt_node_queue.push(value);
|
||||
BLT_END_INTERVAL("Insert", "blt::node_queue");
|
||||
}
|
||||
|
||||
static inline void validate(){
|
||||
bool std_valid = true;
|
||||
bool flat_valid = true;
|
||||
bool node_valid = true;
|
||||
bool stack_valid = true;
|
||||
BLT_START_INTERVAL("Access", "std::queue");
|
||||
for (const auto& value : values) {
|
||||
auto front = base_queue.front();
|
||||
|
||||
if (front != value)
|
||||
std_valid = false;
|
||||
base_queue.pop();
|
||||
}
|
||||
BLT_END_INTERVAL("Access", "std::queue");
|
||||
|
||||
BLT_START_INTERVAL("Access", "blt::flat_queue");
|
||||
for (const auto& value : values) {
|
||||
auto front = blt_flat_queue.front();
|
||||
|
||||
if (front != value)
|
||||
flat_valid = false;
|
||||
blt_flat_queue.pop();
|
||||
}
|
||||
BLT_END_INTERVAL("Access", "blt::flat_queue");
|
||||
|
||||
BLT_START_INTERVAL("Access", "blt::flat_stack");
|
||||
for (const auto& value : values) {
|
||||
auto front = blt_flat_stack.top();
|
||||
|
||||
if (front != value)
|
||||
stack_valid = false;
|
||||
blt_flat_stack.pop();
|
||||
}
|
||||
BLT_END_INTERVAL("Access", "blt::flat_stack");
|
||||
|
||||
BLT_START_INTERVAL("Access", "blt::node_queue");
|
||||
for (const auto& value : values) {
|
||||
auto front = blt_node_queue.front();
|
||||
|
||||
if (front != value)
|
||||
node_valid = false;
|
||||
blt_node_queue.pop();
|
||||
}
|
||||
BLT_END_INTERVAL("Access", "blt::node_queue");
|
||||
|
||||
if (!std_valid)
|
||||
BLT_ERROR("std::queue invalid!");
|
||||
if (!flat_valid)
|
||||
BLT_ERROR("blt::flat_queue invalid!");
|
||||
if (!node_valid)
|
||||
BLT_ERROR("blt::node_queue invalid!");
|
||||
if (!stack_valid)
|
||||
BLT_ERROR("blt::stack invalid!");
|
||||
}
|
||||
|
||||
static inline void test_queues() {
|
||||
blt::random<int, std::uniform_int_distribution> rand{1, std::numeric_limits<int>::max()};
|
||||
|
||||
for (int& value : values){
|
||||
value = rand.get();
|
||||
}
|
||||
|
||||
fill_queues();
|
||||
validate();
|
||||
|
||||
|
||||
BLT_PRINT_PROFILE("Insert", blt::logging::LOG_LEVEL::INFO, true);
|
||||
BLT_PRINT_PROFILE("Access", blt::logging::LOG_LEVEL::INFO, true);
|
||||
}
|
||||
|
||||
#endif //BLT_TESTS_QUEUE_TESTS_H
|
||||
|
|
|
|||
Loading…
Reference in New Issue