Control.Invoke() taking very long time

Question

I'm having an issue with a roughly 15y WinForms application, which is being actively maintained. It's being used by around ten companies, each running it on around 5 - 20 clients. Therein we are using a commercial printer driver (PDF X-Change) to create PDFs from printouts, which employs an asynchronous callback mechanism to inform the application that the PDF has been created (or not). The application uses this information to display the PDF file in a window. Basically something like this:

        void pdfCreationStatusCallback(PdfCreationStatusArgs pcsa)
        {
            if (InvokeRequired)
            {
                Invoke(new PdfCreationStatus(pdfCreationStatusCallback), pcsa);
                return;
            }

            displayPdf(pcsa);
        }

A new company started using the software and reported that the application hangs from time to time. Upon debugging I noticed that call to Invoke() sometimes takes between 20 seconds to almost two hours to return! I used remote debugging in combination with .NET Framework debugging (with dotPeek) to see what happens under the hood. I was able to trace it all the way down to the following code in WaitHandle.cs:

    [SecurityCritical]
    internal static bool InternalWaitOne(
      SafeHandle waitableSafeHandle,
      long millisecondsTimeout,
      bool hasThreadAffinity,
      bool exitContext)
    {
      if (waitableSafeHandle == null)
        throw new ObjectDisposedException((string) null, Environment.GetResourceString("ObjectDisposed_Generic"));

      int num = WaitHandle.WaitOneNative(waitableSafeHandle, (uint) millisecondsTimeout, hasThreadAffinity, exitContext);

      if (AppDomainPauseManager.IsPaused)
        AppDomainPauseManager.ResumeEvent.WaitOneWithoutFAS();

      if (num == 128)
        WaitHandle.ThrowAbandonedMutexException();

      return num != 258;
    }

Here I noticed that on a "healthy" system the call to WaitHandle.WaitOneNative(...) returns 0, thus the method returns true and all is good. On the affected system WaitHandle.WaitOneNative(...) returns 258 (after 1000 ms, which is the value of millisecondsTimeout), thus the method returns false. The method calling InternalWaitOne(..) then calls it in a loop for as long as it takes for WaitHandle.WaitOneNative(...) to finally return a value other than 258 (which as stated above, can even take two hours). My problem is, that I couldn't find the source code to WaitOneNative(..), only the following declaration:

    [SecurityCritical]
    [MethodImpl(MethodImplOptions.InternalCall)]
    private static extern int WaitOneNative(
      SafeHandle waitableSafeHandle,
      uint millisecondsTimeout,
      bool hasThreadAffinity,
      bool exitContext);

When I set a breakpoint at the line int num = WaitHandle.WaitOneNative(..) I have two threads which both hit that spot, both returning num = 258:

This is the stacktrace for the PDF-creating callback function (_pdfPrinter_OnFileSaved):

>   mscorlib.dll!System.Threading.WaitHandle.InternalWaitOne(System.Runtime.InteropServices.SafeHandle waitableSafeHandle, long millisecondsTimeout, bool hasThreadAffinity, bool exitContext) Line 193 C#
    mscorlib.dll!System.Threading.WaitHandle.WaitOne(int millisecondsTimeout, bool exitContext) Line 125    C#
    System.Windows.Forms.dll!System.Windows.Forms.Control.WaitForWaitHandle(System.Threading.WaitHandle waitHandle) Line 2788   C#
    System.Windows.Forms.dll!System.Windows.Forms.Control.MarshaledInvoke(System.Windows.Forms.Control caller, System.Delegate method, object[] args, bool synchronous) Line 4825   C#
    System.Windows.Forms.dll!System.Windows.Forms.Control.Invoke(System.Delegate method, object[] args) Line 4551   C#
    GUISubsystem.dll!GUISubsystem.CalculationForms.Printouts.PrintoutAnbotsartikel.FrmAnbotsartikelDruckParameter.pdfCreationStatusCallback(PdfCreationStatusArgs pcsa) Line 597    C#
    PrinterSubsystem.dll!PrinterSubsystem.PrintingManager._pdfPrinter_OnFileSaved(int jobID, string fileName) Line 885  C#
    [Übergang von Nativ zu Verwaltet]   
    [Übergang von Verwaltet zu Nativ]   
    mscorlib.dll!System.Delegate.DynamicInvokeImpl(object[] args) Line 113  C#
    mscorlib.dll!System.Runtime.InteropServices.ComEventsMethod.DelegateWrapper.Invoke(object[] args) Line 158  C#
    mscorlib.dll!System.Runtime.InteropServices.ComEventsMethod.Invoke(object[] args) Line 121  C#
    mscorlib.dll!System.Runtime.InteropServices.ComEventsSink.System.Runtime.InteropServices.NativeMethods.IDispatch.Invoke(int dispid, ref System.Guid riid, int lcid, System.Runtime.InteropServices.ComTypes.INVOKEKIND wFlags, ref System.Runtime.InteropServices.ComTypes.DISPPARAMS pDispParams, System.IntPtr pvarResult, System.IntPtr pExcepInfo, System.IntPtr puArgErr) Line 153 C#

This is the stacktrace of the other thread (looks like the main message loop):

>   mscorlib.dll!System.Threading.WaitHandle.InternalWaitOne(System.Runtime.InteropServices.SafeHandle waitableSafeHandle, long millisecondsTimeout, bool hasThreadAffinity, bool exitContext) Line 193 C#
    mscorlib.dll!System.Threading.WaitHandle.WaitOne(int millisecondsTimeout, bool exitContext) Line 125    C#
    System.Windows.Forms.dll!System.Windows.Forms.Control.WaitForWaitHandle(System.Threading.WaitHandle waitHandle) Line 2793   C#
    System.Windows.Forms.dll!System.Windows.Forms.Control.MarshaledInvoke(System.Windows.Forms.Control caller, System.Delegate method, object[] args, bool synchronous) Line 4825   C#
    System.Windows.Forms.dll!System.Windows.Forms.Control.Invoke(System.Delegate method, object[] args) Line 4551   C#
    System.Windows.Forms.dll!System.Windows.Forms.WindowsFormsSynchronizationContext.Send(System.Threading.SendOrPostCallback d, object state) Line 74  C#
    System.dll!Microsoft.Win32.SystemEvents.SystemEventInvokeInfo.Invoke(bool checkFinalization, object[] args) Line 1272   C#
    System.dll!Microsoft.Win32.SystemEvents.RaiseEvent(bool checkFinalization, object key, object[] args) Line 970  C#
    System.dll!Microsoft.Win32.SystemEvents.OnUserPreferenceChanged(int msg, System.IntPtr wParam, System.IntPtr lParam) Line 728   C#
    System.dll!Microsoft.Win32.SystemEvents.WindowProc(System.IntPtr hWnd, int msg, System.IntPtr wParam, System.IntPtr lParam) Line 1130   C#
    [Übergang von Nativ zu Verwaltet]   
    [Übergang von Verwaltet zu Nativ]   
    System.Windows.Forms.dll!System.Windows.Forms.Application.ComponentManager.System.Windows.Forms.UnsafeNativeMethods.IMsoComponentManager.FPushMessageLoop(System.IntPtr dwComponentID, int reason, int pvLoopData) Line 1258    C#
    System.Windows.Forms.dll!System.Windows.Forms.Application.ThreadContext.RunMessageLoopInner(int reason, System.Windows.Forms.ApplicationContext context) Line 2042  C#
    System.Windows.Forms.dll!System.Windows.Forms.Application.ThreadContext.RunMessageLoop(int reason, System.Windows.Forms.ApplicationContext context) Line 1982   C#
    System.Windows.Forms.dll!System.Windows.Forms.Application.Run(System.Windows.Forms.Form mainForm) Line 988  C#
    MainEntry.exe!MainEntry.Main(string[] args) Line 118    C#

An additional observation: it only takes this long the first time Invoke() (and thus WaitOneNative()) is called. Once WaitOneNative() returns 0 (instead of 258) the application runs without any delays. This is "reset" once the application is restarted. This is the first time and the first company that is experiencing this problem on 3/7 clients. One of the clients is using Windows 10, the other two Windows 8.1 with the .Net Framework 4.8. Our application is targeting .Net Framework 4.5.

Can anybody tell me where I can find the source code for static extern int WaitOneNative(..), such that I can further investigate what it's waiting for? And/or does anybody have a hint what might be going on here, ie. what WaitOnNative() could be waiting for between a few seconds up to hours? What should I be looking for in the stacktraces, threads, etc.?

Control.Invoke() taking very long time

Answers (1)

Related Questions