feat: Implement logging system and integrate into application

This commit is contained in:
2026-01-04 00:10:20 +00:00
parent e9b944680c
commit 33ca375034
9 changed files with 222 additions and 37 deletions

View File

@@ -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)

View File

@@ -1,6 +1,7 @@
#include "app/audio_player.hpp"
#include "app/sdl3_app.hpp"
#include "app/trace.hpp"
#include "logging/logger.hpp"
#include <atomic>
#include <chrono>
@@ -166,7 +167,7 @@ void Sdl3App::InitSDL() {
audioPlayer_ = std::make_unique<AudioPlayer>();
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<std::chrono::seconds>(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<std::chrono::seconds>(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<std::chrono::seconds>(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;
}
}

View File

@@ -1,5 +1,6 @@
#include "app/sdl3_app.hpp"
#include "app/trace.hpp"
#include "logging/logger.hpp"
#include <set>
#include <stdexcept>
@@ -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();

View File

@@ -1,5 +1,6 @@
#include "app/sdl3_app.hpp"
#include "app/trace.hpp"
#include "logging/logger.hpp"
#include <limits>
#include <stdexcept>
@@ -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;

View File

@@ -1,6 +1,7 @@
#include "app/sdl3_app.hpp"
#include "app/trace.hpp"
#include "app/vulkan_api.hpp"
#include "logging/logger.hpp"
#include <stdexcept>
@@ -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();

View File

@@ -1,4 +1,5 @@
#include "app/vulkan_api.hpp"
#include "logging/logger.hpp"
#include <algorithm>
#include <stdexcept>
@@ -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");
}

108
src/logging/logger.cpp Normal file
View File

@@ -0,0 +1,108 @@
#include "logging/logger.hpp"
#include <chrono>
#include <iomanip>
#include <thread>
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<std::mutex> lock(mutex_);
if (fileStream_) {
fileStream_->close();
}
fileStream_ = std::make_unique<std::ofstream>(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<std::mutex> 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<std::chrono::milliseconds>(
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

69
src/logging/logger.hpp Normal file
View File

@@ -0,0 +1,69 @@
#ifndef SDL3CPP_LOGGING_LOGGER_HPP
#define SDL3CPP_LOGGING_LOGGER_HPP
#include <atomic>
#include <iostream>
#include <sstream>
#include <string>
#include <mutex>
#include <fstream>
#include <memory>
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<LogLevel> level_;
bool consoleEnabled_;
std::unique_ptr<std::ofstream> 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

View File

@@ -21,6 +21,7 @@
#include "app/trace.hpp"
#include "app/sdl3_app.hpp"
#include <SDL3/SDL_main.h>
#include "logging/logger.hpp"
namespace sdl3cpp::app {
std::atomic<bool> 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",