When WinSCP process stops responding, .NET assembly tries to log its main thread callstack

Source commit: c7d5a02450c4f57138a316e8357dd498226a3c8a

dotnet/GlobalSuppressions.cs

@@ -171,3 +171,5 @@ using System.Diagnostics.CodeAnalysis;
 [assembly: SuppressMessage("Microsoft.Interoperability", "CA1407:AvoidStaticMembersInComVisibleTypes", Scope = "member", Target = "WinSCP.RemotePath.#GetFileName(System.String)")]
 [assembly: SuppressMessage("Microsoft.Interoperability", "CA1409:ComVisibleTypesShouldBeCreatable", Scope = "type", Target = "WinSCP.QueryReceivedEventArgs")]
 [assembly: SuppressMessage("Microsoft.Design", "CA1003:UseGenericEventHandlerInstances", Scope = "type", Target = "WinSCP.QueryReceivedEventHandler")]
+[assembly: SuppressMessage("Microsoft.Security", "CA2122:DoNotIndirectlyExposeMethodsWithLinkDemands", Scope = "member", Target = "WinSCP.ExeSessionProcess.#RequestCallstack()")]
+[assembly: SuppressMessage("Microsoft.Design", "CA1031:DoNotCatchGeneralExceptionTypes", Scope = "member", Target = "WinSCP.ExeSessionProcess.#RequestCallstack()")]

dotnet/Session.cs

@@ -1733,6 +1733,8 @@ namespace WinSCP
 
             if (DateTime.Now - _lastOutput > timeout)
             {
+                Logger.WriteLine("Timeout waiting for WinSCP to respond - asking for callstack");
+                _process.RequestCallstack();
                 string message = "Timeout waiting for WinSCP to respond";
                 if (additional != null)
                 {

dotnet/internal/ExeSessionProcess.cs

@@ -969,6 +969,56 @@ namespace WinSCP
             _logger.WriteLine("{0} - exists [{1}]", executablePath, File.Exists(executablePath));
         }
 
+        public void RequestCallstack()
+        {
+            using (_logger.CreateCallstack())
+            {
+                lock (_lock)
+                {
+                    if (_process == null)
+                    {
+                        _logger.WriteLine("Process is closed already");
+                    }
+                    else
+                    {
+                        try
+                        {
+                            string eventName = string.Format(CultureInfo.InvariantCulture, "WinSCPCallstack{0}", _process.Id);
+                            using (EventWaitHandle ev = EventWaitHandle.OpenExisting(eventName))
+                            {
+                                _logger.WriteLine("Setting event {0}", eventName);
+                                ev.Set();
+                                string callstackFileName = string.Format(CultureInfo.InvariantCulture, "{0}.txt", eventName);
+                                string callstackPath = Path.Combine(Path.GetTempPath(), callstackFileName);
+                                int timeout = 2000;
+                                while (!File.Exists(callstackPath))
+                                {
+                                    if (timeout < 0)
+                                    {
+                                        string message = string.Format(CultureInfo.CurrentCulture, "Timeout waiting for callstack file {0} to be created ", callstackPath);
+                                        throw new TimeoutException(message);
+                                    }
+
+                                    int step = 50;
+                                    timeout -= 50;
+                                    Thread.Sleep(step);
+                                }
+                                _logger.WriteLine("Callstack file {0} has been created", callstackPath);
+                                // allow writting to be finished
+                                Thread.Sleep(100);
+                                _logger.WriteLine(File.ReadAllText(callstackPath));
+                                File.Delete(callstackPath);
+                            }
+                        }
+                        catch (Exception e)
+                        {
+                            _logger.WriteException(e);
+                        }
+                    }
+                }
+            }
+        }
+
         public void Cancel()
         {
             _cancel = true;

source/core/Queue.cpp

@@ -347,11 +347,18 @@ void __fastcall TSimpleThread::WaitFor(unsigned int Milliseconds)
 //---------------------------------------------------------------------------
 // TSignalThread
 //---------------------------------------------------------------------------
-__fastcall TSignalThread::TSignalThread(bool LowPriority) :
+__fastcall TSignalThread::TSignalThread(bool LowPriority, HANDLE Event) :
   TSimpleThread(),
   FTerminated(true), FEvent(NULL)
 {
-  FEvent = CreateEvent(NULL, false, false, NULL);
+  if (Event == NULL)
+  {
+    FEvent = CreateEvent(NULL, false, false, NULL);
+  }
+  else
+  {
+    FEvent = Event;
+  }
   DebugAssert(FEvent != NULL);
 
   if (LowPriority)

source/core/Queue.h

@@ -39,7 +39,7 @@ protected:
   HANDLE FEvent;
   bool FTerminated;
 
-  __fastcall TSignalThread(bool LowPriority);
+  __fastcall TSignalThread(bool LowPriority, HANDLE Event = NULL);
   virtual __fastcall ~TSignalThread();
 
   virtual bool __fastcall WaitForEvent();

source/windows/WinInterface.cpp

@@ -5,6 +5,7 @@
 #include <shlwapi.h>
 
 #include <Common.h>
+#include <Queue.h>
 #include <Exceptions.h>
 #include <CoreMain.h>
 #include <TextsCore.h>
@@ -23,6 +24,7 @@
 #include "GUITools.h"
 #include "JclDebug.hpp"
 #include "JclHookExcept.hpp"
+#include <System.IOUtils.hpp>
 #include <StrUtils.hpp>
 #include <WinApi.h>
 #include "Tools.h"
@@ -1458,12 +1460,72 @@ void __fastcall ClickToolbarItem(TTBCustomItem * Item, bool PositionCursor)
   PostMessage(Toolbar->Handle, WM_LBUTTONDOWN, MK_LBUTTON, MAKELPARAM(X, Y));
 }
 //---------------------------------------------------------------------------
+class TCallstackThread : public TSignalThread
+{
+public:
+  __fastcall TCallstackThread() : TSignalThread(true, DoCreateEvent())
+  {
+  }
+
+protected:
+  virtual void __fastcall ProcessEvent()
+  {
+    try
+    {
+      UnicodeString FileName = FORMAT(L"%s.txt", (DoGetName()));
+      UnicodeString Path = TPath::Combine(SystemTemporaryDirectory(), FileName);
+      std::unique_ptr<TStrings> StackStrings;
+      HANDLE MainThreadHandle = reinterpret_cast<HANDLE>(MainThreadID);
+      if (SuspendThread(MainThreadHandle) < 0)
+      {
+        RaiseLastOSError();
+      }
+      try
+      {
+        TJclStackInfoList * StackInfoList = JclCreateThreadStackTraceFromID(true, MainThreadID);
+        if (StackInfoList == NULL)
+        {
+          RaiseLastOSError();
+        }
+        StackStrings.reset(StackInfoListToStrings(StackInfoList));
+      }
+      __finally
+      {
+        if (ResumeThread(MainThreadHandle) < 0)
+        {
+          RaiseLastOSError();
+        }
+      }
+      TFile::WriteAllText(Path, StackStrings->Text);
+    }
+    catch (...)
+    {
+    }
+  }
+
+private:
+  static UnicodeString DoGetName()
+  {
+    return FORMAT("WinSCPCallstack%d", (GetCurrentProcessId ()));
+  }
+
+  static HANDLE DoCreateEvent()
+  {
+    UnicodeString Name = DoGetName();
+    return CreateEvent(NULL, false, false, Name.c_str());
+  }
+};
+//---------------------------------------------------------------------------
+std::unique_ptr<TCallstackThread> CallstackThread;
+//---------------------------------------------------------------------------
 void __fastcall WinInitialize()
 {
   if (JclHookExceptions())
   {
     JclStackTrackingOptions << stAllModules;
     JclAddExceptNotifier(DoExceptNotify, npFirstChain);
+    CallstackThread.reset(new TCallstackThread());
+    CallstackThread->Start();
   }
 
   SetErrorMode(SEM_FAILCRITICALERRORS);
@@ -1477,6 +1539,7 @@ void __fastcall WinInitialize()
 //---------------------------------------------------------------------------
 void __fastcall WinFinalize()
 {
+  CallstackThread.reset(NULL);
   JclRemoveExceptNotifier(DoExceptNotify);
 }
 //---------------------------------------------------------------------------