From 774340edf5cc8f43ca103e374e4db89126d13960 Mon Sep 17 00:00:00 2001 From: baldurk Date: Thu, 5 May 2016 14:48:00 +0200 Subject: [PATCH] Save debug messages per-call in per-thread storage and serialise out * In each entry point we declare a local variable that stays in scope while we call the real function, in the report callback we fill it up with any messages, then when serialising that function we save those messages and on replay restore it out and filter it all back up. --- renderdoc/driver/vulkan/vk_common.h | 2 + renderdoc/driver/vulkan/vk_core.cpp | 191 +++++++++++++++++- renderdoc/driver/vulkan/vk_core.h | 28 ++- renderdoc/driver/vulkan/vk_replay.cpp | 3 +- .../driver/vulkan/wrappers/vk_cmd_funcs.cpp | 1 + .../driver/vulkan/wrappers/vk_queue_funcs.cpp | 14 +- 6 files changed, 228 insertions(+), 11 deletions(-) diff --git a/renderdoc/driver/vulkan/vk_common.h b/renderdoc/driver/vulkan/vk_common.h index 4371eb604..561d21142 100644 --- a/renderdoc/driver/vulkan/vk_common.h +++ b/renderdoc/driver/vulkan/vk_common.h @@ -304,6 +304,8 @@ enum VulkanChunkType CREATE_SWAP_BUFFER, + DEBUG_MESSAGES, + CAPTURE_SCOPE, CONTEXT_CAPTURE_HEADER, CONTEXT_CAPTURE_FOOTER, diff --git a/renderdoc/driver/vulkan/vk_core.cpp b/renderdoc/driver/vulkan/vk_core.cpp index dc709a952..3700de067 100644 --- a/renderdoc/driver/vulkan/vk_core.cpp +++ b/renderdoc/driver/vulkan/vk_core.cpp @@ -153,6 +153,8 @@ const char *VkChunkNames[] = "vkCreateSwapchainKHR", + "Debug Messages", + "Capture", "BeginCapture", "EndCapture", @@ -268,6 +270,7 @@ WrappedVulkan::WrappedVulkan(const char *logFilename) threadSerialiserTLSSlot = Threading::AllocateTLSSlot(); tempMemoryTLSSlot = Threading::AllocateTLSSlot(); + debugMessageSinkTLSSlot = Threading::AllocateTLSSlot(); m_TotalTime = m_AvgFrametime = m_MinFrametime = m_MaxFrametime = 0.0; @@ -510,6 +513,27 @@ string ToStrHelper::Get(const VulkanChunkType &el) return WrappedVulkan::GetChunkName(el); } +WrappedVulkan::ScopedDebugMessageSink::ScopedDebugMessageSink(WrappedVulkan *driver) +{ + driver->SetDebugMessageSink(this); + m_pDriver = driver; +} + +WrappedVulkan::ScopedDebugMessageSink::~ScopedDebugMessageSink() +{ + m_pDriver->SetDebugMessageSink(NULL); +} + +WrappedVulkan::ScopedDebugMessageSink *WrappedVulkan::GetDebugMessageSink() +{ + return (WrappedVulkan::ScopedDebugMessageSink *)Threading::GetTLSValue(debugMessageSinkTLSSlot); +} + +void WrappedVulkan::SetDebugMessageSink(WrappedVulkan::ScopedDebugMessageSink *sink) +{ + Threading::SetTLSValue(debugMessageSinkTLSSlot, (void *)sink); +} + byte *WrappedVulkan::GetTempMemory(size_t s) { TempMem *mem = (TempMem *)Threading::GetTLSValue(tempMemoryTLSSlot); @@ -2070,6 +2094,86 @@ void WrappedVulkan::ReplayLog(uint32_t startEventID, uint32_t endEventID, Replay } } +void WrappedVulkan::Serialise_DebugMessages(Serialiser *localSerialiser, bool isDrawcall) +{ + SCOPED_SERIALISE_CONTEXT(DEBUG_MESSAGES); + + vector debugMessages; + + if(m_State >= WRITING) + { + ScopedDebugMessageSink *sink = GetDebugMessageSink(); + if(sink) + debugMessages.swap(sink->msgs); + } + + SERIALISE_ELEMENT(bool, HasCallstack, isDrawcall && RenderDoc::Inst().GetCaptureOptions().CaptureCallstacksOnlyDraws != 0); + + if(HasCallstack) + { + if(m_State >= WRITING) + { + Callstack::Stackwalk *call = Callstack::Collect(); + + RDCASSERT(call->NumLevels() < 0xff); + + size_t numLevels = call->NumLevels(); + uint64_t *stack = (uint64_t *)call->GetAddrs(); + + localSerialiser->SerialisePODArray("callstack", stack, numLevels); + + delete call; + } + else + { + size_t numLevels = 0; + uint64_t *stack = NULL; + + localSerialiser->SerialisePODArray("callstack", stack, numLevels); + + localSerialiser->SetCallstack(stack, numLevels); + + SAFE_DELETE_ARRAY(stack); + } + } + + SERIALISE_ELEMENT(uint32_t, NumMessages, (uint32_t)debugMessages.size()); + + for(uint32_t i=0; i < NumMessages; i++) + { + ScopedContext msgscope(m_pSerialiser, "DebugMessage", "DebugMessage", 0, false); + + string desc; + if(m_State >= WRITING) + desc = debugMessages[i].description.elems; + + SERIALISE_ELEMENT(uint32_t, Category, debugMessages[i].category); + SERIALISE_ELEMENT(uint32_t, Source, debugMessages[i].source); + SERIALISE_ELEMENT(uint32_t, Severity, debugMessages[i].severity); + SERIALISE_ELEMENT(uint32_t, ID, debugMessages[i].messageID); + SERIALISE_ELEMENT(string, Description, desc); + + if(m_State == READING) + { + DebugMessage msg; + msg.source = (DebugMessageSource)Source; + msg.category = (DebugMessageCategory)Category; + msg.severity = (DebugMessageSeverity)Severity; + msg.messageID = ID; + msg.description = Description; + + m_EventMessages.push_back(msg); + } + } +} + +vector WrappedVulkan::GetDebugMessages() +{ + vector ret; + ret.swap(m_DebugMessages); + return ret; +} + VkBool32 WrappedVulkan::DebugCallback( VkDebugReportFlagsEXT flags, VkDebugReportObjectTypeEXT objectType, @@ -2079,17 +2183,33 @@ VkBool32 WrappedVulkan::DebugCallback( const char* pLayerPrefix, const char* pMessage) { + bool isDS = false, isMEM = false, isSC = false, isOBJ = false, + isSWAP = false, isDL = false, isIMG = false, isPARAM = false; + + if(!strcmp(pLayerPrefix, "DS")) + isDS = true; + else if(!strcmp(pLayerPrefix, "MEM")) + isMEM = true; + else if(!strcmp(pLayerPrefix, "SC")) + isSC = true; + else if(!strcmp(pLayerPrefix, "OBJTRACK")) + isOBJ = true; + else if(!strcmp(pLayerPrefix, "SWAP_CHAIN") || !strcmp(pLayerPrefix, "Swapchain")) + isSWAP = true; + else if(!strcmp(pLayerPrefix, "DL")) + isDL = true; + else if(!strcmp(pLayerPrefix, "Image")) + isIMG = true; + else if(!strcmp(pLayerPrefix, "PARAMCHECK")) + isPARAM = true; + if(m_State < WRITING) { - bool isDS = !strcmp(pLayerPrefix, "DS"); - // All access mask/barrier messages. // These are just too spammy/false positive/unreliable to keep if(isDS && messageCode == 12) return false; - bool isMEM = !strcmp(pLayerPrefix, "MEM"); - // Memory is aliased between image and buffer // ignore memory aliasing warning - we make use of the memory in disjoint ways // and copy image data over separately, so our use is safe @@ -2099,6 +2219,56 @@ VkBool32 WrappedVulkan::DebugCallback( RDCWARN("[%s:%u/%d] %s", pLayerPrefix, (uint32_t)location, messageCode, pMessage); } + else + { + ScopedDebugMessageSink *sink = GetDebugMessageSink(); + + if(sink) + { + DebugMessage msg; + + msg.eventID = 0; + msg.category = eDbgCategory_Miscellaneous; + msg.description = pMessage; + msg.severity = eDbgSeverity_Low; + msg.messageID = messageCode; + msg.source = eDbgSource_API; + + if(flags & VK_DEBUG_REPORT_INFORMATION_BIT_EXT) + msg.severity = eDbgSeverity_Info; + else if(flags & VK_DEBUG_REPORT_DEBUG_BIT_EXT) + msg.severity = eDbgSeverity_Low; + else if(flags & VK_DEBUG_REPORT_WARNING_BIT_EXT) + msg.severity = eDbgSeverity_Medium; + else if(flags & VK_DEBUG_REPORT_ERROR_BIT_EXT) + msg.severity = eDbgSeverity_High; + + if(flags & VK_DEBUG_REPORT_PERFORMANCE_WARNING_BIT_EXT) + msg.category = eDbgCategory_Performance; + else if(isDS) + msg.category = eDbgCategory_Execution; + else if(isMEM) + msg.category = eDbgCategory_Resource_Manipulation; + else if(isSC) + msg.category = eDbgCategory_Shaders; + else if(isOBJ) + msg.category = eDbgCategory_State_Setting; + else if(isSWAP) + msg.category = eDbgCategory_Miscellaneous; + else if(isDL) + msg.category = eDbgCategory_Portability; + else if(isIMG) + msg.category = eDbgCategory_State_Creation; + else if(isPARAM) + msg.category = eDbgCategory_Miscellaneous; + + if(isIMG || isPARAM) + msg.source = eDbgSource_IncorrectAPIUse; + + sink->msgs.push_back(msg); + } + } + return false; } @@ -2401,16 +2571,27 @@ void WrappedVulkan::AddEvent(VulkanChunkType type, string description) create_array(apievent.callstack, stack->NumLevels()); memcpy(apievent.callstack.elems, stack->GetAddrs(), sizeof(uint64_t)*stack->NumLevels()); } + + for(size_t i=0; i < m_EventMessages.size(); i++) + m_EventMessages[i].eventID = apievent.eventID; if(m_LastCmdBufferID != ResourceId()) { m_BakedCmdBufferInfo[m_LastCmdBufferID].curEvents.push_back(apievent); + + vector &msgs = m_BakedCmdBufferInfo[m_LastCmdBufferID].debugMessages; + + msgs.insert(msgs.end(), m_EventMessages.begin(), m_EventMessages.end()); } else { m_RootEvents.push_back(apievent); m_Events.push_back(apievent); + + m_DebugMessages.insert(m_DebugMessages.end(), m_EventMessages.begin(), m_EventMessages.end()); } + + m_EventMessages.clear(); } FetchAPIEvent WrappedVulkan::GetEvent(uint32_t eventID) @@ -2430,4 +2611,4 @@ const FetchDrawcall *WrappedVulkan::GetDrawcall(uint32_t eventID) return NULL; return m_Drawcalls[eventID]; -} +} \ No newline at end of file diff --git a/renderdoc/driver/vulkan/vk_core.h b/renderdoc/driver/vulkan/vk_core.h index 175b60403..61d769640 100644 --- a/renderdoc/driver/vulkan/vk_core.h +++ b/renderdoc/driver/vulkan/vk_core.h @@ -47,7 +47,7 @@ struct VkInitParams : public RDCInitParams void Set(const VkInstanceCreateInfo* pCreateInfo, ResourceId inst); - static const uint32_t VK_SERIALISE_VERSION = 0x0000003; + static const uint32_t VK_SERIALISE_VERSION = 0x0000004; // version number internal to vulkan stream uint32_t SerialiseVersion; @@ -142,6 +142,31 @@ private: friend class VulkanReplay; friend class VulkanDebugManager; + struct ScopedDebugMessageSink + { + ScopedDebugMessageSink(WrappedVulkan *driver); + ~ScopedDebugMessageSink(); + + vector msgs; + WrappedVulkan *m_pDriver; + }; + + friend struct ScopedDebugMessageSink; + +#define SCOPED_DBG_SINK() ScopedDebugMessageSink debug_message_sink(this); + + uint64_t debugMessageSinkTLSSlot; + ScopedDebugMessageSink *GetDebugMessageSink(); + void SetDebugMessageSink(ScopedDebugMessageSink *sink); + + // the messages retrieved for the current event (filled in Serialise_vk...() and read in AddEvent()) + vector m_EventMessages; + + // list of all debug messages by EID in the frame + vector m_DebugMessages; + void Serialise_DebugMessages(Serialiser *localSerialiser, bool isDrawcall); + vector GetDebugMessages(); + enum { eInitialContents_ClearColorImage = 1, eInitialContents_ClearDepthStencilImage, @@ -296,6 +321,7 @@ private: struct BakedCmdBufferInfo { vector curEvents; + vector debugMessages; list drawStack; struct CmdBufferState diff --git a/renderdoc/driver/vulkan/vk_replay.cpp b/renderdoc/driver/vulkan/vk_replay.cpp index cb0edd66d..d0b5738b4 100644 --- a/renderdoc/driver/vulkan/vk_replay.cpp +++ b/renderdoc/driver/vulkan/vk_replay.cpp @@ -649,8 +649,7 @@ FetchFrameRecord VulkanReplay::GetFrameRecord() vector VulkanReplay::GetDebugMessages() { - VULKANNOTIMP("GetDebugMessages"); - return vector(); + return m_pDriver->GetDebugMessages(); } vector VulkanReplay::GetTextures() diff --git a/renderdoc/driver/vulkan/wrappers/vk_cmd_funcs.cpp b/renderdoc/driver/vulkan/wrappers/vk_cmd_funcs.cpp index b1f284f93..b995c724b 100644 --- a/renderdoc/driver/vulkan/wrappers/vk_cmd_funcs.cpp +++ b/renderdoc/driver/vulkan/wrappers/vk_cmd_funcs.cpp @@ -561,6 +561,7 @@ bool WrappedVulkan::Serialise_vkEndCommandBuffer(Serialiser* localSerialiser, Vk { m_BakedCmdBufferInfo[bakeId].draw = m_BakedCmdBufferInfo[m_LastCmdBufferID].draw; m_BakedCmdBufferInfo[bakeId].curEvents = m_BakedCmdBufferInfo[m_LastCmdBufferID].curEvents; + m_BakedCmdBufferInfo[bakeId].debugMessages = m_BakedCmdBufferInfo[m_LastCmdBufferID].debugMessages; m_BakedCmdBufferInfo[bakeId].curEventID = 0; m_BakedCmdBufferInfo[bakeId].eventCount = m_BakedCmdBufferInfo[m_LastCmdBufferID].curEventID; m_BakedCmdBufferInfo[bakeId].drawCount = m_BakedCmdBufferInfo[m_LastCmdBufferID].drawCount; diff --git a/renderdoc/driver/vulkan/wrappers/vk_queue_funcs.cpp b/renderdoc/driver/vulkan/wrappers/vk_queue_funcs.cpp index e11ce03c9..1b28a43e5 100644 --- a/renderdoc/driver/vulkan/wrappers/vk_queue_funcs.cpp +++ b/renderdoc/driver/vulkan/wrappers/vk_queue_funcs.cpp @@ -218,14 +218,22 @@ bool WrappedVulkan::Serialise_vkQueueSubmit( AddEvent(SET_MARKER, name); AddDrawcall(draw, true); m_RootEventID++; + + BakedCmdBufferInfo &cmdBufInfo = m_BakedCmdBufferInfo[cmdIds[c]]; // insert the baked command buffer in-line into this list of notes, assigning new event and drawIDs - InsertDrawsAndRefreshIDs(m_BakedCmdBufferInfo[cmdIds[c]].draw->children, m_RootEventID, m_RootDrawcallID); + InsertDrawsAndRefreshIDs(cmdBufInfo.draw->children, m_RootEventID, m_RootDrawcallID); + + for(size_t i=0; i < cmdBufInfo.debugMessages.size(); i++) + { + m_DebugMessages.push_back(cmdBufInfo.debugMessages[i]); + m_DebugMessages.back().eventID += m_RootEventID; + } m_PartialReplayData.cmdBufferSubmits[cmdIds[c]].push_back(m_RootEventID); - m_RootEventID += m_BakedCmdBufferInfo[cmdIds[c]].eventCount; - m_RootDrawcallID += m_BakedCmdBufferInfo[cmdIds[c]].drawCount; + m_RootEventID += cmdBufInfo.eventCount; + m_RootDrawcallID += cmdBufInfo.drawCount; name = StringFormat::Fmt("=> %s[%u]: vkEndCommandBuffer(%s)", basename.c_str(), c, ToStr::Get(cmdIds[c]).c_str()); draw.name = name;