From 4ea67958cf088455104f19cdc7b542aa30758471 Mon Sep 17 00:00:00 2001 From: shg8 Date: Tue, 20 Feb 2024 22:57:28 -0600 Subject: [PATCH] Robust logging using spdlog --- 3dgs/GSScene.cpp | 8 ++++---- 3dgs/Renderer.cpp | 17 +++++++++++++++-- CMakeLists.txt | 7 +++++++ main.cpp | 27 ++++++++++++++++++--------- vulkan/Buffer.cpp | 1 - vulkan/Swapchain.cpp | 6 ++++++ vulkan/VulkanContext.cpp | 34 +++++++++++++++++++--------------- 7 files changed, 69 insertions(+), 31 deletions(-) diff --git a/3dgs/GSScene.cpp b/3dgs/GSScene.cpp index 9a4caab..c3514be 100644 --- a/3dgs/GSScene.cpp +++ b/3dgs/GSScene.cpp @@ -10,6 +10,7 @@ #include "../vulkan/Utils.h" #include "../vulkan/DescriptorSet.h" #include "../vulkan/pipelines/ComputePipeline.h" +#include "spdlog/spdlog.h" struct VertexStorage { glm::vec3 position; @@ -58,9 +59,8 @@ void GSScene::load(const std::shared_ptr&context) { vertexBuffer->uploadFrom(vertexStagingBuffer); auto endTime = std::chrono::high_resolution_clock::now(); - std::cout << "Loaded " << filename << " in " - << std::chrono::duration_cast(endTime - startTime).count() << "ms" - << std::endl; + spdlog::info("Loaded {} in {}ms", filename, + std::chrono::duration_cast(endTime - startTime).count()); precomputeCov3D(context); } @@ -176,5 +176,5 @@ void GSScene::precomputeCov3D(const std::shared_ptr&context) { commandBuffer->dispatch(numGroups, 1, 1); context->endOneTimeCommandBuffer(std::move(commandBuffer), VulkanContext::Queue::COMPUTE); - std::cout << "Precomputed Cov3D" << std::endl; + spdlog::info("Precomputed Cov3D"); } diff --git a/3dgs/Renderer.cpp b/3dgs/Renderer.cpp index 68162c1..5226332 100644 --- a/3dgs/Renderer.cpp +++ b/3dgs/Renderer.cpp @@ -13,6 +13,8 @@ #include "../vulkan/Utils.h" +#include + #define SORT_ALLOCATE_MULTIPLIER 10 void Renderer::initialize() { @@ -77,7 +79,8 @@ void Renderer::retrieveTimestamps() { } void Renderer::initializeVulkan() { - window = std::make_shared("Vulkan Splatting", 1920, 1080); + spdlog::debug("Initializing Vulkan"); + window = std::make_shared("Vulkan Splatting", 800, 600); context = std::make_shared(Window::getRequiredInstanceExtensions(), std::vector{}, configuration.enableVulkanValidationLayers); @@ -112,6 +115,7 @@ void Renderer::initializeVulkan() { } void Renderer::loadSceneToGPU() { + spdlog::debug("Loading scene to GPU"); scene = std::make_shared(configuration.scene); scene->load(context); @@ -120,6 +124,7 @@ void Renderer::loadSceneToGPU() { } void Renderer::createPreprocessPipeline() { + spdlog::debug("Creating preprocess pipeline"); uniformBuffer = Buffer::uniform(context, sizeof(UniformBuffer)); vertexAttributeBuffer = Buffer::storage(context, scene->getNumVertices() * sizeof(VertexAttributeBuffer), false); tileOverlapBuffer = Buffer::storage(context, scene->getNumVertices() * sizeof(uint32_t), false); @@ -153,6 +158,7 @@ Renderer::Renderer(RendererConfiguration configuration) : configuration(std::mov } void Renderer::createGui() { + spdlog::debug("Creating GUI"); if (!configuration.enableGui) { return; } @@ -163,6 +169,7 @@ void Renderer::createGui() { } void Renderer::createPrefixSumPipeline() { + spdlog::debug("Creating prefix sum pipeline"); prefixSumPingBuffer = Buffer::storage(context, scene->getNumVertices() * sizeof(uint32_t), false); prefixSumPongBuffer = Buffer::storage(context, scene->getNumVertices() * sizeof(uint32_t), false); totalSumBufferHost = Buffer::staging(context, sizeof(uint32_t)); @@ -181,6 +188,7 @@ void Renderer::createPrefixSumPipeline() { } void Renderer::createRadixSortPipeline() { + spdlog::debug("Creating radix sort pipeline"); sortKBufferEven = Buffer::storage(context, scene->getNumVertices() * sizeof(uint64_t) * SORT_ALLOCATE_MULTIPLIER, false); sortKBufferOdd = Buffer::storage(context, scene->getNumVertices() * sizeof(uint64_t) * SORT_ALLOCATE_MULTIPLIER, @@ -239,6 +247,7 @@ void Renderer::createRadixSortPipeline() { } void Renderer::createPreprocessSortPipeline() { + spdlog::debug("Creating preprocess sort pipeline"); preprocessSortPipeline = std::make_shared(context, "preprocess_sort"); auto descriptorSet = std::make_shared(context, FRAMES_IN_FLIGHT); descriptorSet->bindBufferToDescriptorSet(0, vk::DescriptorType::eStorageBuffer, vk::ShaderStageFlagBits::eCompute, @@ -259,6 +268,7 @@ void Renderer::createPreprocessSortPipeline() { } void Renderer::createTileBoundaryPipeline() { + spdlog::debug("Creating tile boundary pipeline"); auto [width, height] = window->getFramebufferSize(); auto tileX = (width + 16 - 1) / 16; auto tileY = (height + 16 - 1) / 16; @@ -280,6 +290,7 @@ void Renderer::createTileBoundaryPipeline() { } void Renderer::createRenderPipeline() { + spdlog::debug("Creating render pipeline"); renderPipeline = std::make_shared(context, "render"); auto inputSet = std::make_shared(context, FRAMES_IN_FLIGHT); inputSet->bindBufferToDescriptorSet(0, vk::DescriptorType::eStorageBuffer, vk::ShaderStageFlagBits::eCompute, @@ -366,7 +377,7 @@ void Renderer::run() { auto now = std::chrono::high_resolution_clock::now(); auto diff = std::chrono::duration_cast(now - lastFpsTime).count(); if (diff > 1000) { - std::cout << "FPS: " << fpsCounter << std::endl; + spdlog::debug("FPS: {}", fpsCounter); fpsCounter = 0; lastFpsTime = now; } else { @@ -400,6 +411,7 @@ void Renderer::run() { } void Renderer::createCommandPool() { + spdlog::debug("Creating command pool"); vk::CommandPoolCreateInfo poolInfo = {}; poolInfo.queueFamilyIndex = context->queues[VulkanContext::Queue::COMPUTE].queueFamily; poolInfo.flags = vk::CommandPoolCreateFlagBits::eResetCommandBuffer; @@ -408,6 +420,7 @@ void Renderer::createCommandPool() { } void Renderer::recordPreprocessCommandBuffer() { + spdlog::debug("Recording preprocess command buffer"); vk::CommandBufferAllocateInfo allocateInfo = {commandPool.get(), vk::CommandBufferLevel::ePrimary, 1}; auto buffers = context->device->allocateCommandBuffersUnique(allocateInfo); preprocessCommandBuffer = std::move(buffers[0]); diff --git a/CMakeLists.txt b/CMakeLists.txt index 9e90087..548c456 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -50,6 +50,12 @@ FetchContent_Declare(libenvpp ) FetchContent_MakeAvailable(libenvpp) +FetchContent_Declare(spdlog + GIT_REPOSITORY https://github.com/gabime/spdlog.git + GIT_TAG v1.13.0 +) +FetchContent_MakeAvailable(spdlog) + FetchContent_Declare(imgui GIT_REPOSITORY https://github.com/ocornut/imgui.git GIT_TAG v1.90.3 @@ -145,6 +151,7 @@ target_include_directories(vulkan_splatting PUBLIC ${glm_SOURCE_DIR} ${imgui_SOURCE_DIR} ${imgui_SOURCE_DIR}/backends + ${spdlog_SOURCE_DIR}/include ) target_link_libraries(vulkan_splatting PUBLIC glfw libenvpp::libenvpp) diff --git a/main.cpp b/main.cpp index 6931d5e..e91db06 100644 --- a/main.cpp +++ b/main.cpp @@ -3,13 +3,17 @@ #include "3dgs/Renderer.h" #include "args.hxx" +#include "spdlog/spdlog.h" int main(int argc, char** argv) { + spdlog::set_pattern("[%H:%M:%S] [%^%L%$] %v"); + args::ArgumentParser parser("Vulkan Splatting"); args::HelpFlag helpFlag{parser, "help", "Display this help menu", {'h', "help"}}; args::Flag validationLayersFlag{ - parser, "validation-layers", "Enable Vulkan validation layers", {'v', "validation-layers"} + parser, "validation-layers", "Enable Vulkan validation layers", {"validation"} }; + args::Flag verboseFlag{parser, "verbose", "Enable verbose logging", {'v', "verbose"}}; args::ValueFlag physicalDeviceIdFlag{ parser, "physical-device", "Select physical device by index", {'d', "device"} }; @@ -31,14 +35,8 @@ int main(int argc, char** argv) { return 0; } catch (const args::ParseError& e) { - std::cerr << e.what() << std::endl; - std::cerr << parser; - return 1; - } - - if (!scenePath) { - std::cerr << "Scene path is required" << std::endl; - std::cerr << parser; + std::cout << e.what() << std::endl; + std::cout << parser; return 1; } @@ -48,6 +46,10 @@ int main(int argc, char** argv) { auto immediateSwapchain = pre.register_variable("IMMEDIATE_SWAPCHAIN"); auto envVars = pre.parse_and_validate(); + if (args::get(verboseFlag)) { + spdlog::set_level(spdlog::level::debug); + } + RendererConfiguration config{ envVars.get_or(validationLayers, false), envVars.get(physicalDeviceId).has_value() @@ -57,6 +59,12 @@ int main(int argc, char** argv) { args::get(scenePath) }; + // check that the scene file exists + if (!std::filesystem::exists(config.scene)) { + spdlog::critical("File does not exist: {}", config.scene); + return 0; + } + if (validationLayersFlag) { config.enableVulkanValidationLayers = args::get(validationLayersFlag); } @@ -81,6 +89,7 @@ int main(int argc, char** argv) { renderer.run(); #ifndef DEBUG } catch (const std::exception& e) { + spdlog::critical(e.what()); std::cout << e.what() << std::endl; return 0; } diff --git a/vulkan/Buffer.cpp b/vulkan/Buffer.cpp index 3abbd46..13bbf1a 100644 --- a/vulkan/Buffer.cpp +++ b/vulkan/Buffer.cpp @@ -103,7 +103,6 @@ void Buffer::downloadTo(std::shared_ptr buffer, vk::DeviceSize srcOffset Buffer::~Buffer() { vmaDestroyBuffer(context->allocator, buffer, allocation); - std::cout << "Destroyed buffer" << std::endl; } std::shared_ptr Buffer::uniform(std::shared_ptr context, uint32_t size, bool concurrentSharing) { diff --git a/vulkan/Swapchain.cpp b/vulkan/Swapchain.cpp index 5c16d8c..1c4b75b 100644 --- a/vulkan/Swapchain.cpp +++ b/vulkan/Swapchain.cpp @@ -1,5 +1,7 @@ #include "Swapchain.h" +#include "spdlog/spdlog.h" + Swapchain::Swapchain(const std::shared_ptr&context, const std::shared_ptr&window, bool immediate) : context( context), window(window), immediate(immediate) { @@ -24,6 +26,7 @@ void Swapchain::createSwapchain() { break; } } + spdlog::debug("Surface format: {}", surfaceFormat.format); presentMode = vk::PresentModeKHR::eFifo; for (const auto&availablePresentMode: presentModes) { @@ -37,6 +40,7 @@ void Swapchain::createSwapchain() { break; } } + spdlog::debug("Present mode: {}", presentMode); auto extent = capabilities.currentExtent; if (capabilities.currentExtent.width == UINT32_MAX) { @@ -87,6 +91,7 @@ void Swapchain::createSwapchain() { swapchainFormat = surfaceFormat.format; swapchain = context->device->createSwapchainKHRUnique(createInfo); + spdlog::debug("Swapchain created"); } void Swapchain::createSwapchainImages() { @@ -120,4 +125,5 @@ void Swapchain::recreate() { createSwapchain(); createSwapchainImages(); + spdlog::debug("Swapchain recreated"); } diff --git a/vulkan/VulkanContext.cpp b/vulkan/VulkanContext.cpp index 9dcbbfa..c89a2bb 100644 --- a/vulkan/VulkanContext.cpp +++ b/vulkan/VulkanContext.cpp @@ -4,23 +4,13 @@ #include #include "Utils.h" +#include VULKAN_HPP_DEFAULT_DISPATCH_LOADER_DYNAMIC_STORAGE VkBool32 debugCallback(VkDebugUtilsMessageSeverityFlagBitsEXT messageSeverity, VkDebugUtilsMessageTypeFlagsEXT messageType, const VkDebugUtilsMessengerCallbackDataEXT* pCallbackData, void* pUserData) { - const char* severity = "???"; - if (messageSeverity & VK_DEBUG_UTILS_MESSAGE_SEVERITY_VERBOSE_BIT_EXT) { - severity = "VERBOSE"; - } else if (messageSeverity & VK_DEBUG_UTILS_MESSAGE_SEVERITY_INFO_BIT_EXT) { - severity = "INFO"; - } else if (messageSeverity & VK_DEBUG_UTILS_MESSAGE_SEVERITY_WARNING_BIT_EXT) { - severity = "WARNING"; - } else if (messageSeverity & VK_DEBUG_UTILS_MESSAGE_SEVERITY_ERROR_BIT_EXT) { - severity = "ERROR"; - } - const char* type = "???"; if (messageType & VK_DEBUG_UTILS_MESSAGE_TYPE_GENERAL_BIT_EXT) { type = "GENERAL"; @@ -30,7 +20,16 @@ VkBool32 debugCallback(VkDebugUtilsMessageSeverityFlagBitsEXT messageSeverity, type = "PERFORMANCE"; } - std::cerr << "[" << severity << "][" << type << "]: " << pCallbackData->pMessage << std::endl; + const char* severity = "???"; + if (messageSeverity & VK_DEBUG_UTILS_MESSAGE_SEVERITY_VERBOSE_BIT_EXT) { + spdlog::debug("[{}]: {}", type, pCallbackData->pMessage); + } else if (messageSeverity & VK_DEBUG_UTILS_MESSAGE_SEVERITY_INFO_BIT_EXT) { + spdlog::info("[{}]: {}", type, pCallbackData->pMessage); + } else if (messageSeverity & VK_DEBUG_UTILS_MESSAGE_SEVERITY_WARNING_BIT_EXT) { + spdlog::warn("[{}]: {}", type, pCallbackData->pMessage); + } else if (messageSeverity & VK_DEBUG_UTILS_MESSAGE_SEVERITY_ERROR_BIT_EXT) { + spdlog::critical("[{}]: {}", type, pCallbackData->pMessage); + } return VK_FALSE; } @@ -92,6 +91,7 @@ void VulkanContext::createInstance() { instance = vk::createInstanceUnique(createInfoChain.get()); VULKAN_HPP_DEFAULT_DISPATCHER.init(*instance); + spdlog::debug("Vulkan instance created"); } bool VulkanContext::isDeviceSuitable(vk::PhysicalDevice device, std::optional surface) { @@ -128,9 +128,11 @@ void VulkanContext::selectPhysicalDevice(std::optional id, std::optiona } auto devices = instance->enumeratePhysicalDevices(); + + spdlog::info("Available physical devices:"); int ind = 0; for (auto& device: devices) { - std::cout << "[" << ind++ << "] " << device.getProperties().deviceName << std::endl; + spdlog::info("[{}] {}", ind++, device.getProperties().deviceName); } if (id.has_value()) { @@ -138,7 +140,7 @@ void VulkanContext::selectPhysicalDevice(std::optional id, std::optiona throw std::runtime_error("Invalid physical device id"); } physicalDevice = devices[id.value()]; - std::cout << "Selected physical device (by index): " << physicalDevice.getProperties().deviceName << std::endl; + spdlog::info("Selected physical device (by index): {}", physicalDevice.getProperties().deviceName); return; } @@ -162,7 +164,7 @@ void VulkanContext::selectPhysicalDevice(std::optional id, std::optiona } } - std::cout << "Selected physical device (automatically): " << physicalDevice.getProperties().deviceName << std::endl; + spdlog::info("Selected physical device (automatically): {}", physicalDevice.getProperties().deviceName); } VulkanContext::QueueFamilyIndices VulkanContext::findQueueFamilies() { @@ -249,6 +251,8 @@ void VulkanContext::createLogicalDevice(vk::PhysicalDeviceFeatures deviceFeature } } + spdlog::debug("Logical device created"); + // Create VMA setupVma(); createCommandPool();