From d6abc006a931702db178519371e2209ccad2735d Mon Sep 17 00:00:00 2001 From: PancakeTAS Date: Thu, 17 Jul 2025 02:40:24 +0200 Subject: [PATCH] improve logging in main application for users fixes #47 --- include/utils/benchmark.hpp | 7 +++- include/utils/log.hpp | 74 --------------------------------- src/config/config.cpp | 2 +- src/main.cpp | 80 +++++++++++++++++++++--------------- src/utils/benchmark.cpp | 81 +++++++++++++++++-------------------- src/utils/log.cpp | 50 ----------------------- src/utils/utils.cpp | 10 ++--- 7 files changed, 96 insertions(+), 208 deletions(-) delete mode 100644 include/utils/log.hpp delete mode 100644 src/utils/log.cpp diff --git a/include/utils/benchmark.hpp b/include/utils/benchmark.hpp index f940872..fc7f481 100644 --- a/include/utils/benchmark.hpp +++ b/include/utils/benchmark.hpp @@ -1,10 +1,15 @@ #pragma once +#include + namespace Benchmark { /// /// Run the benchmark. /// - void run(); + /// @param width The width of the benchmark. + /// @param height The height of the benchmark. + /// + [[noreturn]] void run(uint32_t width, uint32_t height); } diff --git a/include/utils/log.hpp b/include/utils/log.hpp deleted file mode 100644 index 6576aa5..0000000 --- a/include/utils/log.hpp +++ /dev/null @@ -1,74 +0,0 @@ -#pragma once - -#include -#include -#include -#include -#include -#include -#include - -namespace Log { - - namespace Internal { - extern bool isSetup; - - extern std::set debugModules; - extern bool debugAllModules; - - extern std::ofstream logFile; - extern std::mutex logMutex; - - void setup(); - } - - template - void log(std::string_view color, std::string_view module, - std::format_string fmt, Args&&... args) { - Internal::setup(); - - const std::string prefix = std::format("lsfg-vk({}): ", module); - const std::string message = std::format(fmt, std::forward(args)...); - - const std::lock_guard lock(Internal::logMutex); - std::cerr << color << prefix << message << "\033[0m" << '\n'; - if (Internal::logFile.is_open()) { - Internal::logFile << prefix << message << '\n'; - Internal::logFile.flush(); - } - } - - const std::string_view WHITE = "\033[1;37m"; - const std::string_view YELLOW = "\033[1;33m"; - const std::string_view RED = "\033[1;31m"; - - template - void info(std::string_view module, std::format_string fmt, Args&&... args) { - log(WHITE, module, fmt, std::forward(args)...); - } - - template - void warn(std::string_view module, std::format_string fmt, Args&&... args) { - log(YELLOW, module, fmt, std::forward(args)...); - } - - template - void error(std::string_view module, std::format_string fmt, Args&&... args) { - log(RED, module, fmt, std::forward(args)...); - } - - const std::string_view GRAY = "\033[1;90m"; - -#ifdef LSFG_NO_DEBUG -template -void debug(std::string_view, std::format_string, Args&&...) {} -#else - template - void debug(std::string_view module, std::format_string fmt, Args&&... args) { - Internal::setup(); - if (Internal::debugAllModules || Internal::debugModules.contains(std::string(module))) - log(GRAY, module, fmt, std::forward(args)...); - } -#endif - -} diff --git a/src/config/config.cpp b/src/config/config.cpp index 80d28a0..ee4175b 100644 --- a/src/config/config.cpp +++ b/src/config/config.cpp @@ -92,7 +92,7 @@ namespace { if (event->len <= 0 || event->mask & IN_IGNORED) continue; - std::string name(reinterpret_cast(event->name)); + const std::string name(reinterpret_cast(event->name)); if (name != filename) continue; diff --git a/src/main.cpp b/src/main.cpp index 7b26d73..b6edace 100644 --- a/src/main.cpp +++ b/src/main.cpp @@ -1,44 +1,19 @@ #include "config/config.hpp" #include "extract/extract.hpp" +#include "utils/benchmark.hpp" #include "utils/utils.hpp" -#include #include +#include #include +#include +#include #include +#include namespace { - /// Check if the library is preloaded or Vulkan loaded. - bool isPreload() { - const char* preload = std::getenv("LD_PRELOAD"); - if (!preload || *preload == '\0') - return false; - const std::string preload_str(preload); - return preload_str.find("liblsfg-vk.so") != std::string::npos; - } - - /// Check if a benchmark is requested. - bool requestedBenchmark() { - const char* benchmark = std::getenv("LSFG_BENCHMARK"); - if (!benchmark || *benchmark == '\0') - return false; - const std::string benchmark_str(benchmark); - return benchmark_str == "1"; - } - __attribute__((constructor)) void lsfgvk_init() { - if (isPreload()) { - if (requestedBenchmark()) { - // TODO: Call benchmark function. - exit(0); - } - - // TODO: health check, maybe? - std::cerr << "lsfg-vk: This library is not meant to be preloaded, unless you are running a benchmark.\n"; - exit(1); - } - - // read configuration (might block) + // read configuration const std::string file = Utils::getConfigFile(); try { Config::loadAndWatchConfig(file); @@ -59,7 +34,7 @@ namespace { // exit silently if not enabled auto& conf = Config::activeConf; - if (!conf.enable) + if (!conf.enable && name != "benchmark") return; // print config @@ -79,5 +54,46 @@ namespace { exit(0); } std::cerr << "lsfg-vk: Shaders extracted successfully.\n"; + + // run benchmark if requested + const char* benchmark_flag = std::getenv("LSFG_BENCHMARK"); + if (!benchmark_flag) + return; + + const std::string resolution(benchmark_flag); + uint32_t width{}; + uint32_t height{}; + try { + const size_t x = resolution.find('x'); + if (x == std::string::npos) + throw std::runtime_error("Unable to find 'x' in benchmark string"); + + const std::string width_str = resolution.substr(0, x); + const std::string height_str = resolution.substr(x + 1); + if (width_str.empty() || height_str.empty()) + throw std::runtime_error("Invalid resolution"); + + const int32_t w = std::stoi(width_str); + const int32_t h = std::stoi(height_str); + if (w < 0 || h < 0) + throw std::runtime_error("Resolution cannot be negative"); + + width = static_cast(w); + height = static_cast(h); + } catch (const std::exception& e) { + std::cerr << "lsfg-vk: An error occurred while trying to parse the resolution, exiting:\n"; + std::cerr << "- " << e.what() << '\n'; + } + + std::thread benchmark([width, height]() { + try { + Benchmark::run(width, height); + } catch (const std::exception& e) { + std::cerr << "lsfg-vk: An error occurred during the benchmark:\n"; + std::cerr << "- " << e.what() << '\n'; + } + }); + benchmark.detach(); + conf.enable = false; } } diff --git a/src/utils/benchmark.cpp b/src/utils/benchmark.cpp index eb86702..0f0d0fd 100644 --- a/src/utils/benchmark.cpp +++ b/src/utils/benchmark.cpp @@ -1,63 +1,47 @@ #include "utils/benchmark.hpp" +#include "config/config.hpp" #include "extract/extract.hpp" #include "extract/trans.hpp" -#include "utils/log.hpp" #include #include #include +#include -#include -#include +#include #include +#include +#include +#include +#include #include #include using namespace Benchmark; -void Benchmark::run() { - // fetch benchmark parameters - const char* lsfgFlowScale = std::getenv("LSFG_FLOW_SCALE"); - const char* lsfgHdr = std::getenv("LSFG_HDR"); - const char* lsfgMultiplier = std::getenv("LSFG_MULTIPLIER"); - const char* lsfgExtentWidth = std::getenv("LSFG_EXTENT_WIDTH"); - const char* lsfgExtentHeight = std::getenv("LSFG_EXTENT_HEIGHT"); - const char* lsfgPerfMode = std::getenv("LSFG_PERF_MODE"); - - const float flowScale = lsfgFlowScale - ? std::stof(lsfgFlowScale) : 1.0F; - const bool isHdr = lsfgHdr - ? *lsfgHdr == '1' : false; - const uint64_t multiplier = lsfgMultiplier - ? std::stoull(std::string(lsfgMultiplier)) : 2; - const uint32_t width = lsfgExtentWidth - ? static_cast(std::stoul(lsfgExtentWidth)) : 1920; - const uint32_t height = lsfgExtentHeight - ? static_cast(std::stoul(lsfgExtentHeight)) : 1080; - const bool perfMode = lsfgPerfMode - ? *lsfgPerfMode == '1' : false; +void Benchmark::run(uint32_t width, uint32_t height) { + const auto& conf = Config::activeConf; auto* lsfgInitialize = LSFG_3_1::initialize; auto* lsfgCreateContext = LSFG_3_1::createContext; auto* lsfgPresentContext = LSFG_3_1::presentContext; - if (perfMode) { + if (conf.performance) { lsfgInitialize = LSFG_3_1P::initialize; lsfgCreateContext = LSFG_3_1P::createContext; lsfgPresentContext = LSFG_3_1P::presentContext; } - Log::info("bench", "Running {}x benchmark with {}x{} extent and flow scale of {} {} HDR", - multiplier, width, height, flowScale, isHdr ? "with" : "without"); - // create the benchmark context const char* lsfgDeviceUUID = std::getenv("LSFG_DEVICE_UUID"); const uint64_t deviceUUID = lsfgDeviceUUID ? std::stoull(std::string(lsfgDeviceUUID), nullptr, 16) : 0x1463ABAC; + setenv("DISABLE_LSFG", "1", 1); // NOLINT + Extract::extractShaders(); lsfgInitialize( deviceUUID, // some magic number if not given - isHdr, 1.0F / flowScale, multiplier - 1, + conf.hdr, 1.0F / conf.flowScale, conf.multiplier - 1, [](const std::string& name) -> std::vector { auto dxbc = Extract::getShader(name); auto spirv = Extract::translateShader(dxbc); @@ -66,21 +50,24 @@ void Benchmark::run() { ); const int32_t ctx = lsfgCreateContext(-1, -1, {}, { .width = width, .height = height }, - isHdr ? VK_FORMAT_R16G16B16A16_SFLOAT : VK_FORMAT_R8G8B8A8_UNORM + conf.hdr ? VK_FORMAT_R16G16B16A16_SFLOAT : VK_FORMAT_R8G8B8A8_UNORM ); - Log::info("bench", "Benchmark context created, ready to run"); + unsetenv("DISABLE_LSFG"); // NOLINT // run the benchmark (run 8*n + 1 so the fences are waited on) const auto now = std::chrono::high_resolution_clock::now(); - const uint64_t iterations = (8 * 500) + 1; - for (uint64_t count = 0; count < iterations; count++) { + const uint64_t iterations = 8 * 500UL; + + std::cerr << "lsfg-vk: Benchmark started, running " << iterations << " iterations...\n"; + for (uint64_t count = 0; count < iterations + 1; count++) { lsfgPresentContext(ctx, -1, {}); - if (count % 500 == 0) - Log::info("bench", "{:.2f}% done ({}/{})", - static_cast(count) / static_cast(iterations) * 100.0F, - count + 1, iterations); + if (count % 50 == 0 && count > 0) + std::cerr << "lsfg-vk: " + << std::setprecision(2) << std::fixed + << static_cast(count) / static_cast(iterations) * 100.0F + << "% done (" << count + 1 << "/" << iterations << ")\r"; } const auto then = std::chrono::high_resolution_clock::now(); @@ -89,15 +76,21 @@ void Benchmark::run() { const auto perIteration = static_cast(ms) / static_cast(iterations); - const uint64_t totalGen = (multiplier - 1) * iterations; + const uint64_t totalGen = (conf.multiplier - 1) * iterations; const auto genFps = static_cast(totalGen) / (static_cast(ms) / 1000.0F); - const uint64_t totalFrames = iterations * multiplier; + const uint64_t totalFrames = iterations * conf.multiplier; const auto totalFps = static_cast(totalFrames) / (static_cast(ms) / 1000.0F); - Log::info("bench", "Benchmark completed in {} ms", ms); - Log::info("bench", "Time per iteration: {:.2f} ms", perIteration); - Log::info("bench", "Generation FPS: {:.2f}", genFps); - Log::info("bench", "Final FPS: {:.2f}", totalFps); - Log::info("bench", "Benchmark finished, exiting"); + std::cerr << "lsfg-vk: Benchmark completed in " << ms << " ms\n"; + std::cerr << " Time taken per real frame: " + << std::setprecision(2) << std::fixed << perIteration << " ms\n"; + std::cerr << " Generated " << totalGen << " frames in total at " + << std::setprecision(2) << std::fixed << genFps << " FPS\n"; + std::cerr << " Total of " << totalFrames << " frames presented at " + << std::setprecision(2) << std::fixed << totalFps << " FPS\n"; + + // sleep for a second, then exit + std::this_thread::sleep_for(std::chrono::seconds(1)); + _exit(0); } diff --git a/src/utils/log.cpp b/src/utils/log.cpp deleted file mode 100644 index 225d9f4..0000000 --- a/src/utils/log.cpp +++ /dev/null @@ -1,50 +0,0 @@ -#include "utils/log.hpp" - -#include - -#include -#include -#include -#include -#include -#include -#include - -using namespace Log; - -bool Internal::isSetup{}; - -std::set Internal::debugModules; -bool Internal::debugAllModules{}; - -std::ofstream Internal::logFile; -std::mutex Internal::logMutex; - -void Internal::setup() { - if (isSetup) return; - isSetup = true; - - // open log file - const char* env_log_file = std::getenv("LSFG_LOG_FILE"); - if (env_log_file) { - std::ostringstream filename; - filename << getpid() << "_" << env_log_file; - logFile.open(filename.str(), std::ios::app); - } - - // parse debug modules - const char* env_log_debug = std::getenv("LSFG_LOG_DEBUG"); - if (!env_log_debug) - return; - const std::string debugModulesStr(env_log_debug); - - std::stringstream ss(debugModulesStr); - std::string item; - while (std::getline(ss, item, ',')) { - if (item == "all") { - debugAllModules = true; - return; - } - debugModules.insert(item); - } - } diff --git a/src/utils/utils.cpp b/src/utils/utils.cpp index f58532e..16b86d9 100644 --- a/src/utils/utils.cpp +++ b/src/utils/utils.cpp @@ -1,5 +1,4 @@ #include "utils/utils.hpp" -#include "utils/log.hpp" #include "common/exception.hpp" #include "layer.hpp" @@ -82,12 +81,8 @@ std::vector Utils::addExtensions(const char* const* extensions, siz [e](const char* extName) { return std::string(extName) == std::string(e); }); - if (it == ext.end()) { - Log::debug("hooks-init", "Adding extension: {}", e); + if (it == ext.end()) ext.push_back(e); - } else { - Log::debug("hooks-init", "Extension {} already present", e); - } } return ext; @@ -214,6 +209,9 @@ void Utils::resetLimitN(const std::string& id) noexcept { /// Get the process name std::string Utils::getProcessName() { + const char* benchmark_flag = std::getenv("LSFG_BENCHMARK"); + if (benchmark_flag) + return "benchmark"; std::array exe{}; const ssize_t exe_len = readlink("/proc/self/exe", exe.data(), exe.size() - 1); if (exe_len <= 0)