[idd] capture: log committed frame graph

idd/LGIdd/capture/CFrameGraph.cpp

@@ -20,6 +20,8 @@
 
 #include "capture/CFrameGraph.h"
 
+#include "CDebug.h"
+
 #include <cstring>
 
 bool Frame::Same(const GraphCfg& left, const GraphCfg& right)
@@ -64,6 +66,68 @@ bool Frame::Valid(FrameDamage damage, const RECT * rects, unsigned count,
   return false;
 }
 
+static const char * OpName(FrameOp op)
+{
+  switch (op)
+  {
+    case FrameOp::SRC:   return "src";
+    case FrameOp::CAL:   return "cal";
+    case FrameOp::LUT:   return "lut";
+    case FrameOp::SCALE: return "scale";
+    case FrameOp::SDR:   return "sdr";
+    case FrameOp::SCRGB: return "scrgb";
+    case FrameOp::HDR10: return "hdr10";
+  }
+  return "?";
+}
+
+static const char * PixelName(FramePixel pixel)
+{
+  switch (pixel)
+  {
+    case FramePixel::BGRA8:   return "bgra8";
+    case FramePixel::RGBA8:   return "rgba8";
+    case FramePixel::RGB10A2: return "rgb10";
+    case FramePixel::RGBA16F: return "rgba16f";
+  }
+  return "?";
+}
+
+static const char * SignalName(FrameSignal signal)
+{
+  switch (signal)
+  {
+    case FrameSignal::SRGB:         return "srgb";
+    case FrameSignal::PQ_BT2020:    return "pq";
+    case FrameSignal::SCRGB_LINEAR: return "scrgb";
+  }
+  return "?";
+}
+
+static const char * StorageName(FrameStorage storage)
+{
+  switch (storage)
+  {
+    case FrameStorage::D3D11_TEXTURE: return "d3d11";
+    case FrameStorage::D3D12_TEXTURE: return "d3d12";
+    default:                          return "?";
+  }
+}
+
+static void Branch(char * result, const bool * ancestry,
+  unsigned depth, bool last)
+{
+  char * current = result;
+  for (unsigned i = 0; i < depth; ++i)
+  {
+    const char * segment = ancestry[i] ? "   " : "|  ";
+    memcpy(current, segment, 3);
+    current += 3;
+  }
+  memcpy(current, last ? "`- " : "+- ", 3);
+  current[3] = 0;
+}
+
 void CFrameGraph::Reset()
 {
   m_cfg        = GraphCfg {};
@@ -307,6 +371,95 @@ bool CFrameGraph::Stamp(uint64_t generation)
   return true;
 }
 
+void CFrameGraph::LogNode(unsigned node, const GraphRouteName * routes,
+  unsigned routeCount, bool * ancestry, unsigned depth, bool last) const
+{
+  char branch[FRAME_GRAPH_MAX_NODES * 3 + 4];
+  Branch(branch, ancestry, depth, last);
+
+  const GraphNode& item = m_nodes[node];
+  switch (item.op)
+  {
+    case FrameOp::SRC:
+      DEBUG_INFO("%ssrc %s/%s", branch,
+        PixelName(item.profile.pixel), SignalName(item.profile.signal));
+      break;
+
+    case FrameOp::SDR:
+    case FrameOp::SCRGB:
+      DEBUG_INFO("%snative %s", branch, PixelName(item.profile.pixel));
+      break;
+
+    case FrameOp::SCALE:
+      DEBUG_INFO("%sscale %ux%u %s/%s", branch,
+        item.width, item.height, PixelName(item.profile.pixel),
+        SignalName(item.profile.signal));
+      break;
+
+    default:
+      DEBUG_INFO("%s%s %s/%s", branch, OpName(item.op),
+        PixelName(item.profile.pixel), SignalName(item.profile.signal));
+      break;
+  }
+
+  unsigned children = 0;
+  for (unsigned child = 1; child < m_nodeCount; ++child)
+    if (m_nodes[child].refs && m_nodes[child].parent == node)
+      ++children;
+  for (unsigned leaf = 0; leaf < m_leafCount; ++leaf)
+    if (m_leaves[leaf].node == node)
+      ++children;
+
+  ancestry[depth] = last;
+  unsigned emitted = 0;
+  for (unsigned child = 1; child < m_nodeCount; ++child)
+    if (m_nodes[child].refs && m_nodes[child].parent == node)
+      LogNode(child, routes, routeCount, ancestry, depth + 1,
+        ++emitted == children);
+
+  for (unsigned leaf = 0; leaf < m_leafCount; ++leaf)
+  {
+    const GraphLeaf& endpoint = m_leaves[leaf];
+    if (endpoint.node != node)
+      continue;
+
+    const wchar_t * name = L"transport";
+    for (unsigned route = 0; routes && route < routeCount; ++route)
+      if (routes[route].id    == endpoint.id    &&
+          routes[route].epoch == endpoint.epoch &&
+          routes[route].name)
+      {
+        name = routes[route].name;
+        break;
+      }
+
+    Branch(branch, ancestry, depth + 1, ++emitted == children);
+    DEBUG_INFO("%s%ls:%u %s", branch, name, endpoint.id,
+      StorageName(endpoint.cfg.profile.storage));
+  }
+}
+
+void CFrameGraph::Log(const GraphRouteName * routes,
+  unsigned routeCount) const
+{
+  if (!Ready() || routeCount > TRANSPORT_MAX_INSTANCES ||
+      (routeCount && !routes))
+    return;
+
+  const unsigned long long generation =
+    static_cast<unsigned long long>(m_generation);
+  const char * mode = m_cfg.mode == GpuMode::HARDWARE ? "hw" : "sw";
+  if (m_cfg.srcWidth == m_cfg.width && m_cfg.srcHeight == m_cfg.height)
+    DEBUG_INFO("Frame graph g=%llu mode=%s %ux%u", generation, mode,
+      m_cfg.srcWidth, m_cfg.srcHeight);
+  else
+    DEBUG_INFO("Frame graph g=%llu mode=%s %ux%u -> %ux%u",
+      generation, mode, m_cfg.srcWidth, m_cfg.srcHeight,
+      m_cfg.width, m_cfg.height);
+  bool ancestry[FRAME_GRAPH_MAX_NODES] = {};
+  LogNode(0, routes, routeCount, ancestry, 0, true);
+}
+
 bool CFrameGraph::Same(const GraphCfg& cfg) const
 {
   return Ready() && Frame::Same(m_cfg, cfg);

idd/LGIdd/capture/CFrameGraph.h

@@ -96,6 +96,13 @@ struct GraphLeaf
   FrameCfg  cfg;
 };
 
+struct GraphRouteName
+{
+  BackendId      id    = 0;
+  uint32_t       epoch = 0;
+  const wchar_t * name = nullptr;
+};
+
 // All products derived from one capture retain the same immutable content.
 // It contains no acquired IddCx or Direct3D resource.
 struct FrameContent
@@ -148,6 +155,8 @@ private:
     unsigned height,
     const FrameProfile& profile);
   unsigned Checkpoint(const FrameProfile& profile);
+  void LogNode(unsigned node, const GraphRouteName * routes,
+    unsigned routeCount, bool * ancestry, unsigned depth, bool last) const;
 
 public:
   void Reset();
@@ -158,6 +167,7 @@ public:
   bool Seal();
   bool Stamp(uint64_t generation);
   bool Ready() const { return m_sealed && m_generation; }
+  void Log(const GraphRouteName * routes, unsigned routeCount) const;
   bool Same(const GraphCfg& cfg) const;
   const GraphLeaf * FindLeaf(BackendId id, uint32_t epoch, bool tex,
     const FrameCfg& frame) const;

idd/LGIdd/transport/CTransportManager.cpp

@@ -1127,6 +1127,8 @@ CfgResult CTransportManager::Cfg(const GraphCfg& cfg,
     bool                        selected     = false;
     bool                        eligible     = false;
     ITexSink                  * texSink      = nullptr;
+    std::wstring                name;
+    CfgResult                   outcome      = CfgResult::NEXT;
     FrameProfile                profiles[FRAME_PROFILE_MAX] = {};
     unsigned                    profileCount = 0;
   };
@@ -1175,6 +1177,7 @@ CfgResult CTransportManager::Cfg(const GraphCfg& cfg,
       route.required  = entry.required;
       route.primary   = entry.primary;
       route.texSink   = entry.texSink;
+      route.name      = entry.config.kind;
       state           = entry.state;
       frameAbsent     = entry.frameAbsent;
       frameAdded      = entry.frameAdded;
@@ -1186,14 +1189,20 @@ CfgResult CTransportManager::Cfg(const GraphCfg& cfg,
     {
       if (!route.required &&
           (frameAbsent || state == State::FAILED))
+      {
+        if (frameAbsent)
+          route.outcome = CfgResult::REJECTED;
         continue;
+      }
       result = frameAbsent ? CfgResult::REJECTED :
         (state == State::FAILED ? CfgResult::FAILED : CfgResult::RETRY);
+      route.outcome = result;
       break;
     }
     if (route.texSink && !activation)
     {
       route.eligible = false;
+      route.outcome  = CfgResult::REJECTED;
       if (route.required)
       {
         result = CfgResult::REJECTED;
@@ -1309,9 +1318,14 @@ CfgResult CTransportManager::Cfg(const GraphCfg& cfg,
       }
 
       if (route.selected)
+      {
+        route.outcome = CfgResult::ACCEPTED;
         continue;
+      }
 
       route.transport->Abort();
+      route.outcome = routeResult == CfgResult::NEXT ?
+        CfgResult::REJECTED : routeResult;
       if (routeResult == CfgResult::RETRY)
       {
         result = CfgResult::RETRY;
@@ -1319,8 +1333,7 @@ CfgResult CTransportManager::Cfg(const GraphCfg& cfg,
       }
       if (route.required)
       {
-        result = routeResult == CfgResult::NEXT ?
+        result = route.outcome;
-          CfgResult::REJECTED : routeResult;
         break;
       }
     }
@@ -1346,6 +1359,7 @@ CfgResult CTransportManager::Cfg(const GraphCfg& cfg,
       }
 
   bool activationReady = false;
+  bool committed       = false;
   if (result == CfgResult::ACCEPTED && activation)
   {
     result = activation->Prep(next);
@@ -1372,6 +1386,7 @@ CfgResult CTransportManager::Cfg(const GraphCfg& cfg,
     m_tex.Commit(texStage);
     if (activationReady)
       activation->Commit();
+    committed = true;
   }
   else
   {
@@ -1386,6 +1401,27 @@ CfgResult CTransportManager::Cfg(const GraphCfg& cfg,
   for (unsigned i = routeCount; i > 0; --i)
     EndCall(*routes[i - 1].entry, routes[i - 1].transport);
   EndPhase();
+
+  if (committed)
+  {
+    GraphRouteName logRoutes[FRAME_MAX_SINKS];
+    unsigned logRouteCount = 0;
+    for (unsigned route = 0; route < routeCount; ++route)
+      if (routes[route].selected)
+      {
+        GraphRouteName& label = logRoutes[logRouteCount++];
+        label.id    = routes[route].id;
+        label.epoch = routes[route].epoch;
+        label.name  = routes[route].name.c_str();
+      }
+    next.Log(logRoutes, logRouteCount);
+  }
+  if (result == CfgResult::ACCEPTED || result == CfgResult::REJECTED)
+    for (unsigned i = 0; i < routeCount; ++i)
+      if (routes[i].outcome == CfgResult::REJECTED)
+        DEBUG_INFO("Frame route rejected %ls:%u",
+          routes[i].name.empty() ? L"transport" : routes[i].name.c_str(),
+          routes[i].id);
   return result;
 }