Merge pull request #247 from larskraemer/logging_class

Move logging functionality into a class
pull/153/head
jackun 4 years ago committed by GitHub
commit 85a1eef453
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23

@ -5,16 +5,10 @@
string os, cpu, gpu, ram, kernel, driver; string os, cpu, gpu, ram, kernel, driver;
bool sysInfoFetched = false; bool sysInfoFetched = false;
int gpuLoadLog = 0, cpuLoadLog = 0;
Clock::duration elapsedLog;
std::vector<std::string> logFiles;
double fps; double fps;
std::vector<logData> logArray;
ofstream out;
bool loggingOn;
Clock::time_point log_start, log_end;
logData currentLogData = {}; logData currentLogData = {};
bool logUpdate = false;
std::unique_ptr<Logger> logger;
string exec(string command) { string exec(string command) {
char buffer[128]; char buffer[128];
@ -38,16 +32,16 @@ string exec(string command) {
return result; return result;
} }
void upload_file(){ void upload_file(std::string logFile){
std::string command = "curl --include --request POST https://flightlessmango.com/logs -F 'log[game_id]=26506' -F 'log[user_id]=176' -F 'attachment=true' -A 'mangohud' "; std::string command = "curl --include --request POST https://flightlessmango.com/logs -F 'log[game_id]=26506' -F 'log[user_id]=176' -F 'attachment=true' -A 'mangohud' ";
command += " -F 'log[uploads][]=@" + logFiles.back() + "'"; command += " -F 'log[uploads][]=@" + logFile + "'";
command += " | grep Location | cut -c11-"; command += " | grep Location | cut -c11-";
std::string url = exec(command); std::string url = exec(command);
exec("xdg-open " + url); exec("xdg-open " + url);
} }
void upload_files(){ void upload_files(const std::vector<std::string>& logFiles){
std::string command = "curl --include --request POST https://flightlessmango.com/logs -F 'log[game_id]=26506' -F 'log[user_id]=176' -F 'attachment=true' -A 'mangohud' "; std::string command = "curl --include --request POST https://flightlessmango.com/logs -F 'log[game_id]=26506' -F 'log[user_id]=176' -F 'attachment=true' -A 'mangohud' ";
for (auto& file : logFiles) for (auto& file : logFiles)
command += " -F 'log[uploads][]=@" + file + "'"; command += " -F 'log[uploads][]=@" + file + "'";
@ -58,8 +52,11 @@ void upload_files(){
} }
void writeFile(string filename){ void writeFile(string filename){
logFiles.push_back(filename); auto& logArray = logger->get_log_data();
out.open(filename, ios::out | ios::app); #ifndef NDEBUG
std::cerr << "Writing log file [" << filename << "], " << logArray.size() << " entries\n";
#endif
std::ofstream out(filename, ios::out | ios::app);
out << "os," << "cpu," << "gpu," << "ram," << "kernel," << "driver" << endl; out << "os," << "cpu," << "gpu," << "ram," << "kernel," << "driver" << endl;
out << os << "," << cpu << "," << gpu << "," << ram << "," << kernel << "," << driver << endl; out << os << "," << cpu << "," << gpu << "," << ram << "," << kernel << "," << driver << endl;
out << "fps," << "cpu_load," << "gpu_load," << "cpu_temp," << "gpu_temp," << "gpu_core_clock," << "gpu_mem_clock," << "gpu_vram_used," << "ram_used," << "elapsed" << endl; out << "fps," << "cpu_load," << "gpu_load," << "cpu_temp," << "gpu_temp," << "gpu_core_clock," << "gpu_mem_clock," << "gpu_vram_used," << "ram_used," << "elapsed" << endl;
@ -76,9 +73,7 @@ void writeFile(string filename){
out << logArray[i].ram_used << ","; out << logArray[i].ram_used << ",";
out << std::chrono::duration_cast<std::chrono::microseconds>(logArray[i].previous).count() << "\n"; out << std::chrono::duration_cast<std::chrono::microseconds>(logArray[i].previous).count() << "\n";
} }
logger->clear_log_data();
out.close();
logArray.clear();
} }
string get_log_suffix(){ string get_log_suffix(){
@ -92,23 +87,73 @@ string get_log_suffix(){
void logging(void *params_void){ void logging(void *params_void){
overlay_params *params = reinterpret_cast<overlay_params *>(params_void); overlay_params *params = reinterpret_cast<overlay_params *>(params_void);
while (loggingOn){ logger->wait_until_data_valid();
auto now = Clock::now(); while (logger->is_active()){
elapsedLog = now - log_start; logger->try_log();
this_thread::sleep_for(chrono::milliseconds(params->log_interval));
currentLogData.fps = fps;
currentLogData.previous = elapsedLog;
if (logUpdate)
logArray.push_back(currentLogData);
if (params->log_duration && (elapsedLog >= std::chrono::seconds(params->log_duration)))
loggingOn = false;
else
if (logUpdate)
this_thread::sleep_for(std::chrono::milliseconds(params->log_interval));
else
this_thread::sleep_for(chrono::milliseconds(0));
} }
}
writeFile(params->output_file + get_log_suffix()); Logger::Logger(overlay_params* in_params)
: m_logging_on(false),
m_values_valid(false),
m_params(in_params)
{
#ifndef NDEBUG
std::cerr << "Logger constructed!\n";
#endif
}
void Logger::start_logging() {
if(m_logging_on) return;
m_values_valid = false;
m_logging_on = true;
m_log_start = Clock::now();
if((not m_params->output_file.empty()) and (m_params->log_interval != 0)){
std::thread(logging, m_params).detach();
}
}
void Logger::stop_logging() {
if(not m_logging_on) return;
m_logging_on = false;
m_log_end = Clock::now();
std::thread(calculate_benchmark_data).detach();
if(not m_params->output_file.empty()) {
m_log_files.emplace_back(m_params->output_file + get_log_suffix());
std::thread(writeFile, m_log_files.back()).detach();
}
} }
void Logger::try_log() {
if(not is_active()) return;
if(not m_values_valid) return;
auto now = Clock::now();
auto elapsedLog = now - m_log_start;
currentLogData.previous = elapsedLog;
currentLogData.fps = fps;
m_log_array.push_back(currentLogData);
if(m_params->log_duration and (elapsedLog >= std::chrono::seconds(m_params->log_duration))){
stop_logging();
}
}
void Logger::wait_until_data_valid() {
std::unique_lock<std::mutex> lck(m_values_valid_mtx);
while(! m_values_valid) m_values_valid_cv.wait(lck);
}
void Logger::notify_data_valid() {
std::unique_lock<std::mutex> lck(m_values_valid_mtx);
m_values_valid = true;
m_values_valid_cv.notify_all();
}
void Logger::upload_last_log() {
if(m_log_files.empty()) return;
std::thread(upload_file, m_log_files.back()).detach();
}

@ -3,9 +3,12 @@
#include <fstream> #include <fstream>
#include <chrono> #include <chrono>
#include <thread> #include <thread>
#include <condition_variable>
#include "timing.hpp" #include "timing.hpp"
#include "overlay_params.h"
using namespace std; using namespace std;
struct logData{ struct logData{
double fps; double fps;
@ -21,20 +24,46 @@ struct logData{
Clock::duration previous; Clock::duration previous;
}; };
class Logger {
public:
Logger(overlay_params* in_params);
void start_logging();
void stop_logging();
void try_log();
bool is_active() const { return m_logging_on; }
void wait_until_data_valid();
void notify_data_valid();
auto last_log_end() const noexcept { return m_log_end; }
auto last_log_begin() const noexcept { return m_log_start; }
const std::vector<logData>& get_log_data() const noexcept { return m_log_array; }
void clear_log_data() noexcept { m_log_array.clear(); }
void upload_last_log();
private:
std::vector<logData> m_log_array;
std::vector<std::string> m_log_files;
Clock::time_point m_log_start;
Clock::time_point m_log_end;
bool m_logging_on;
std::mutex m_values_valid_mtx;
std::condition_variable m_values_valid_cv;
bool m_values_valid;
overlay_params* m_params;
};
extern std::unique_ptr<Logger> logger;
extern string os, cpu, gpu, ram, kernel, driver; extern string os, cpu, gpu, ram, kernel, driver;
extern bool sysInfoFetched; extern bool sysInfoFetched;
extern Clock::duration elapsedLog;
extern std::vector<std::string> logFiles;
extern double fps; extern double fps;
extern std::vector<logData> logArray;
extern bool loggingOn;
extern Clock::time_point log_start, log_end;
extern logData currentLogData; extern logData currentLogData;
extern bool logUpdate;
void logging(void *params_void);
void writeFile(string filename);
string exec(string command); string exec(string command);
string get_log_suffix(void);
void upload_file(void);
void upload_files(void);

@ -735,17 +735,17 @@ void init_system_info(){
} }
void update_hw_info(struct swapchain_stats& sw_stats, struct overlay_params& params, uint32_t vendorID){ void update_hw_info(struct swapchain_stats& sw_stats, struct overlay_params& params, uint32_t vendorID){
if (params.enabled[OVERLAY_PARAM_ENABLED_cpu_stats] || loggingOn) { if (params.enabled[OVERLAY_PARAM_ENABLED_cpu_stats] || logger->is_active()) {
cpuStats.UpdateCPUData(); cpuStats.UpdateCPUData();
sw_stats.total_cpu = cpuStats.GetCPUDataTotal().percent; sw_stats.total_cpu = cpuStats.GetCPUDataTotal().percent;
if (params.enabled[OVERLAY_PARAM_ENABLED_core_load]) if (params.enabled[OVERLAY_PARAM_ENABLED_core_load])
cpuStats.UpdateCoreMhz(); cpuStats.UpdateCoreMhz();
if (params.enabled[OVERLAY_PARAM_ENABLED_cpu_temp] || loggingOn) if (params.enabled[OVERLAY_PARAM_ENABLED_cpu_temp] || logger->is_active())
cpuStats.UpdateCpuTemp(); cpuStats.UpdateCpuTemp();
} }
if (params.enabled[OVERLAY_PARAM_ENABLED_gpu_stats] || loggingOn) { if (params.enabled[OVERLAY_PARAM_ENABLED_gpu_stats] || logger->is_active()) {
if (vendorID == 0x1002) if (vendorID == 0x1002)
getAmdGpuInfo(); getAmdGpuInfo();
@ -754,7 +754,7 @@ void update_hw_info(struct swapchain_stats& sw_stats, struct overlay_params& par
} }
// get ram usage/max // get ram usage/max
if (params.enabled[OVERLAY_PARAM_ENABLED_ram] || loggingOn) if (params.enabled[OVERLAY_PARAM_ENABLED_ram] || logger->is_active())
update_meminfo(); update_meminfo();
if (params.enabled[OVERLAY_PARAM_ENABLED_io_read] || params.enabled[OVERLAY_PARAM_ENABLED_io_write]) if (params.enabled[OVERLAY_PARAM_ENABLED_io_read] || params.enabled[OVERLAY_PARAM_ENABLED_io_write])
getIoStats(&sw_stats.io); getIoStats(&sw_stats.io);
@ -769,8 +769,7 @@ void update_hw_info(struct swapchain_stats& sw_stats, struct overlay_params& par
currentLogData.cpu_load = cpuStats.GetCPUDataTotal().percent; currentLogData.cpu_load = cpuStats.GetCPUDataTotal().percent;
currentLogData.cpu_temp = cpuStats.GetCPUDataTotal().temp; currentLogData.cpu_temp = cpuStats.GetCPUDataTotal().temp;
if (!logUpdate) logger->notify_data_valid();
logUpdate = true;
} }
void check_keybinds(struct swapchain_stats& sw_stats, struct overlay_params& params, uint32_t vendorID){ void check_keybinds(struct swapchain_stats& sw_stats, struct overlay_params& params, uint32_t vendorID){
@ -790,24 +789,17 @@ void check_keybinds(struct swapchain_stats& sw_stats, struct overlay_params& par
#else #else
pressed = false; pressed = false;
#endif #endif
if (pressed && (now - log_end > 11s)){ if (pressed && (now - logger->last_log_end() > 11s)) {
last_f2_press = now; last_f2_press = now;
if(loggingOn){ if (logger->is_active()) {
log_end = now; logger->stop_logging();
std::thread(calculate_benchmark_data).detach();
} else { } else {
logUpdate = false; logger->start_logging();
std::thread(update_hw_info, std::ref(sw_stats), std::ref(params), vendorID).detach(); std::thread(update_hw_info, std::ref(sw_stats), std::ref(params),
vendorID)
.detach();
benchmark.fps_data.clear(); benchmark.fps_data.clear();
log_start = now;
} }
if (!params.output_file.empty() && params.log_duration == 0 && params.log_interval == 0 && loggingOn)
writeFile(params.output_file + get_log_suffix());
loggingOn = !loggingOn;
if (!params.output_file.empty() && loggingOn && params.log_interval != 0)
std::thread(logging, &params).detach();
} }
} }
@ -843,8 +835,7 @@ void check_keybinds(struct swapchain_stats& sw_stats, struct overlay_params& par
#endif #endif
if (pressed){ if (pressed){
last_upload_press = now; last_upload_press = now;
if (logFiles.size() > 0) logger->upload_last_log();
std::thread(upload_file).detach();
} }
} }
} }
@ -873,12 +864,13 @@ void calculate_benchmark_data(){
} }
void update_hud_info(struct swapchain_stats& sw_stats, struct overlay_params& params, uint32_t vendorID){ void update_hud_info(struct swapchain_stats& sw_stats, struct overlay_params& params, uint32_t vendorID){
if(not logger) logger = std::make_unique<Logger>(&params);
uint32_t f_idx = sw_stats.n_frames % ARRAY_SIZE(sw_stats.frames_stats); uint32_t f_idx = sw_stats.n_frames % ARRAY_SIZE(sw_stats.frames_stats);
uint64_t now = os_time_get(); /* us */ uint64_t now = os_time_get(); /* us */
double elapsed = (double)(now - sw_stats.last_fps_update); /* us */ double elapsed = (double)(now - sw_stats.last_fps_update); /* us */
fps = 1000000.0f * sw_stats.n_frames_since_update / elapsed; fps = 1000000.0f * sw_stats.n_frames_since_update / elapsed;
if (loggingOn) if (logger->is_active())
benchmark.fps_data.push_back(fps); benchmark.fps_data.push_back(fps);
if (sw_stats.last_present_time) { if (sw_stats.last_present_time) {
@ -1092,7 +1084,7 @@ void render_benchmark(swapchain_stats& data, struct overlay_params& params, ImVe
ImGui::SetNextWindowPos(ImVec2(data.main_window_pos.x, data.main_window_pos.y + window_size.y + 5), ImGuiCond_Always); ImGui::SetNextWindowPos(ImVec2(data.main_window_pos.x, data.main_window_pos.y + window_size.y + 5), ImGuiCond_Always);
vector<pair<string, float>> benchmark_data = {{"97% ", benchmark.ninety}, {"AVG ", benchmark.avg}, {"1% ", benchmark.oneP}, {"0.1%", benchmark.pointOneP}}; vector<pair<string, float>> benchmark_data = {{"97% ", benchmark.ninety}, {"AVG ", benchmark.avg}, {"1% ", benchmark.oneP}, {"0.1%", benchmark.pointOneP}};
float display_time = std::chrono::duration<float>(now - log_end).count(); float display_time = std::chrono::duration<float>(now - logger->last_log_end()).count();
static float display_for = 10.0f; static float display_for = 10.0f;
float alpha; float alpha;
if(params.background_alpha != 0){ if(params.background_alpha != 0){
@ -1126,7 +1118,7 @@ void render_benchmark(swapchain_stats& data, struct overlay_params& params, ImVe
ImGui::TextColored(ImVec4(1.0, 1.0, 1.0, alpha / params.background_alpha), "%s", finished); ImGui::TextColored(ImVec4(1.0, 1.0, 1.0, alpha / params.background_alpha), "%s", finished);
ImGui::Dummy(ImVec2(0.0f, 8.0f)); ImGui::Dummy(ImVec2(0.0f, 8.0f));
char duration[20]; char duration[20];
snprintf(duration, sizeof(duration), "Duration: %.1fs", std::chrono::duration<float>(log_end - log_start).count()); snprintf(duration, sizeof(duration), "Duration: %.1fs", std::chrono::duration<float>(logger->last_log_end() - logger->last_log_begin()).count());
ImGui::SetCursorPosX((ImGui::GetWindowSize().x / 2 )- (ImGui::CalcTextSize(duration).x / 2)); ImGui::SetCursorPosX((ImGui::GetWindowSize().x / 2 )- (ImGui::CalcTextSize(duration).x / 2));
ImGui::TextColored(ImVec4(1.0, 1.0, 1.0, alpha / params.background_alpha), "%s", duration); ImGui::TextColored(ImVec4(1.0, 1.0, 1.0, alpha / params.background_alpha), "%s", duration);
for (auto& data_ : benchmark_data){ for (auto& data_ : benchmark_data){
@ -1152,6 +1144,7 @@ void render_benchmark(swapchain_stats& data, struct overlay_params& params, ImVe
void render_imgui(swapchain_stats& data, struct overlay_params& params, ImVec2& window_size, bool is_vulkan) void render_imgui(swapchain_stats& data, struct overlay_params& params, ImVec2& window_size, bool is_vulkan)
{ {
ImGui::GetIO().FontGlobalScale = params.font_scale; ImGui::GetIO().FontGlobalScale = params.font_scale;
if(not logger) logger = std::make_unique<Logger>(&params);
uint32_t f_idx = (data.n_frames - 1) % ARRAY_SIZE(data.frames_stats); uint32_t f_idx = (data.n_frames - 1) % ARRAY_SIZE(data.frames_stats);
uint64_t frame_timing = data.frames_stats[f_idx].stats[OVERLAY_PLOTS_frame_timing]; uint64_t frame_timing = data.frames_stats[f_idx].stats[OVERLAY_PLOTS_frame_timing];
static float char_width = ImGui::CalcTextSize("A").x; static float char_width = ImGui::CalcTextSize("A").x;
@ -1379,14 +1372,8 @@ void render_imgui(swapchain_stats& data, struct overlay_params& params, ImVec2&
ImGui::PopFont(); ImGui::PopFont();
} }
if (loggingOn && params.log_interval == 0){ if (params.log_interval == 0){
elapsedLog = now - log_start; logger->try_log();
if (params.log_duration && (elapsedLog) >= std::chrono::seconds(params.log_duration))
loggingOn = false;
currentLogData.fps = fps;
currentLogData.previous = elapsedLog;
logArray.push_back(currentLogData);
} }
if (params.enabled[OVERLAY_PARAM_ENABLED_frame_timing]){ if (params.enabled[OVERLAY_PARAM_ENABLED_frame_timing]){
@ -1432,18 +1419,12 @@ void render_imgui(swapchain_stats& data, struct overlay_params& params, ImVec2&
ImGui::PopFont(); ImGui::PopFont();
#endif #endif
if(loggingOn) if(logger->is_active())
ImGui::GetWindowDrawList()->AddCircleFilled(ImVec2(data.main_window_pos.x + window_size.x - 15, data.main_window_pos.y + 15), 10, params.engine_color, 20); ImGui::GetWindowDrawList()->AddCircleFilled(ImVec2(data.main_window_pos.x + window_size.x - 15, data.main_window_pos.y + 15), 10, params.engine_color, 20);
window_size = ImVec2(window_size.x, ImGui::GetCursorPosY() + 10.0f); window_size = ImVec2(window_size.x, ImGui::GetCursorPosY() + 10.0f);
ImGui::End(); ImGui::End();
if (loggingOn && params.log_duration && (now - log_start) >= std::chrono::seconds(params.log_duration)){ if((now - logger->last_log_end()) < 12s)
loggingOn = false;
log_end = now;
std::thread(calculate_benchmark_data).detach();
}
if((now - log_end) < 12s)
render_benchmark(data, params, window_size, height, now); render_benchmark(data, params, window_size, height, now);
} }
} }

Loading…
Cancel
Save