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.
This commit is contained in:
baldurk
2016-05-05 15:44:19 +02:00
parent b3114bd21d
commit 774340edf5
6 changed files with 228 additions and 11 deletions
+2
View File
@@ -304,6 +304,8 @@ enum VulkanChunkType
CREATE_SWAP_BUFFER,
DEBUG_MESSAGES,
CAPTURE_SCOPE,
CONTEXT_CAPTURE_HEADER,
CONTEXT_CAPTURE_FOOTER,
+186 -5
View File
@@ -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<false, VulkanChunkType>::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<DebugMessage> 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<DebugMessage> WrappedVulkan::GetDebugMessages()
{
vector<DebugMessage> 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<DebugMessage> &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];
}
}
+27 -1
View File
@@ -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<DebugMessage> 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<DebugMessage> m_EventMessages;
// list of all debug messages by EID in the frame
vector<DebugMessage> m_DebugMessages;
void Serialise_DebugMessages(Serialiser *localSerialiser, bool isDrawcall);
vector<DebugMessage> GetDebugMessages();
enum {
eInitialContents_ClearColorImage = 1,
eInitialContents_ClearDepthStencilImage,
@@ -296,6 +321,7 @@ private:
struct BakedCmdBufferInfo
{
vector<FetchAPIEvent> curEvents;
vector<DebugMessage> debugMessages;
list<VulkanDrawcallTreeNode *> drawStack;
struct CmdBufferState
+1 -2
View File
@@ -649,8 +649,7 @@ FetchFrameRecord VulkanReplay::GetFrameRecord()
vector<DebugMessage> VulkanReplay::GetDebugMessages()
{
VULKANNOTIMP("GetDebugMessages");
return vector<DebugMessage>();
return m_pDriver->GetDebugMessages();
}
vector<ResourceId> VulkanReplay::GetTextures()
@@ -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;
@@ -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;