From 4101237fdd0b30428b96a6a0aeee8f43ede56ae8 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Lars=20Kr=C3=A4mer?= <24323470+larskraemer@users.noreply.github.com> Date: Sun, 21 Jun 2020 18:52:38 +0200 Subject: [PATCH 1/3] Move logging functionality into a class --- src/logging.cpp | 96 ++++++++++++++++++++++++++++++++++--------------- src/logging.h | 48 +++++++++++++++++++------ src/overlay.cpp | 56 +++++++++++------------------ 3 files changed, 125 insertions(+), 75 deletions(-) diff --git a/src/logging.cpp b/src/logging.cpp index 56e6bf42..2e30c847 100644 --- a/src/logging.cpp +++ b/src/logging.cpp @@ -5,16 +5,11 @@ string os, cpu, gpu, ram, kernel, driver; bool sysInfoFetched = false; -int gpuLoadLog = 0, cpuLoadLog = 0; -Clock::duration elapsedLog; std::vector logFiles; double fps; -std::vector logArray; -ofstream out; -bool loggingOn; -Clock::time_point log_start, log_end; logData currentLogData = {}; -bool logUpdate = false; + +std::unique_ptr logger; string exec(string command) { char buffer[128]; @@ -58,8 +53,10 @@ void upload_files(){ } void writeFile(string filename){ + auto& logArray = logger->get_log_data(); + std::cerr << "writeFile(" << filename << ", vector(" << logArray.size() << "))\n"; logFiles.push_back(filename); - out.open(filename, ios::out | ios::app); + 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 << "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 << std::chrono::duration_cast(logArray[i].previous).count() << "\n"; } - - out.close(); - logArray.clear(); + logger->clear_log_data(); } string get_log_suffix(){ @@ -92,23 +87,68 @@ string get_log_suffix(){ void logging(void *params_void){ overlay_params *params = reinterpret_cast(params_void); - while (loggingOn){ - auto now = Clock::now(); - elapsedLog = now - log_start; - - 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)); + logger->wait_until_data_valid(); + while (logger->is_active()){ + logger->try_log(); + this_thread::sleep_for(chrono::milliseconds(params->log_interval)); + } +} + +Logger::Logger(overlay_params* in_params) + : loggingOn(false), + values_valid(false), + params(in_params) +{ +#ifndef NDEBUG + std::cerr << "Logger constructed!\n"; +#endif +} + +void Logger::start_logging() { + if(loggingOn) return; + values_valid = false; + loggingOn = true; + log_start = Clock::now(); + if((not params->output_file.empty()) and (params->log_interval != 0)){ + std::thread(logging, params).detach(); + } +} + +void Logger::stop_logging() { + if(not loggingOn) return; + loggingOn = false; + log_end = Clock::now(); + + std::thread(calculate_benchmark_data).detach(); + + if(not params->output_file.empty()) { + std::thread(writeFile, params->output_file + get_log_suffix()).detach(); + } +} + + +void Logger::try_log() { + if(not is_active()) return; + if(not values_valid) return; + auto now = Clock::now(); + auto elapsedLog = now - log_start; + + currentLogData.previous = elapsedLog; + currentLogData.fps = fps; + logArray.push_back(currentLogData); + + if(params->log_duration and (elapsedLog >= std::chrono::seconds(params->log_duration))){ + stop_logging(); } +} - writeFile(params->output_file + get_log_suffix()); +void Logger::wait_until_data_valid() { + std::unique_lock lck(values_valid_mtx); + while(! values_valid) values_valid_cv.wait(lck); } + +void Logger::notify_data_valid() { + std::unique_lock lck(values_valid_mtx); + values_valid = true; + values_valid_cv.notify_all(); +} \ No newline at end of file diff --git a/src/logging.h b/src/logging.h index 8df1def4..d4679365 100644 --- a/src/logging.h +++ b/src/logging.h @@ -3,9 +3,12 @@ #include #include #include +#include #include "timing.hpp" +#include "overlay_params.h" + using namespace std; struct logData{ double fps; @@ -21,20 +24,43 @@ struct logData{ 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 loggingOn; } + + void wait_until_data_valid(); + void notify_data_valid(); + + auto last_log_end() const noexcept { return log_end; } + auto last_log_begin() const noexcept { return log_start; } + + const std::vector& get_log_data() const noexcept { return logArray; } + void clear_log_data() noexcept { logArray.clear(); } +private: + std::vector logArray; + Clock::time_point log_start; + Clock::time_point log_end; + bool loggingOn; + + std::mutex values_valid_mtx; + std::condition_variable values_valid_cv; + bool values_valid; + + overlay_params* params; +}; + +extern std::unique_ptr logger; + extern string os, cpu, gpu, ram, kernel, driver; extern bool sysInfoFetched; -extern Clock::duration elapsedLog; -extern std::vector logFiles; extern double fps; -extern std::vector logArray; -extern bool loggingOn; -extern Clock::time_point log_start, log_end; extern logData currentLogData; -extern bool logUpdate; -void logging(void *params_void); -void writeFile(string filename); string exec(string command); -string get_log_suffix(void); -void upload_file(void); -void upload_files(void); diff --git a/src/overlay.cpp b/src/overlay.cpp index 902ceb4f..84359747 100644 --- a/src/overlay.cpp +++ b/src/overlay.cpp @@ -735,17 +735,17 @@ void init_system_info(){ } 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(); sw_stats.total_cpu = cpuStats.GetCPUDataTotal().percent; if (params.enabled[OVERLAY_PARAM_ENABLED_core_load]) cpuStats.UpdateCoreMhz(); - if (params.enabled[OVERLAY_PARAM_ENABLED_cpu_temp] || loggingOn) + if (params.enabled[OVERLAY_PARAM_ENABLED_cpu_temp] || logger->is_active()) 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) getAmdGpuInfo(); @@ -754,7 +754,7 @@ void update_hw_info(struct swapchain_stats& sw_stats, struct overlay_params& par } // get ram usage/max - if (params.enabled[OVERLAY_PARAM_ENABLED_ram] || loggingOn) + if (params.enabled[OVERLAY_PARAM_ENABLED_ram] || logger->is_active()) update_meminfo(); if (params.enabled[OVERLAY_PARAM_ENABLED_io_read] || params.enabled[OVERLAY_PARAM_ENABLED_io_write]) 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_temp = cpuStats.GetCPUDataTotal().temp; - if (!logUpdate) - logUpdate = true; + logger->notify_data_valid(); } void check_keybinds(struct swapchain_stats& sw_stats, struct overlay_params& params, uint32_t vendorID){ @@ -792,22 +791,14 @@ void check_keybinds(struct swapchain_stats& sw_stats, struct overlay_params& par #endif if (pressed && (now - log_end > 11s)){ last_f2_press = now; - if(loggingOn){ - log_end = now; + if(logger->is_active()){ + logger->stop_logging(); std::thread(calculate_benchmark_data).detach(); } else { - logUpdate = false; + logger->start_logging(); std::thread(update_hw_info, std::ref(sw_stats), std::ref(params), vendorID).detach(); 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, ¶ms).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){ + if(not logger) logger = std::make_unique(¶ms); uint32_t f_idx = sw_stats.n_frames % ARRAY_SIZE(sw_stats.frames_stats); uint64_t now = os_time_get(); /* us */ double elapsed = (double)(now - sw_stats.last_fps_update); /* us */ fps = 1000000.0f * sw_stats.n_frames_since_update / elapsed; - if (loggingOn) + if (logger->is_active()) benchmark.fps_data.push_back(fps); 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); vector> benchmark_data = {{"97% ", benchmark.ninety}, {"AVG ", benchmark.avg}, {"1% ", benchmark.oneP}, {"0.1%", benchmark.pointOneP}}; - float display_time = std::chrono::duration(now - log_end).count(); + float display_time = std::chrono::duration(now - logger->last_log_end()).count(); static float display_for = 10.0f; float alpha; 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::Dummy(ImVec2(0.0f, 8.0f)); char duration[20]; - snprintf(duration, sizeof(duration), "Duration: %.1fs", std::chrono::duration(log_end - log_start).count()); + snprintf(duration, sizeof(duration), "Duration: %.1fs", std::chrono::duration(logger->last_log_end() - logger->last_log_begin()).count()); 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); for (auto& data_ : benchmark_data){ @@ -1151,7 +1143,11 @@ 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) { +<<<<<<< HEAD ImGui::GetIO().FontGlobalScale = params.font_scale; +======= + if(not logger) logger = std::make_unique(¶ms); +>>>>>>> 9c2e489... Move logging functionality into a class 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]; static float char_width = ImGui::CalcTextSize("A").x; @@ -1379,14 +1375,8 @@ void render_imgui(swapchain_stats& data, struct overlay_params& params, ImVec2& ImGui::PopFont(); } - if (loggingOn && params.log_interval == 0){ - elapsedLog = now - log_start; - 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.log_interval == 0){ + logger->try_log(); } if (params.enabled[OVERLAY_PARAM_ENABLED_frame_timing]){ @@ -1432,18 +1422,12 @@ void render_imgui(swapchain_stats& data, struct overlay_params& params, ImVec2& ImGui::PopFont(); #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); window_size = ImVec2(window_size.x, ImGui::GetCursorPosY() + 10.0f); ImGui::End(); - if (loggingOn && params.log_duration && (now - log_start) >= std::chrono::seconds(params.log_duration)){ - loggingOn = false; - log_end = now; - std::thread(calculate_benchmark_data).detach(); - } - if((now - log_end) < 12s) + if((now - logger->last_log_end()) < 12s) render_benchmark(data, params, window_size, height, now); - } } From 329725c13472af19e82baba87bae5f5964cfc5cd Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Lars=20Kr=C3=A4mer?= <24323470+larskraemer@users.noreply.github.com> Date: Wed, 24 Jun 2020 22:03:49 +0200 Subject: [PATCH 2/3] Move Log uploading; Cleanup --- src/logging.cpp | 65 ++++++++++++++++++++++++++----------------------- src/logging.h | 29 ++++++++++++---------- src/overlay.cpp | 12 ++++----- 3 files changed, 57 insertions(+), 49 deletions(-) diff --git a/src/logging.cpp b/src/logging.cpp index 2e30c847..757edc1b 100644 --- a/src/logging.cpp +++ b/src/logging.cpp @@ -5,7 +5,6 @@ string os, cpu, gpu, ram, kernel, driver; bool sysInfoFetched = false; -std::vector logFiles; double fps; logData currentLogData = {}; @@ -33,16 +32,16 @@ string exec(string command) { 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' "; - command += " -F 'log[uploads][]=@" + logFiles.back() + "'"; + command += " -F 'log[uploads][]=@" + logFile + "'"; command += " | grep Location | cut -c11-"; std::string url = exec(command); exec("xdg-open " + url); } -void upload_files(){ +void upload_files(const std::vector& 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' "; for (auto& file : logFiles) command += " -F 'log[uploads][]=@" + file + "'"; @@ -54,8 +53,9 @@ void upload_files(){ void writeFile(string filename){ auto& logArray = logger->get_log_data(); - std::cerr << "writeFile(" << filename << ", vector(" << logArray.size() << "))\n"; - logFiles.push_back(filename); +#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; @@ -95,9 +95,9 @@ void logging(void *params_void){ } Logger::Logger(overlay_params* in_params) - : loggingOn(false), - values_valid(false), - params(in_params) + : m_logging_on(false), + m_values_valid(false), + m_params(in_params) { #ifndef NDEBUG std::cerr << "Logger constructed!\n"; @@ -105,50 +105,55 @@ Logger::Logger(overlay_params* in_params) } void Logger::start_logging() { - if(loggingOn) return; - values_valid = false; - loggingOn = true; - log_start = Clock::now(); - if((not params->output_file.empty()) and (params->log_interval != 0)){ - std::thread(logging, params).detach(); + 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 loggingOn) return; - loggingOn = false; - log_end = Clock::now(); + if(not m_logging_on) return; + m_logging_on = false; + m_log_end = Clock::now(); std::thread(calculate_benchmark_data).detach(); - if(not params->output_file.empty()) { - std::thread(writeFile, params->output_file + get_log_suffix()).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 values_valid) return; + if(not m_values_valid) return; auto now = Clock::now(); - auto elapsedLog = now - log_start; + auto elapsedLog = now - m_log_start; currentLogData.previous = elapsedLog; currentLogData.fps = fps; - logArray.push_back(currentLogData); + m_log_array.push_back(currentLogData); - if(params->log_duration and (elapsedLog >= std::chrono::seconds(params->log_duration))){ + 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 lck(values_valid_mtx); - while(! values_valid) values_valid_cv.wait(lck); + std::unique_lock lck(m_values_valid_mtx); + while(! m_values_valid) m_values_valid_cv.wait(lck); } void Logger::notify_data_valid() { - std::unique_lock lck(values_valid_mtx); - values_valid = true; - values_valid_cv.notify_all(); + std::unique_lock 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(); } \ No newline at end of file diff --git a/src/logging.h b/src/logging.h index d4679365..042e8e49 100644 --- a/src/logging.h +++ b/src/logging.h @@ -33,27 +33,30 @@ public: void try_log(); - bool is_active() const { return loggingOn; } + bool is_active() const { return m_logging_on; } void wait_until_data_valid(); void notify_data_valid(); - auto last_log_end() const noexcept { return log_end; } - auto last_log_begin() const noexcept { return log_start; } + auto last_log_end() const noexcept { return m_log_end; } + auto last_log_begin() const noexcept { return m_log_start; } - const std::vector& get_log_data() const noexcept { return logArray; } - void clear_log_data() noexcept { logArray.clear(); } + const std::vector& 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 logArray; - Clock::time_point log_start; - Clock::time_point log_end; - bool loggingOn; + std::vector m_log_array; + std::vector m_log_files; + Clock::time_point m_log_start; + Clock::time_point m_log_end; + bool m_logging_on; - std::mutex values_valid_mtx; - std::condition_variable values_valid_cv; - bool values_valid; + std::mutex m_values_valid_mtx; + std::condition_variable m_values_valid_cv; + bool m_values_valid; - overlay_params* params; + overlay_params* m_params; }; extern std::unique_ptr logger; diff --git a/src/overlay.cpp b/src/overlay.cpp index 84359747..983021d1 100644 --- a/src/overlay.cpp +++ b/src/overlay.cpp @@ -789,14 +789,15 @@ void check_keybinds(struct swapchain_stats& sw_stats, struct overlay_params& par #else pressed = false; #endif - if (pressed && (now - log_end > 11s)){ + if (pressed && (now - logger->last_log_end() > 11s)) { last_f2_press = now; - if(logger->is_active()){ + if (logger->is_active()) { logger->stop_logging(); - std::thread(calculate_benchmark_data).detach(); } else { 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(); } } @@ -834,8 +835,7 @@ void check_keybinds(struct swapchain_stats& sw_stats, struct overlay_params& par #endif if (pressed){ last_upload_press = now; - if (logFiles.size() > 0) - std::thread(upload_file).detach(); + logger->upload_last_log(); } } } From 0b29a7ea06b2fe89878f9108483c115ee73fa64c Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Lars=20Kr=C3=A4mer?= <24323470+larskraemer@users.noreply.github.com> Date: Mon, 29 Jun 2020 16:43:25 +0200 Subject: [PATCH 3/3] Remove conflict in render_imgui --- src/overlay.cpp | 3 --- 1 file changed, 3 deletions(-) diff --git a/src/overlay.cpp b/src/overlay.cpp index 983021d1..e84324be 100644 --- a/src/overlay.cpp +++ b/src/overlay.cpp @@ -1143,11 +1143,8 @@ 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) { -<<<<<<< HEAD ImGui::GetIO().FontGlobalScale = params.font_scale; -======= if(not logger) logger = std::make_unique(¶ms); ->>>>>>> 9c2e489... Move logging functionality into a class 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]; static float char_width = ImGui::CalcTextSize("A").x;