152 lines
7.5 KiB
C++
152 lines
7.5 KiB
C++
#pragma once
|
|
// Always-on frame recorder for slowdowns: the time of every frame split into named CPU sections (cheap clock marks in the frame loop), the GPU
|
|
// passes (timestamps), and counts of what the world holds; the last 1200 frames are kept. F10 (or NG_PERF_AUTO=ms: any frame slower than that,
|
|
// at most every 10 s) writes perf/perf_<time>.txt (summary, averages, the slowest frames in full) and perf_<time>.csv (every frame).
|
|
#include <algorithm>
|
|
#include <chrono>
|
|
#include <cstdio>
|
|
#include <ctime>
|
|
#include <filesystem>
|
|
#include <string>
|
|
#include <vector>
|
|
|
|
namespace ng {
|
|
|
|
class PerfRecorder {
|
|
public:
|
|
static constexpr int kMaxSections = 32, kGpu = 20, kCounts = 12;
|
|
struct Frame {
|
|
int frame = 0;
|
|
float total = 0, wait = 0, gpu = 0; // whole frame (wall time from one frame to the next), waiting for the GPU / the swap chain, the GPU's own time
|
|
float sect[kMaxSections] = {};
|
|
float gpuPass[kGpu] = {};
|
|
int count[kCounts] = {};
|
|
};
|
|
|
|
PerfRecorder() : ring_(1200) {}
|
|
|
|
// a section name per id (registered once, in order of first use)
|
|
int section(const char* name) {
|
|
for (int i = 0; i < (int)names_.size(); ++i) if (names_[i] == name) return i;
|
|
if ((int)names_.size() >= kMaxSections) return kMaxSections - 1;
|
|
names_.push_back(name);
|
|
return (int)names_.size() - 1;
|
|
}
|
|
void set_count_names(std::vector<std::string> n) { countNames_ = std::move(n); }
|
|
void set_gpu_names(std::vector<std::string> n) { gpuNames_ = std::move(n); }
|
|
|
|
// the start of a frame: the previous one is closed
|
|
void begin(int frame) {
|
|
const auto now = clk::now();
|
|
if (open_) {
|
|
cur_.total = ms(frameT_, now);
|
|
ring_[head_ % ring_.size()] = cur_;
|
|
++head_;
|
|
if (autoMs_ > 0 && cur_.total > autoMs_ && std::chrono::duration<double>(now - lastAuto_).count() > 10.0) { pendingAuto_ = true; lastAuto_ = now; }
|
|
}
|
|
cur_ = Frame();
|
|
cur_.frame = frame;
|
|
frameT_ = now; markT_ = now; curSect_ = -1; open_ = true;
|
|
}
|
|
// from here on the time goes to section `id` (until the next mark)
|
|
void mark(int id) {
|
|
const auto now = clk::now();
|
|
if (curSect_ >= 0 && curSect_ < kMaxSections) cur_.sect[curSect_] += ms(markT_, now);
|
|
curSect_ = id; markT_ = now;
|
|
}
|
|
void wait_ms(float w) { cur_.wait += w; }
|
|
void gpu_ms(float g) { cur_.gpu = g; }
|
|
void gpu_pass(int k, float v) { if (k >= 0 && k < kGpu) cur_.gpuPass[k] = v; }
|
|
void count(int k, int v) { if (k >= 0 && k < kCounts) cur_.count[k] = v; }
|
|
void set_auto(double msThreshold) { autoMs_ = msThreshold; }
|
|
bool take_auto() { const bool a = pendingAuto_; pendingAuto_ = false; return a; }
|
|
|
|
// the report: returns the path of the text file
|
|
std::string dump(const std::string& dir, const std::string& context, const char* why) {
|
|
namespace fs = std::filesystem;
|
|
std::error_code ec;
|
|
fs::create_directories(dir, ec);
|
|
std::time_t t = std::time(nullptr);
|
|
std::tm tm{};
|
|
localtime_s(&tm, &t);
|
|
char stamp[32];
|
|
std::strftime(stamp, sizeof stamp, "%Y%m%d_%H%M%S", &tm);
|
|
const std::string base = (fs::path(dir) / ("perf_" + std::string(stamp))).string();
|
|
std::vector<Frame> fr;
|
|
const size_t n = std::min(head_, ring_.size());
|
|
for (size_t k = head_ - n; k < head_; ++k) fr.push_back(ring_[k % ring_.size()]);
|
|
if (FILE* f = std::fopen((base + ".csv").c_str(), "wb")) {
|
|
std::fprintf(f, "frame,total_ms,wait_ms,gpu_ms");
|
|
for (const auto& s : names_) std::fprintf(f, ",\"%s\"", s.c_str()); // (quoted: some names hold commas)
|
|
for (const auto& s : gpuNames_) std::fprintf(f, ",\"gpu %s\"", s.c_str());
|
|
for (const auto& s : countNames_) std::fprintf(f, ",\"%s\"", s.c_str());
|
|
std::fprintf(f, "\r\n");
|
|
for (const Frame& x : fr) {
|
|
std::fprintf(f, "%d,%.3f,%.3f,%.3f", x.frame, x.total, x.wait, x.gpu);
|
|
for (size_t s = 0; s < names_.size(); ++s) std::fprintf(f, ",%.3f", x.sect[s]);
|
|
for (size_t s = 0; s < gpuNames_.size(); ++s) std::fprintf(f, ",%.3f", x.gpuPass[s]);
|
|
for (size_t s = 0; s < countNames_.size(); ++s) std::fprintf(f, ",%d", x.count[s]);
|
|
std::fprintf(f, "\r\n");
|
|
}
|
|
std::fclose(f);
|
|
}
|
|
FILE* f = std::fopen((base + ".txt").c_str(), "wb");
|
|
if (!f) return "";
|
|
auto line = [&](const Frame& x) {
|
|
std::fprintf(f, "frame %6d %6.1f ms (waiting for the GPU %.1f, GPU %.1f)\r\n", x.frame, x.total, x.wait, x.gpu);
|
|
std::vector<std::pair<float, std::string>> v;
|
|
for (size_t s = 0; s < names_.size(); ++s) if (x.sect[s] >= 0.05f) v.push_back({x.sect[s], names_[s]});
|
|
std::sort(v.rbegin(), v.rend());
|
|
std::fprintf(f, " CPU:");
|
|
for (auto& [m, s] : v) std::fprintf(f, " %s %.2f", s.c_str(), m);
|
|
std::fprintf(f, "\r\n GPU:");
|
|
for (size_t s = 0; s < gpuNames_.size(); ++s) if (x.gpuPass[s] >= 0.05f) std::fprintf(f, " %s %.2f", gpuNames_[s].c_str(), x.gpuPass[s]);
|
|
std::fprintf(f, "\r\n counts:");
|
|
for (size_t s = 0; s < countNames_.size(); ++s) std::fprintf(f, " %s %d", countNames_[s].c_str(), x.count[s]);
|
|
std::fprintf(f, "\r\n");
|
|
};
|
|
std::fprintf(f, "noita_gpu performance report (%s), %s\r\n%s\r\n\r\n", why, stamp, context.c_str());
|
|
if (!fr.empty()) {
|
|
double avg = 0, worst = 0;
|
|
Frame mean;
|
|
for (const Frame& x : fr) {
|
|
avg += x.total; worst = std::max(worst, (double)x.total);
|
|
mean.wait += x.wait; mean.gpu += x.gpu;
|
|
for (int s = 0; s < kMaxSections; ++s) mean.sect[s] += x.sect[s];
|
|
for (int s = 0; s < kGpu; ++s) mean.gpuPass[s] += x.gpuPass[s];
|
|
}
|
|
const float k = 1.0f / (float)fr.size();
|
|
mean.total = (float)(avg * k); mean.wait *= k; mean.gpu *= k;
|
|
for (float& s : mean.sect) s *= k;
|
|
for (float& s : mean.gpuPass) s *= k;
|
|
mean.frame = -1;
|
|
for (int s = 0; s < kCounts; ++s) mean.count[s] = fr.back().count[s];
|
|
std::fprintf(f, "%zu frames (%.1f s of frames): average %.1f ms, worst %.1f ms\r\n\r\nAVERAGE (counts: the last frame)\r\n", fr.size(), avg / 1000.0, avg * k, worst);
|
|
line(mean);
|
|
std::vector<const Frame*> sorted;
|
|
for (const Frame& x : fr) sorted.push_back(&x);
|
|
std::sort(sorted.begin(), sorted.end(), [](const Frame* a, const Frame* b) { return a->total > b->total; });
|
|
std::fprintf(f, "\r\nTHE 25 SLOWEST FRAMES\r\n");
|
|
for (size_t q = 0; q < std::min<size_t>(25, sorted.size()); ++q) line(*sorted[q]);
|
|
std::fprintf(f, "\r\nTHE LAST 60 FRAMES\r\n");
|
|
for (size_t q = fr.size() > 60 ? fr.size() - 60 : 0; q < fr.size(); ++q) line(fr[q]);
|
|
}
|
|
std::fclose(f);
|
|
return base + ".txt";
|
|
}
|
|
|
|
private:
|
|
using clk = std::chrono::steady_clock;
|
|
static float ms(clk::time_point a, clk::time_point b) { return std::chrono::duration<float, std::milli>(b - a).count(); }
|
|
std::vector<Frame> ring_;
|
|
size_t head_ = 0;
|
|
Frame cur_;
|
|
bool open_ = false, pendingAuto_ = false;
|
|
int curSect_ = -1;
|
|
double autoMs_ = 0;
|
|
clk::time_point frameT_ = clk::now(), markT_ = clk::now(), lastAuto_ = clk::now() - std::chrono::hours(1);
|
|
std::vector<std::string> names_, gpuNames_, countNames_;
|
|
};
|
|
|
|
} // namespace ng
|