Add verbose logging for audit mode

renderdoc/driver/d3d12/d3d12_command_list4_wrap.cpp

@@ -1009,6 +1009,12 @@ bool WrappedID3D12GraphicsCommandList::Serialise_BuildRaytracingAccelerationStru
 
     if(D3D12_Debug_RTAuditing())
     {
+      RDCLOG("Recording %s dynamic build to %llx on %s",
+             AccStructDesc.Inputs.Type == D3D12_RAYTRACING_ACCELERATION_STRUCTURE_TYPE_TOP_LEVEL
+                 ? "tlas"
+                 : "blas",
+             AccStructDesc.DestAccelerationStructureData, ToStr(m_Cmd->m_LastCmdListID).c_str());
+
       ResourceId destASBId;
       D3D12BufferOffset destASBOffset;
 
@@ -1200,6 +1206,15 @@ void WrappedID3D12GraphicsCommandList::BuildRaytracingAccelerationStructure(
     // pre-allocate the AS ID so it can be serialised before the resource is created later on after submission
     ResourceId dstASId = ResourceIDGen::GetNewUniqueID();
 
+    if(D3D12_Debug_RTAuditing())
+    {
+      RDCLOG("%s: Build to %llx, will be %s", ToStr(GetResourceID()).c_str(),
+             pDesc->DestAccelerationStructureData, ToStr(dstASId).c_str());
+
+      for(UINT i = 0; i < NumPostbuildInfoDescs; i++)
+        RDCLOG("   postbuild %s", ToStr(pPostbuildInfoDescs[i].InfoType).c_str());
+    }
+
     // Acceleration structure (AS) are created on buffer created with Acceleration structure init
     // state which helps them differentiate between non-Acceleration structure buffers (non-ASB).
 
@@ -1412,6 +1427,23 @@ void WrappedID3D12GraphicsCommandList::EmitRaytracingAccelerationStructurePostbu
 
   if(IsCaptureMode(m_State))
   {
+    if(D3D12_Debug_RTAuditing())
+    {
+      if(NumSourceAccelerationStructures == 1)
+      {
+        RDCLOG("Emitting %s info from %llx", ToStr(pDesc->InfoType).c_str(),
+               *pSourceAccelerationStructureData);
+      }
+      else
+      {
+        RDCLOG("Emitting %s info", ToStr(pDesc->InfoType).c_str());
+        for(UINT i = 0; i < NumSourceAccelerationStructures; i++)
+        {
+          RDCLOG("  [%u]: %llx", i, pSourceAccelerationStructureData[i]);
+        }
+      }
+    }
+
     CACHE_THREAD_SERIALISER();
     SCOPED_SERIALISE_CHUNK(D3D12Chunk::List_EmitRaytracingAccelerationStructurePostbuildInfo);
     Serialise_EmitRaytracingAccelerationStructurePostbuildInfo(
@@ -1453,6 +1485,12 @@ bool WrappedID3D12GraphicsCommandList::Serialise_CopyRaytracingAccelerationStruc
       {
         ID3D12GraphicsCommandList4 *list = Unwrap4(m_Cmd->RerecordCmdList(m_Cmd->m_LastCmdListID));
 
+        if(D3D12_Debug_RTAuditing())
+        {
+          RDCLOG("Recording copy from %llx to %llx on %s", SourceAccelerationStructureData,
+                 DestAccelerationStructureData, ToStr(m_Cmd->m_LastCmdListID).c_str());
+        }
+
         if(!D3D12_Debug_RTAuditing())
         {
           list->CopyRaytracingAccelerationStructure(DestAccelerationStructureData,
@@ -1469,6 +1507,12 @@ bool WrappedID3D12GraphicsCommandList::Serialise_CopyRaytracingAccelerationStruc
                                                   SourceAccelerationStructureData, Mode);
       }
 
+      if(D3D12_Debug_RTAuditing())
+      {
+        RDCLOG("Recording copy from %llx to %llx on %s", SourceAccelerationStructureData,
+               DestAccelerationStructureData, ToStr(m_Cmd->m_LastCmdListID).c_str());
+      }
+
       m_Cmd->AddEvent();
 
       ActionDescription actionDesc;
@@ -1502,6 +1546,13 @@ void WrappedID3D12GraphicsCommandList::CopyRaytracingAccelerationStructure(
     // pre-allocate the AS ID so it can be serialised before the resource is created later on after submission
     ResourceId dstASId = ResourceIDGen::GetNewUniqueID();
 
+    if(D3D12_Debug_RTAuditing())
+    {
+      RDCLOG("%s: Copy %llx to %llx (%s), will be %s", ToStr(GetResourceID()).c_str(),
+             SourceAccelerationStructureData, DestAccelerationStructureData, ToStr(Mode).c_str(),
+             ToStr(dstASId).c_str());
+    }
+
     {
       CACHE_THREAD_SERIALISER();
       SCOPED_SERIALISE_CHUNK(D3D12Chunk::List_CopyRaytracingAccelerationStructure);

renderdoc/driver/d3d12/d3d12_command_queue_wrap.cpp

@@ -843,6 +843,11 @@ void WrappedID3D12CommandQueue::ExecuteCommandListsInternal(UINT NumCommandLists
       WrappedID3D12GraphicsCommandList *wrapped =
           (WrappedID3D12GraphicsCommandList *)(ppCommandLists[i]);
 
+      if(D3D12_Debug_RTAuditing())
+      {
+        RDCLOG("Submit-callbacks for %s", ToStr(wrapped->GetResourceID()).c_str());
+      }
+
       if(!wrapped->ExecuteImmediateASBuildCallbacks())
       {
         RDCERR("Unable to execute post build for acc struct");

renderdoc/driver/d3d12/d3d12_device.cpp

@@ -52,6 +52,7 @@ RDOC_DEBUG_CONFIG(bool, D3D12_Debug_SingleSubmitFlushing, false,
                   "Every command buffer is submitted and fully flushed to the GPU, to narrow down "
                   "the source of problems.");
 RDOC_DEBUG_CONFIG(bool, D3D12_Debug_RTOverlay, false, "Add some RT tracking to the overlay.");
+RDOC_EXTERN_CONFIG(bool, D3D12_Debug_RTAuditing);
 
 WRAPPED_POOL_INST(WrappedID3D12Device);
 
@@ -3951,6 +3952,33 @@ bool WrappedID3D12Device::Serialise_CreateAS(SerialiserType &ser, ID3D12Resource
     {
       GetResourceManager()->AddLiveResource(asId, accStructAtOffset);
 
+      if(D3D12_Debug_RTAuditing())
+      {
+        RDCLOG("Creating %s AS %s at %s + %llu (%llu bytes): %llx remapped to %llx",
+               type == D3D12_RAYTRACING_ACCELERATION_STRUCTURE_TYPE_BOTTOM_LEVEL ? "blas" : "tlas",
+               ToStr(asId).c_str(),
+               ToStr(GetResourceManager()->GetOriginalID(GetResID(pResource))).c_str(),
+               resourceOffset, byteSize, asbWrappedResource->GetOriginalVA() + resourceOffset,
+               accStructAtOffset->GetVirtualAddress());
+
+        RDCASSERTEQUAL(accStructAtOffset->GetVirtualAddress(),
+                       asbWrappedResource->GetGPUVirtualAddress() + resourceOffset);
+
+        m_ASDebugTracking.update(accStructAtOffset->GetVirtualAddress(),
+                                 accStructAtOffset->GetVirtualAddress() + accStructAtOffset->Size(),
+                                 asId, [](ResourceId x, ResourceId y) {
+                                   if(x == ResourceId())
+                                     return y;
+                                   if(y == ResourceId())
+                                     return x;
+                                   // not necessarily an error if one is stale or overwritten partway
+                                   // through the frame, but something to watch out for in tracking
+                                   RDCWARN("AS Overlap between %s and %s", ToStr(x).c_str(),
+                                           ToStr(y).c_str());
+                                   return x;
+                                 });
+      }
+
       AddResource(asId, ResourceType::AccelerationStructure, "Acceleration Structure");
       // ignored if there's no heap
       DerivedResource(pResource, asId);
@@ -3983,6 +4011,12 @@ void WrappedID3D12Device::CreateAS(ID3D12Resource *pResource, UINT64 resourceOff
   {
     D3D12ResourceRecord *record = as->GetResourceRecord();
 
+    if(D3D12_Debug_RTAuditing())
+    {
+      RDCLOG("Creating %s at %s + %llx (%llx)", ToStr(as->GetResourceID()).c_str(),
+             ToStr(GetResID(pResource)).c_str(), resourceOffset, as->GetVirtualAddress());
+    }
+
     m_HaveSeenASBuild = true;
 
     {

renderdoc/driver/d3d12/d3d12_device.h

@@ -588,6 +588,7 @@ private:
   rdcarray<D3D12ResourceRecord *> m_ForcedReferences;
   Threading::CriticalSection m_ForcedReferencesLock;
   bool m_HaveSeenASBuild = false;
+  Intervals<ResourceId> m_ASDebugTracking;
 
   int64_t m_QueueCounter = 0;
 

renderdoc/driver/d3d12/d3d12_initstate.cpp

@@ -1484,6 +1484,27 @@ bool D3D12ResourceManager::Serialise_InitialState(SerialiserType &ser, ResourceI
               WrappedID3D12Resource *blasASB = GetLiveAs<WrappedID3D12Resource>(blasId);
 
               D3D12AccelerationStructure *blasCheck = NULL;
+
+              // check and log more fine-grained if we're auditing
+              if(D3D12_Debug_RTAuditing())
+              {
+                rdcstr invalid;
+
+                if(blasId == ResourceId() || blasASB == NULL)
+                  invalid = StringFormat::Fmt("Address references non-existant buffer");
+                else if(!blasASB->GetAccStructIfExist(blasOffs, &blasCheck))
+                  invalid = StringFormat::Fmt("No valid AS created at buffer location");
+                else if(blasCheck->Type() == D3D12_RAYTRACING_ACCELERATION_STRUCTURE_TYPE_TOP_LEVEL)
+                  invalid = StringFormat::Fmt("TLAS referenced, assuming overwritten");
+
+                if(!invalid.empty())
+                {
+                  RDCWARN("%s %u: %s", ToStr(id).c_str(), i, invalid.c_str());
+                  instances[i].AccelerationStructure = 0;
+                  continue;
+                }
+              }
+
               if(blasId == ResourceId() || blasASB == NULL ||
                  !blasASB->GetAccStructIfExist(blasOffs, &blasCheck))
               {
@@ -1509,6 +1530,13 @@ bool D3D12ResourceManager::Serialise_InitialState(SerialiserType &ser, ResourceI
                 continue;
               }
 
+              if(D3D12_Debug_RTAuditing())
+              {
+                RDCLOG("%s %u: remapped from %llx to %llx", ToStr(id).c_str(), i,
+                       instances[i].AccelerationStructure,
+                       blasASB->GetGPUVirtualAddress() + blasOffs);
+              }
+
               RDCASSERTEQUAL(blasCheck->GetVirtualAddress(),
                              blasASB->GetGPUVirtualAddress() + blasOffs);
 
@@ -2059,6 +2087,13 @@ void D3D12ResourceManager::Apply_InitialState(ID3D12DeviceChild *live, D3D12Init
       {
         desc.DestAccelerationStructureData = as->GetVirtualAddress();
         list->BuildRaytracingAccelerationStructure(&desc, 0, NULL);
+
+        if(D3D12_Debug_RTAuditing())
+        {
+          RDCLOG("Apply TLAS - Rebuilding %s to %llx",
+                 ToStr(GetOriginalID(as->GetResourceID())).c_str(),
+                 desc.DestAccelerationStructureData);
+        }
       }
       // if we haven't cached it, build and cache the AS then copy into place
       else if(data.cachedBuiltAS == NULL)
@@ -2070,12 +2105,25 @@ void D3D12ResourceManager::Apply_InitialState(ID3D12DeviceChild *live, D3D12Init
         desc.DestAccelerationStructureData = data.cachedBuiltAS->Address();
         list->BuildRaytracingAccelerationStructure(&desc, 0, NULL);
 
+        if(D3D12_Debug_RTAuditing())
+        {
+          RDCLOG("Apply BLAS - Caching %s to %llx", ToStr(GetOriginalID(as->GetResourceID())).c_str(),
+                 desc.DestAccelerationStructureData);
+        }
+
         list->ResourceBarrier(1, &barrier);
 
         // copy to the real location
         list->CopyRaytracingAccelerationStructure(
             as->GetVirtualAddress(), desc.DestAccelerationStructureData,
             D3D12_RAYTRACING_ACCELERATION_STRUCTURE_COPY_MODE_CLONE);
+
+        if(D3D12_Debug_RTAuditing())
+        {
+          RDCLOG("Apply BLAS - Copying %s from %llx to %llx",
+                 ToStr(GetOriginalID(as->GetResourceID())).c_str(),
+                 desc.DestAccelerationStructureData, as->GetVirtualAddress());
+        }
       }
       // if we have a cached AS, just copy from it
       else
@@ -2088,6 +2136,13 @@ void D3D12ResourceManager::Apply_InitialState(ID3D12DeviceChild *live, D3D12Init
         list->CopyRaytracingAccelerationStructure(
             as->GetVirtualAddress(), data.cachedBuiltAS->Address(),
             D3D12_RAYTRACING_ACCELERATION_STRUCTURE_COPY_MODE_CLONE);
+
+        if(D3D12_Debug_RTAuditing())
+        {
+          RDCLOG("Apply BLAS - Copying %s from %llx to %llx",
+                 ToStr(GetOriginalID(as->GetResourceID())).c_str(), data.cachedBuiltAS->Address(),
+                 as->GetVirtualAddress());
+        }
       }
 
       list->ResourceBarrier(1, &barrier);

renderdoc/driver/d3d12/d3d12_manager.cpp

@@ -1068,7 +1068,10 @@ void D3D12RTManager::CheckASCaching()
   {
     ASBuildData *buildData = m_InMemASBuildDatas[i];
 
-    RDCDEBUG("Flushing AS build data of size %llu to disk", buildData->buffer->Size());
+    if(D3D12_Debug_RTAuditing())
+    {
+      RDCDEBUG("Flushing AS build data of size %llu to disk", buildData->buffer->Size());
+    }
 
     // de-interleave positions in geoms here if their stride is greater than vertex format?
     buildData->filename = StringFormat::Fmt(