[idd] debug: add additional logging

idd/LGIdd/CIndirectDeviceContext.cpp

@@ -163,13 +163,21 @@ void CIndirectDeviceContext::StopInitRetry()
 
 void CIndirectDeviceContext::InitAdapter()
 {
+  DEBUG_TRACE("InitAdapter");
+
   // The adapter only needs to be created once. D0Entry and the retry timer can
   // both land here, so guard against re-entrancy and repeated creation.
   if (m_adapter)
+  {
+    DEBUG_TRACE("Adapter initialization skipped: adapter already exists");
     return;
+  }
 
   if (InterlockedCompareExchange(&m_initInProgress, 1, 0) != 0)
+  {
+    DEBUG_TRACE("Adapter initialization skipped: initialization already in progress");
     return;
+  }
 
   // At boot the IVSHMEM PCI device may not have enumerated yet. Rather than
   // silently abandoning the adapter (leaving the device loaded but with no
@@ -187,9 +195,18 @@ void CIndirectDeviceContext::InitAdapter()
   }
 
   QueryIddCxCapabilities();
+  DEBUG_TRACE("Loading configured display modes");
   PopulateDefaultModes();
+  DEBUG_TRACE("Initializing monitor EDID");
   InitializeEdid();
 
+  AcquireSRWLockShared(&m_modeLock);
+  const size_t modeCount = m_displayModes.size();
+  const UINT edidSize = m_edid.Size();
+  ReleaseSRWLockShared(&m_modeLock);
+  DEBUG_INFO("Initializing adapter with %llu modes and a %u-byte EDID",
+    (unsigned long long)modeCount, edidSize);
+
   IDDCX_ADAPTER_CAPS caps = {};
   caps.Size = sizeof(caps);
 
@@ -229,7 +246,9 @@ void CIndirectDeviceContext::InitAdapter()
   init.pCaps            = ∩︀
   init.ObjectAttributes = &attr;
 
-  IDARG_OUT_ADAPTER_INIT initOut;
+  IDARG_OUT_ADAPTER_INIT initOut = {};
+  DEBUG_INFO("Calling IddCxAdapterInitAsync with flags 0x%08x",
+    caps.Flags);
   NTSTATUS status = IddCxAdapterInitAsync(&init, &initOut);
   if (!NT_SUCCESS(status) && CanUseIddCx110DDIs())
   {
@@ -250,39 +269,91 @@ void CIndirectDeviceContext::InitAdapter()
   }
 
   m_adapter = initOut.AdapterObject;
-
+  if (!m_adapter)
-  // try to co-exist with the virtual video device by telling IddCx which adapter we prefer to render on
-  IDXGIFactory * factory = NULL;
-  IDXGIAdapter * dxgiAdapter;
-  CreateDXGIFactory(__uuidof(IDXGIFactory), (void **)&factory);
-  for (UINT i = 0; factory->EnumAdapters(i, &dxgiAdapter) != DXGI_ERROR_NOT_FOUND; ++i)
   {
-    DXGI_ADAPTER_DESC adapterDesc;
+    DEBUG_ERROR("IddCxAdapterInitAsync succeeded without returning an adapter object");
-    dxgiAdapter->GetDesc(&adapterDesc);
+    InterlockedExchange(&m_initInProgress, 0);
-    dxgiAdapter->Release();
+    return;
-
+  }
-    if ((adapterDesc.VendorId == 0x1414 && adapterDesc.DeviceId == 0x008c) || // Microsoft Basic Render Driver
+
-        (adapterDesc.VendorId == 0x1b36 && adapterDesc.DeviceId == 0x000d) || // QXL
+  DEBUG_INFO("IddCxAdapterInitAsync started successfully (adapter %p)",
-        (adapterDesc.VendorId == 0x1234 && adapterDesc.DeviceId == 0x1111))   // QEMU Standard VGA
+    m_adapter);
-      continue;
+
-
+  // Try to co-exist with the virtual video device by telling IddCx which
-    IDARG_IN_ADAPTERSETRENDERADAPTER args = {};
+  // hardware adapter we prefer to render on.
-    args.PreferredRenderAdapter = adapterDesc.AdapterLuid;
+  IDXGIFactory * factory = NULL;
-    IddCxAdapterSetRenderAdapter(m_adapter, &args);
+  HRESULT factoryStatus = CreateDXGIFactory(
-    break;
+    __uuidof(IDXGIFactory), (void **)&factory);
+  if (FAILED(factoryStatus))
+    DEBUG_ERROR_HR(factoryStatus, "CreateDXGIFactory Failed");
+  else
+  {
+    bool renderAdapterSelected = false;
+    for (UINT i = 0;; ++i)
+    {
+      IDXGIAdapter * dxgiAdapter = nullptr;
+      HRESULT enumStatus = factory->EnumAdapters(i, &dxgiAdapter);
+      if (enumStatus == DXGI_ERROR_NOT_FOUND)
+        break;
+      if (FAILED(enumStatus))
+      {
+        DEBUG_ERROR_HR(enumStatus, "Failed to enumerate DXGI adapter %u", i);
+        break;
+      }
+
+      DXGI_ADAPTER_DESC adapterDesc = {};
+      HRESULT descStatus = dxgiAdapter->GetDesc(&adapterDesc);
+      dxgiAdapter->Release();
+      if (FAILED(descStatus))
+      {
+        DEBUG_ERROR_HR(descStatus, "Failed to query DXGI adapter %u", i);
+        continue;
+      }
+
+      if (adapterDesc.VendorId == 0x1414 && adapterDesc.DeviceId == 0x008c)
+      {
+        DEBUG_INFO("Ignoring software render adapter %ls", adapterDesc.Description);
+        continue;
+      }
+
+      if ((adapterDesc.VendorId == 0x1b36 && adapterDesc.DeviceId == 0x000d) || // QXL
+          (adapterDesc.VendorId == 0x1234 && adapterDesc.DeviceId == 0x1111))   // QEMU Standard VGA
+      {
+        DEBUG_INFO("Ignoring display-only adapter %ls (vendor 0x%04x, device 0x%04x)",
+          adapterDesc.Description, adapterDesc.VendorId, adapterDesc.DeviceId);
+        continue;
+      }
+
+      DEBUG_INFO("Selecting render adapter %ls (vendor 0x%04x, device 0x%04x)",
+        adapterDesc.Description, adapterDesc.VendorId, adapterDesc.DeviceId);
+      IDARG_IN_ADAPTERSETRENDERADAPTER args = {};
+      args.PreferredRenderAdapter = adapterDesc.AdapterLuid;
+      IddCxAdapterSetRenderAdapter(m_adapter, &args);
+      DEBUG_INFO("Preferred render adapter set");
+      renderAdapterSelected = true;
+      break;
+    }
+
+    if (!renderAdapterSelected)
+      DEBUG_INFO("No preferred hardware render adapter was selected");
+
+    factory->Release();
   }
-  factory->Release();
 
   auto * wrapper = WdfObjectGet_CIndirectDeviceContextWrapper(m_adapter);
   wrapper->context = this;
+  DEBUG_INFO("Adapter context attached; waiting for initialization callback");
 
   // Adapter is up; no need to keep retrying.
   StopInitRetry();
   InterlockedExchange(&m_initInProgress, 0);
+  DEBUG_INFO("Adapter initialization request complete; returning to IddCx");
 }
 
 void CIndirectDeviceContext::FinishInit(UINT connectorIndex)
 {
+  DEBUG_INFO("Creating monitor on connector %u", connectorIndex);
+
   // We support a single monitor; never create a second one if one already
   // exists (a replug must clear m_monitor via departure first).
   AcquireSRWLockExclusive(&m_stateLock);
@@ -303,6 +374,7 @@ void CIndirectDeviceContext::FinishInit(UINT connectorIndex)
   AcquireSRWLockShared(&m_modeLock);
   edid.assign(m_edid.Data(), m_edid.Data() + m_edid.Size());
   ReleaseSRWLockShared(&m_modeLock);
+  DEBUG_INFO("Using %llu-byte monitor EDID", (unsigned long long)edid.size());
 
   IDDCX_MONITOR_INFO info = {};
   info.Size           = sizeof(info);
@@ -314,13 +386,18 @@ void CIndirectDeviceContext::FinishInit(UINT connectorIndex)
   info.MonitorDescription.DataSize = (UINT)edid.size();
   info.MonitorDescription.pData    = edid.empty() ? nullptr : edid.data();
 
-  CoCreateGuid(&info.MonitorContainerId);
+  HRESULT hr = CoCreateGuid(&info.MonitorContainerId);
+  if (FAILED(hr))
+  {
+    DEBUG_ERROR_HR(hr, "Failed to create the monitor container ID");
+    return;
+  }
 
   IDARG_IN_MONITORCREATE create = {};
   create.ObjectAttributes = &attr;
   create.pMonitorInfo     = &info;
 
-  IDARG_OUT_MONITORCREATE createOut;
+  IDARG_OUT_MONITORCREATE createOut = {};
   NTSTATUS status = IddCxMonitorCreate(m_adapter, &create, &createOut);
   if (!NT_SUCCESS(status))
   {
@@ -328,6 +405,8 @@ void CIndirectDeviceContext::FinishInit(UINT connectorIndex)
     return;
   }
 
+  DEBUG_INFO("Monitor object created (%p)", createOut.MonitorObject);
+
   AcquireSRWLockExclusive(&m_stateLock);
   m_monitor = createOut.MonitorObject;
   ReleaseSRWLockExclusive(&m_stateLock);
@@ -335,13 +414,15 @@ void CIndirectDeviceContext::FinishInit(UINT connectorIndex)
   auto * wrapper = WdfObjectGet_CIndirectMonitorContextWrapper(m_monitor);
   wrapper->context = new CIndirectMonitorContext(m_monitor, this);
 
-  IDARG_OUT_MONITORARRIVAL out;
+  IDARG_OUT_MONITORARRIVAL out = {};
   status = IddCxMonitorArrival(m_monitor, &out);
   if (FAILED(status))
   {
     DEBUG_ERROR_HR(status, "IddCxMonitorArrival Failed");
     return;
   }
+
+  DEBUG_INFO("Monitor arrival reported successfully");
 }
 
 void CIndirectDeviceContext::ReplugMonitor()

idd/LGIdd/Device.cpp

@@ -62,18 +62,34 @@ NTSTATUS LGIddDeviceD0Entry(WDFDEVICE device, WDF_POWER_DEVICE_STATE previousSta
 {
   UNREFERENCED_PARAMETER(previousState);
 
+  DEBUG_INFO("Device entered D0, starting adapter initialization");
   auto * wrapper = WdfObjectGet_CIndirectDeviceContextWrapper(device);
   wrapper->context->InitAdapter();
 
+  DEBUG_INFO("Device D0 entry completed");
   return STATUS_SUCCESS;
 }
 
 NTSTATUS LGIddAdapterInitFinished(IDDCX_ADAPTER adapter, const IDARG_IN_ADAPTER_INIT_FINISHED * args)
 {
+  DEBUG_INFO("Adapter initialization callback completed with status 0x%08x",
+    args->AdapterInitStatus);
+
   auto * wrapper = WdfObjectGet_CIndirectDeviceContextWrapper(adapter);
   if (!NT_SUCCESS(args->AdapterInitStatus))
+  {
+    DEBUG_ERROR_HR(args->AdapterInitStatus,
+      "IddCx adapter initialization failed asynchronously");
     return STATUS_SUCCESS;
+  }
 
+  if (!wrapper->context)
+  {
+    DEBUG_ERROR("Adapter initialization completed before its context was attached");
+    return STATUS_INVALID_DEVICE_STATE;
+  }
+
+  DEBUG_INFO("Adapter initialized, creating monitor");
   wrapper->context->FinishInit(0);
   return STATUS_SUCCESS;
 }
@@ -82,6 +98,7 @@ NTSTATUS LGIddAdapterCommitModes(IDDCX_ADAPTER adapter, const IDARG_IN_COMMITMOD
 {
   UNREFERENCED_PARAMETER(adapter);
   UNREFERENCED_PARAMETER(args);
+  DEBUG_INFO("Display modes committed");
   return STATUS_SUCCESS;
 }
 
@@ -158,6 +175,7 @@ NTSTATUS LGIddAdapterCommitModes2(IDDCX_ADAPTER adapter, const IDARG_IN_COMMITMO
 {
   UNREFERENCED_PARAMETER(adapter);
   UNREFERENCED_PARAMETER(args);
+  DEBUG_INFO("Display modes committed through IddCx 1.10");
   return STATUS_SUCCESS;
 }
 
@@ -189,6 +207,7 @@ NTSTATUS LGIddMonitorQueryTargetModes2(IDDCX_MONITOR monitor, const IDARG_IN_QUE
 
 NTSTATUS LGIddMonitorAssignSwapChain(IDDCX_MONITOR monitor, const IDARG_IN_SETSWAPCHAIN* inArgs)
 {
+  DEBUG_INFO("Swap chain assigned to monitor %p", monitor);
   auto * wrapper = WdfObjectGet_CIndirectMonitorContextWrapper(monitor);
   wrapper->context->AssignSwapChain(
     inArgs->hSwapChain, inArgs->RenderAdapterLuid, inArgs->hNextSurfaceAvailable);
@@ -197,6 +216,7 @@ NTSTATUS LGIddMonitorAssignSwapChain(IDDCX_MONITOR monitor, const IDARG_IN_SETSW
 
 NTSTATUS LGIddMonitorUnassignSwapChain(IDDCX_MONITOR monitor)
 {
+  DEBUG_INFO("Swap chain unassigned from monitor %p", monitor);
   auto* wrapper = WdfObjectGet_CIndirectMonitorContextWrapper(monitor);
   wrapper->context->UnassignSwapChain();
   return STATUS_SUCCESS;
@@ -280,5 +300,9 @@ NTSTATUS LGIddCreateDevice(_Inout_ PWDFDEVICE_INIT deviceInit)
   l_wdfDevice = device;
 
   status = IddCxDeviceInitialize(device);
+  if (!NT_SUCCESS(status))
+    DEBUG_ERROR_HR(status, "IddCxDeviceInitialize Failed");
+  else
+    DEBUG_INFO("IddCx device initialized");
   return status;
 }