Bug 1921759: Log the process that holds the clipboard mutex on Window…

…s a=dmeehan

When Windows keeps us from getting access to the clipboard because another
application is using it, this will report the exe that currently holds the
mutex.

widget/windows/WinUtils.cpp

@@ -7,6 +7,7 @@
 #include "WinUtils.h"
 
 #include <knownfolders.h>
+#include <psapi.h>
 #include <winioctl.h>
 
 #include "gfxPlatform.h"
@@ -2070,6 +2071,21 @@ const char* WinUtils::WinEventToEventName(UINT msg) {
              : nullptr;
 }
 
+nsresult WinUtils::GetProcessImageName(DWORD aProcessId, nsAString& aName) {
+  nsAutoHandle procHandle(
+      ::OpenProcess(PROCESS_QUERY_INFORMATION, FALSE, aProcessId));
+  if (!procHandle) {
+    return NS_ERROR_NOT_AVAILABLE;
+  }
+  wchar_t path[MAX_PATH] = {L'\0'};
+  auto len = ::GetProcessImageFileNameW(procHandle, path, std::size(path));
+  if (!len) {
+    return NS_ERROR_FAILURE;
+  }
+  aName = path;
+  return NS_OK;
+}
+
 // Note to testers and/or test-authors: on Windows 10, and possibly on other
 // versions as well, supplying the `WS_EX_LAYOUTRTL` flag here has no effect
 // whatsoever on child common-dialogs **unless the system UI locale is also set

widget/windows/WinUtils.h

@@ -566,6 +566,8 @@ class WinUtils {
 
   static void GetClipboardFormatAsString(UINT aFormat, nsAString& aOutput);
 
+  static nsresult GetProcessImageName(DWORD aProcessId, nsAString& aName);
+
  private:
   static WhitelistVec BuildWhitelist();
 

widget/windows/nsClipboard.cpp

@@ -393,13 +393,42 @@ static void OleGetClipboardResultToString(const HRESULT aHres,
   }
 }
 
+static void MaybeLogClipboardCurrentOwner(
+    const HRESULT aHres, const mozilla::StaticString& aMethodName) {
+  if (!MOZ_CLIPBOARD_LOG_ENABLED()) {
+    return;
+  }
+  if (aHres != CLIPBRD_E_CANT_OPEN) {
+    return;
+  }
+  auto hwnd = ::GetOpenClipboardWindow();
+  if (!hwnd) {
+    MOZ_CLIPBOARD_LOG(
+        "IDataObject::%s | Clipboard already opened by unknown process",
+        aMethodName.get());
+    return;
+  }
+  DWORD procId;
+  DWORD threadId = ::GetWindowThreadProcessId(hwnd, &procId);
+  NS_ENSURE_TRUE_VOID(threadId);
+  nsAutoString procName;
+  NS_ENSURE_SUCCESS_VOID(
+      mozilla::widget::WinUtils::GetProcessImageName(procId, procName));
+  MOZ_CLIPBOARD_LOG(
+      "IDataObject::%s | Clipboard already opened by HWND: %p | "
+      "Process ID: %lu | Thread ID: %lu | App name: %s",
+      aMethodName.get(), hwnd, procId, threadId,
+      NS_ConvertUTF16toUTF8(procName).get());
+}
+
 // See
 // <https://docs.microsoft.com/en-us/windows/win32/api/ole2/nf-ole2-olegetclipboard>.
 static void LogOleGetClipboardResult(const HRESULT aHres) {
   if (MOZ_CLIPBOARD_LOG_ENABLED()) {
     nsAutoCString hresString;
     OleGetClipboardResultToString(aHres, hresString);
     MOZ_CLIPBOARD_LOG("OleGetClipboard result: %s", hresString.get());
+    MaybeLogClipboardCurrentOwner(aHres, "OleGetClipboard");
   }
 }
 
@@ -438,6 +467,7 @@ static void LogOleSetClipboardResult(const HRESULT aHres) {
     nsAutoCString hresString;
     OleSetClipboardResultToString(aHres, hresString);
     MOZ_CLIPBOARD_LOG("OleSetClipboard result: %s", hresString.get());
+    MaybeLogClipboardCurrentOwner(aHres, "OleSetClipboard");
   }
 }
 
@@ -459,7 +489,9 @@ static HRESULT RepeatedlyTry(Function aFunction, LogFunction aLogFunction,
       break;
     }
 
-    std::this_thread::sleep_for(std::chrono::milliseconds(kDelayInMs));
+    // TODO: This was formerly std::sleep_for, which wasn't actually sleeping
+    // in tests (bug 1927664).
+    ::SleepEx(kDelayInMs, TRUE);
   }
 
   return hres;
@@ -603,12 +635,13 @@ nsresult nsClipboard::GetNativeDataOffClipboard(nsIWidget* aWidget,
 // See methods listed at
 // <https://docs.microsoft.com/en-us/windows/win32/api/objidl/nn-objidl-idataobject#methods>.
 static void LogIDataObjectMethodResult(const HRESULT aHres,
-                                       const nsCString& aMethodName) {
+                                       mozilla::StaticString aMethodName) {
   if (MOZ_CLIPBOARD_LOG_ENABLED()) {
     nsAutoCString hresString;
     IDataObjectMethodResultToString(aHres, hresString);
     MOZ_CLIPBOARD_LOG("IDataObject::%s result : %s", aMethodName.get(),
                       hresString.get());
+    MaybeLogClipboardCurrentOwner(aHres, aMethodName);
   }
 }
 
@@ -623,8 +656,7 @@ static HRESULT RepeatedlyTryGetData(IDataObject& aDataObject, LPFORMATETC pFE,
                                     LPSTGMEDIUM pSTM) {
   return RepeatedlyTry(
       [&aDataObject, &pFE, &pSTM]() { return aDataObject.GetData(pFE, pSTM); },
-      std::bind(LogIDataObjectMethodResult, std::placeholders::_1,
-                "GetData"_ns));
+      [](HRESULT hres) { LogIDataObjectMethodResult(hres, "GetData"); });
 }
 
 //-------------------------------------------------------------------------
@@ -638,7 +670,7 @@ HRESULT nsClipboard::FillSTGMedium(IDataObject* aDataObject, UINT aFormat,
   // memory
   HRESULT hres = S_FALSE;
   hres = aDataObject->QueryGetData(pFE);
-  LogIDataObjectMethodResult(hres, "QueryGetData"_ns);
+  LogIDataObjectMethodResult(hres, "QueryGetData");
   if (S_OK == hres) {
     hres = RepeatedlyTryGetData(*aDataObject, pFE, pSTM);
   }