From 33ca3750345f4d14eee8f51f26cea040763b95d5 Mon Sep 17 00:00:00 2001 From: johndoe6345789 Date: Sun, 4 Jan 2026 00:10:20 +0000 Subject: [PATCH] feat: Implement logging system and integrate into application --- CMakeLists.txt | 7 ++- src/app/sdl3_app_core.cpp | 20 ++---- src/app/sdl3_app_device.cpp | 8 ++- src/app/sdl3_app_render.cpp | 16 ++--- src/app/sdl3_app_swapchain.cpp | 12 ++-- src/app/vulkan_api.cpp | 5 ++ src/logging/logger.cpp | 108 +++++++++++++++++++++++++++++++++ src/logging/logger.hpp | 69 +++++++++++++++++++++ src/main.cpp | 14 ++++- 9 files changed, 222 insertions(+), 37 deletions(-) create mode 100644 src/logging/logger.cpp create mode 100644 src/logging/logger.hpp diff --git a/CMakeLists.txt b/CMakeLists.txt index 2ce4085..5c07a95 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -102,6 +102,7 @@ find_package(glm CONFIG REQUIRED) if(BUILD_SDL3_APP) add_executable(sdl3_app src/main.cpp + src/logging/logger.cpp src/app/sdl3_app_core.cpp src/app/audio_player.cpp src/app/sdl3_app_device.cpp @@ -114,13 +115,13 @@ if(BUILD_SDL3_APP) src/app/vulkan_api.cpp src/script/script_engine.cpp src/script/physics_bridge.cpp + src/script/lua_helpers.cpp + src/script/lua_bindings.cpp + src/script/mesh_loader.cpp src/script/scene_manager.cpp src/script/shader_manager.cpp src/script/gui_manager.cpp src/script/audio_manager.cpp - src/script/lua_helpers.cpp - src/script/lua_bindings.cpp - src/script/mesh_loader.cpp ) target_include_directories(sdl3_app PRIVATE "${CMAKE_CURRENT_SOURCE_DIR}/src") target_link_libraries(sdl3_app PRIVATE ${SDL_TARGET} Vulkan::Vulkan lua::lua CLI11::CLI11 rapidjson assimp::assimp Bullet::Bullet glm::glm Vorbis::vorbisfile Vorbis::vorbis) diff --git a/src/app/sdl3_app_core.cpp b/src/app/sdl3_app_core.cpp index 92cb810..d231436 100644 --- a/src/app/sdl3_app_core.cpp +++ b/src/app/sdl3_app_core.cpp @@ -1,6 +1,7 @@ #include "app/audio_player.hpp" #include "app/sdl3_app.hpp" #include "app/trace.hpp" +#include "logging/logger.hpp" #include #include @@ -166,7 +167,7 @@ void Sdl3App::InitSDL() { audioPlayer_ = std::make_unique(); scriptEngine_.SetAudioPlayer(audioPlayer_.get()); } catch (const std::exception& exc) { - std::cerr << "AudioPlayer: " << exc.what() << '\n'; + LOG_WARN("AudioPlayer initialization failed: " + std::string(exc.what())); } } @@ -238,27 +239,14 @@ void Sdl3App::MainLoop() { if (!firstFrameCompleted_) { auto elapsed = now - start; if (elapsed > kLaunchTimeout) { - std::cerr << "\n=== LAUNCH TIMEOUT ==="; - std::cerr << "\nApplication failed to render first frame within " - << std::chrono::duration_cast(kLaunchTimeout).count() - << " seconds.\n"; - std::cerr << "This typically indicates:\n"; - std::cerr << " - GPU driver issue or incompatibility\n"; - std::cerr << " - Window manager/compositor problem\n"; - std::cerr << " - Vulkan swapchain configuration mismatch\n"; - std::cerr << "\nTroubleshooting suggestions:\n"; - std::cerr << " - Update GPU drivers\n"; - std::cerr << " - Try disabling compositor (if using X11/Wayland)\n"; - std::cerr << " - Check dmesg/journalctl for GPU errors\n"; - std::cerr << " - Run with VK_LOADER_DEBUG=all for detailed Vulkan logs\n"; - std::cerr << "======================\n" << std::flush; + LOG_ERROR("Launch timeout: Application failed to render first frame within " + std::to_string(std::chrono::duration_cast(kLaunchTimeout).count()) + " seconds. This typically indicates GPU driver issue, window manager problem, or Vulkan swapchain configuration mismatch."); throw std::runtime_error("Launch timeout: First frame did not complete"); } // Print progress indicator every second during launch if (now - lastProgressTime > std::chrono::seconds(1)) { auto waitTime = std::chrono::duration_cast(elapsed).count(); - std::cout << "Waiting for first frame... (" << waitTime << "s)\n" << std::flush; + LOG_INFO("Waiting for first frame... (" + std::to_string(waitTime) + "s)"); lastProgressTime = now; } } diff --git a/src/app/sdl3_app_device.cpp b/src/app/sdl3_app_device.cpp index 2200556..e916da3 100644 --- a/src/app/sdl3_app_device.cpp +++ b/src/app/sdl3_app_device.cpp @@ -1,5 +1,6 @@ #include "app/sdl3_app.hpp" #include "app/trace.hpp" +#include "logging/logger.hpp" #include #include @@ -174,9 +175,11 @@ void Sdl3App::CreateLogicalDevice() { createInfo.ppEnabledExtensionNames = kDeviceExtensions.data(); if (vkCreateDevice(physicalDevice_, &createInfo, nullptr, &device_) != VK_SUCCESS) { + LOG_ERROR("Failed to create logical device"); throw std::runtime_error("Failed to create logical device"); } + LOG_INFO("Logical device created successfully"); vkGetDeviceQueue(device_, *indices.graphicsFamily, 0, &graphicsQueue_); vkGetDeviceQueue(device_, *indices.presentFamily, 0, &presentQueue_); } @@ -228,10 +231,11 @@ bool Sdl3App::CheckDeviceExtensionSupport(VkPhysicalDevice device) { } if (!requiredExtensions.empty()) { - std::cerr << "Missing required device extensions:\n"; + std::string missingList; for (const auto& missing : requiredExtensions) { - std::cerr << " - " << missing << "\n"; + missingList += " - " + missing + "\n"; } + LOG_ERROR("Missing required device extensions:\n" + missingList); } return requiredExtensions.empty(); diff --git a/src/app/sdl3_app_render.cpp b/src/app/sdl3_app_render.cpp index e8ddd40..8d3f878 100644 --- a/src/app/sdl3_app_render.cpp +++ b/src/app/sdl3_app_render.cpp @@ -1,5 +1,6 @@ #include "app/sdl3_app.hpp" #include "app/trace.hpp" +#include "logging/logger.hpp" #include #include @@ -240,16 +241,17 @@ void Sdl3App::SetupGuiRenderer() { void Sdl3App::DrawFrame(float time) { TRACE_FUNCTION(); + LOG_DEBUG("Drawing frame at time " + std::to_string(time)); // Use reasonable timeout instead of infinite wait (5 seconds) constexpr uint64_t kFenceTimeout = 5000000000ULL; // 5 seconds in nanoseconds VkResult fenceResult = vkWaitForFences(device_, 1, &inFlightFence_, VK_TRUE, kFenceTimeout); if (fenceResult == VK_TIMEOUT) { - std::cerr << "\nERROR: Fence wait timeout: GPU appears to be hung\n"; + LOG_ERROR("Fence wait timeout: GPU appears to be hung"); PrintGpuDiagnostics("Fence wait timeout after 5 seconds"); throw std::runtime_error("Fence wait timeout: GPU appears to be hung"); } else if (fenceResult != VK_SUCCESS) { - std::cerr << "\nERROR: Fence wait failed with code: " << fenceResult << "\n"; + LOG_ERROR("Fence wait failed with code: " + std::to_string(fenceResult)); PrintGpuDiagnostics("Fence wait failed with error code " + std::to_string(fenceResult)); throw std::runtime_error("Fence wait failed"); } @@ -262,15 +264,15 @@ void Sdl3App::DrawFrame(float time) { if (result == VK_ERROR_OUT_OF_DATE_KHR || result == VK_SUBOPTIMAL_KHR || framebufferResized_) { consecutiveSwapchainRecreations_++; - std::cout << "Swapchain recreation triggered (attempt " << consecutiveSwapchainRecreations_ << ")"; + std::string logMsg = "Swapchain recreation triggered (attempt " + std::to_string(consecutiveSwapchainRecreations_) + ")"; if (result == VK_ERROR_OUT_OF_DATE_KHR) { - std::cout << " - OUT_OF_DATE"; + logMsg += " - OUT_OF_DATE"; } else if (result == VK_SUBOPTIMAL_KHR) { - std::cout << " - SUBOPTIMAL"; + logMsg += " - SUBOPTIMAL"; } else if (framebufferResized_) { - std::cout << " - RESIZE_EVENT"; + logMsg += " - RESIZE_EVENT"; } - std::cout << "\n"; + LOG_INFO(logMsg); // Detect infinite swapchain recreation loop constexpr int kMaxConsecutiveRecreations = 10; diff --git a/src/app/sdl3_app_swapchain.cpp b/src/app/sdl3_app_swapchain.cpp index f28a43e..af16b6c 100644 --- a/src/app/sdl3_app_swapchain.cpp +++ b/src/app/sdl3_app_swapchain.cpp @@ -1,6 +1,7 @@ #include "app/sdl3_app.hpp" #include "app/trace.hpp" #include "app/vulkan_api.hpp" +#include "logging/logger.hpp" #include @@ -187,14 +188,13 @@ void Sdl3App::RecreateSwapChain() { while (width == 0 || height == 0) { // Escape hatch 1: Check for signal (Ctrl+C) if (ShouldStop()) { - std::cerr << "Received stop signal while waiting for valid window dimensions\n"; + LOG_WARN("Received stop signal while waiting for valid window dimensions"); throw std::runtime_error("Application shutdown requested"); } // Escape hatch 2: Timeout after maximum attempts if (attempts >= kMaxAttempts) { - std::cerr << "Timeout waiting for valid window dimensions after " << attempts << " attempts\n"; - std::cerr << "Window size stuck at: " << width << "x" << height << "\n"; + LOG_ERROR("Timeout waiting for valid window dimensions after " + std::to_string(attempts) + " attempts. Window size stuck at: " + std::to_string(width) + "x" + std::to_string(height)); throw std::runtime_error("Window resize timeout: dimensions remain 0x0"); } @@ -208,14 +208,12 @@ void Sdl3App::RecreateSwapChain() { // Log periodically for debugging if (attempts % 10 == 0) { - std::cerr << "Still waiting for valid window dimensions (attempt " - << attempts << "/" << kMaxAttempts << "): " - << width << "x" << height << "\n"; + LOG_DEBUG("Still waiting for valid window dimensions (attempt " + std::to_string(attempts) + "/" + std::to_string(kMaxAttempts) + "): " + std::to_string(width) + "x" + std::to_string(height)); } } } - std::cout << "Window resize resolved: " << width << "x" << height << "\n"; + LOG_INFO("Window resize resolved: " + std::to_string(width) + "x" + std::to_string(height)); vkDeviceWaitIdle(device_); CleanupSwapChain(); CreateSwapChain(); diff --git a/src/app/vulkan_api.cpp b/src/app/vulkan_api.cpp index 535e346..c3e3895 100644 --- a/src/app/vulkan_api.cpp +++ b/src/app/vulkan_api.cpp @@ -1,4 +1,5 @@ #include "app/vulkan_api.hpp" +#include "logging/logger.hpp" #include #include @@ -14,10 +15,12 @@ uint32_t FindMemoryType(VkPhysicalDevice physicalDevice, uint32_t typeFilter, Vk for (uint32_t i = 0; i < memProperties.memoryTypeCount; ++i) { if ((typeFilter & (1 << i)) && (memProperties.memoryTypes[i].propertyFlags & properties) == properties) { + LOG_DEBUG("Found suitable memory type: " + std::to_string(i)); return i; } } + LOG_ERROR("Failed to find suitable memory type"); throw std::runtime_error("Failed to find suitable memory type"); } @@ -38,8 +41,10 @@ VkExtent2D ChooseSwapExtent(VkSurfaceCapabilitiesKHR capabilities, SDL_Window* w void CreateBuffer(VkDevice device, VkPhysicalDevice physicalDevice, VkDeviceSize size, VkBufferUsageFlags usage, VkMemoryPropertyFlags properties, VkBuffer& buffer, VkDeviceMemory& bufferMemory) { + LOG_DEBUG("Creating buffer with size " + std::to_string(size) + " bytes"); // Validate buffer size if (size == 0) { + LOG_ERROR("Cannot create buffer with size 0"); throw std::runtime_error("Cannot create buffer with size 0"); } diff --git a/src/logging/logger.cpp b/src/logging/logger.cpp new file mode 100644 index 0000000..ce9c3a7 --- /dev/null +++ b/src/logging/logger.cpp @@ -0,0 +1,108 @@ +#include "logging/logger.hpp" + +#include +#include +#include + +namespace sdl3cpp::logging { + +Logger& Logger::GetInstance() { + static Logger instance; + return instance; +} + +Logger::Logger() : level_(LogLevel::INFO), consoleEnabled_(true) {} + +Logger::~Logger() { + if (fileStream_) { + fileStream_->close(); + } +} + +void Logger::SetLevel(LogLevel level) { + level_.store(level, std::memory_order_relaxed); +} + +LogLevel Logger::GetLevel() const { + return level_.load(std::memory_order_relaxed); +} + +void Logger::SetOutputFile(const std::string& filename) { + std::lock_guard lock(mutex_); + if (fileStream_) { + fileStream_->close(); + } + fileStream_ = std::make_unique(filename, std::ios::app); + if (!fileStream_->is_open()) { + // Fallback to console if file can't be opened + std::cerr << "Failed to open log file: " << filename << std::endl; + fileStream_.reset(); + } +} + +void Logger::EnableConsoleOutput(bool enable) { + consoleEnabled_ = enable; +} + +void Logger::Log(LogLevel level, const std::string& message) { + if (level < GetLevel()) { + return; + } + + std::lock_guard lock(mutex_); + std::string formattedMessage = FormatMessage(level, message); + + if (consoleEnabled_) { + WriteToConsole(level, formattedMessage); + } + + if (fileStream_) { + WriteToFile(formattedMessage); + } +} + +void Logger::Log(LogLevel level, const char* message) { + Log(level, std::string(message)); +} + +std::string Logger::LevelToString(LogLevel level) const { + switch (level) { + case LogLevel::TRACE: return "TRACE"; + case LogLevel::DEBUG: return "DEBUG"; + case LogLevel::INFO: return "INFO"; + case LogLevel::WARN: return "WARN"; + case LogLevel::ERROR: return "ERROR"; + default: return "UNKNOWN"; + } +} + +void Logger::WriteToConsole(LogLevel level, const std::string& message) { + if (level >= LogLevel::ERROR) { + std::cerr << message << std::endl; + } else { + std::cout << message << std::endl; + } +} + +void Logger::WriteToFile(const std::string& message) { + if (fileStream_) { + *fileStream_ << message << std::endl; + fileStream_->flush(); + } +} + +std::string Logger::FormatMessage(LogLevel level, const std::string& message) { + auto now = std::chrono::system_clock::now(); + auto time = std::chrono::system_clock::to_time_t(now); + auto ms = std::chrono::duration_cast( + now.time_since_epoch()) % 1000; + + std::ostringstream oss; + oss << std::put_time(std::localtime(&time), "%Y-%m-%d %H:%M:%S") + << '.' << std::setfill('0') << std::setw(3) << ms.count() + << " [" << LevelToString(level) << "] " + << message; + return oss.str(); +} + +} // namespace sdl3cpp::logging \ No newline at end of file diff --git a/src/logging/logger.hpp b/src/logging/logger.hpp new file mode 100644 index 0000000..4c56abc --- /dev/null +++ b/src/logging/logger.hpp @@ -0,0 +1,69 @@ +#ifndef SDL3CPP_LOGGING_LOGGER_HPP +#define SDL3CPP_LOGGING_LOGGER_HPP + +#include +#include +#include +#include +#include +#include +#include + +namespace sdl3cpp::logging { + +enum class LogLevel { + TRACE = 0, + DEBUG = 1, + INFO = 2, + WARN = 3, + ERROR = 4, + OFF = 5 +}; + +class Logger { +public: + static Logger& GetInstance(); + + void SetLevel(LogLevel level); + LogLevel GetLevel() const; + + void SetOutputFile(const std::string& filename); + void EnableConsoleOutput(bool enable); + + void Log(LogLevel level, const std::string& message); + void Log(LogLevel level, const char* message); + + // Convenience methods + void Trace(const std::string& message) { Log(LogLevel::TRACE, message); } + void Debug(const std::string& message) { Log(LogLevel::DEBUG, message); } + void Info(const std::string& message) { Log(LogLevel::INFO, message); } + void Warn(const std::string& message) { Log(LogLevel::WARN, message); } + void Error(const std::string& message) { Log(LogLevel::ERROR, message); } + +private: + Logger(); + ~Logger(); + + Logger(const Logger&) = delete; + Logger& operator=(const Logger&) = delete; + + std::string LevelToString(LogLevel level) const; + std::string FormatMessage(LogLevel level, const std::string& message); + void WriteToConsole(LogLevel level, const std::string& message); + void WriteToFile(const std::string& message); + + std::atomic level_; + bool consoleEnabled_; + std::unique_ptr fileStream_; + std::mutex mutex_; +}; + +#define LOG_TRACE(msg) sdl3cpp::logging::Logger::GetInstance().Trace(msg) +#define LOG_DEBUG(msg) sdl3cpp::logging::Logger::GetInstance().Debug(msg) +#define LOG_INFO(msg) sdl3cpp::logging::Logger::GetInstance().Info(msg) +#define LOG_WARN(msg) sdl3cpp::logging::Logger::GetInstance().Warn(msg) +#define LOG_ERROR(msg) sdl3cpp::logging::Logger::GetInstance().Error(msg) + +} // namespace sdl3cpp::logging + +#endif // SDL3CPP_LOGGING_LOGGER_HPP \ No newline at end of file diff --git a/src/main.cpp b/src/main.cpp index 2572fdc..072333a 100644 --- a/src/main.cpp +++ b/src/main.cpp @@ -21,6 +21,7 @@ #include "app/trace.hpp" #include "app/sdl3_app.hpp" #include +#include "logging/logger.hpp" namespace sdl3cpp::app { std::atomic g_signalReceived{false}; @@ -315,6 +316,15 @@ int main(int argc, char** argv) { try { AppOptions options = ParseCommandLine(argc, argv); sdl3cpp::app::TraceLogger::SetEnabled(options.traceEnabled); + // Initialize logger + auto& logger = sdl3cpp::logging::Logger::GetInstance(); + if (options.traceEnabled) { + logger.SetLevel(sdl3cpp::logging::LogLevel::TRACE); + } else { + logger.SetLevel(sdl3cpp::logging::LogLevel::INFO); + } + logger.EnableConsoleOutput(true); + LOG_INFO("Application starting"); LogRuntimeConfig(options.runtimeConfig); if (options.seedOutput) { WriteRuntimeConfigJson(options.runtimeConfig, *options.seedOutput); @@ -330,7 +340,7 @@ int main(int argc, char** argv) { app.Run(); } catch (const std::runtime_error& e) { std::string errorMsg = e.what(); - std::cerr << "\nERROR: " << errorMsg << '\n'; + LOG_ERROR("Runtime error: " + errorMsg); // Check if this is a timeout/hang error - show simpler message for these bool isTimeoutError = errorMsg.find("timeout") != std::string::npos || @@ -356,7 +366,7 @@ int main(int argc, char** argv) { } return EXIT_FAILURE; } catch (const std::exception& e) { - std::cerr << "\nERROR: " << e.what() << '\n'; + LOG_ERROR("Exception: " + std::string(e.what())); SDL_ShowSimpleMessageBox( SDL_MESSAGEBOX_ERROR, "Application Error",