This morning I was setting up to move some new code I had written as an initial experiment into a new codebase, which is stored using Team Foundation Version Control (TFVC) in Visual Studio Team Services (VSTS). Before I could do that, I needed to go and update my local workspace to the latest version.

Unfortunately, Visual Studio 2017 was not being cooperative, and would get stuck with the “downloading files” dialog open everytime I tried it. So I decided to give TF.exe a try and see if the command line tool was doing the same. It was.

Annoyed with it, and with my search-fu failing me, I decided to attach trusty old WinDBG to the hung instance of TF.exe. What were the threads doing?

DbgId ThreadId ClrThread Apartment Kind       Action
===== ======== ========= ========= ========== ===================================================================================================
    0     31c4   104d2d0 STA                  MonitorWait: Microsoft.TeamFoundation.VersionControl.Client.AsyncOperation.WaitForCompletion(Int32)
    2     1b98   105b6b8 MTA       Finalizer  
    6      6bc   637a078 MTA       Worker     (idle)
    7     2854   637b690           Worker     (idle)
    9     7f10   63adef8 MTA       Background WaitHandle.WaitAny: 0x00000000040708bc
   12      4ec   71f7d00 MTA       IO         
   13     71e4   7232520 MTA       Worker     WaitHandle.WaitOne: 0x0000000003eacd64

Thread 12 didn’t seem to be relevant. Thread 13, however, seemed to be stuck on a file async operation:

DbgId ThreadId Apartment Kind   CLR          GC Mode    GC Suspending?
   13     71e4 MTA       Worker v4.7.2098.00 Preemptive no

WaitHandle.WaitOne
------------------
WaitHandle Type    Microsoft.Win32.SafeHandles.SafeWaitHandle
WaitHandle Address 0x0000000003eacd64

SP       IP       Function
08b5eb44 00000000 HelperMethodFrame_1OBJ [System.Threading.WaitHandle.WaitOneNative(System.Runtime.InteropServices.SafeHandle, UInt32, Boolean, Boolean)]
08b5ec28 72092f71 System.Threading.WaitHandle.InternalWaitOne(System.Runtime.InteropServices.SafeHandle, Int64, Boolean, Boolean)
08b5ec40 72092f38 System.Threading.WaitHandle.WaitOne(Int32, Boolean)
08b5ec54 72092fc2 System.Threading.WaitHandle.WaitOne()
08b5ec5c 720d16d9 System.IO.FileStreamAsyncResult.Wait()
08b5ec7c 7208769b System.IO.FileStream.EndWrite(System.IAsyncResult)
08b5ec8c 720b76ce System.IO.FileStream.FlushWrite(Boolean)
08b5ec9c 721267ee System.IO.FileStream.Dispose(Boolean)
08b5ecbc 72126786 System.IO.Stream.Close()
08b5ecc8 0f48294c Microsoft.TeamFoundation.VersionControl.Client.UploadDownload.DownloadBeginReadCallback(System.IAsyncResult)
08b5ed6c 713e83e9 System.Net.LazyAsyncResult..ctor(System.Object, System.Object, System.AsyncCallback, System.Object)
08b5ed80 713e829b System.Net.ConnectStream.BeginReadWithoutValidation(Byte[], Int32, Int32, System.AsyncCallback, System.Object)
08b5eddc 713e8193 System.Net.ConnectStream.BeginRead(Byte[], Int32, Int32, System.AsyncCallback, System.Object)
08b5ee04 0f483d6c Microsoft.TeamFoundation.VersionControl.Client.UploadDownload.DecompressAndWriteChunk(DownloadAsyncResult)
08b5ee20 0f4839e1 Microsoft.TeamFoundation.VersionControl.Client.UploadDownload.DownloadDestBeginWriteCallback(System.IAsyncResult)
08b5ee4c 720d1867 System.IO.FileStreamAsyncResult.CallUserCallbackWorker()
08b5ee58 720d1838 System.IO.FileStreamAsyncResult+<>c.<CallUserCallback>b__39_0(System.Object)
08b5ee5c 720705c2 System.Threading.QueueUserWorkItemCallback.WaitCallback_Context(System.Object)
08b5ee64 72109a4a System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
08b5eed4 72109956 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
08b5eee8 720714c0 System.Threading.QueueUserWorkItemCallback.System.Threading.IThreadPoolWorkItem.ExecuteWorkItem()
08b5eefc 72070c22 System.Threading.ThreadPoolWorkQueue.Dispatch()
08b5ef4c 72070a8a System.Threading._ThreadPoolWaitCallback.PerformWaitCallback()
08b5f170 00000000 DebuggerU2MCatchHandlerFrame

Looking at the async operation, we see indeed it’s not complete, even after minutes of waiting:

0x03ff028c System.IO.FileStreamAsyncResult
[statics]
  0000  _userCallback           : NULL
  0004  _userStateObject        : NULL
  0008  _waitHandle             : 03ff02bc (System.Threading.ManualResetEvent)
  000c  _handle                 : 03fd7814 (Microsoft.Win32.SafeHandles.SafeFileHandle)
  0010  _overlapped             : 03e90fd8 (System.UIntPtr)
  0014  _EndXxxCalled           : 1 (System.Int32)
  0018  _numBytes               : 0 (System.Int32)
  001c  _errorCode              : 0 (System.Int32)
  0020  _numBufferedBytes       : 0 (System.Int32)
  0024  _isWrite                : True (System.Boolean)
  0025  _isComplete             : False (System.Boolean)
  0026  _completedSynchronously : False (System.Boolean)

So clearly, the hang is happening because the async operation to close one of the .gz files used when downloading changes is never completing.

Where does this leave me? Nowhere, really, since I still have no clue why the file close is never completing. However, spending some quality time in WinDBG sure is better than throwing my laptop out the window!

Up next: Wiping my local workspace and spending 1+ hour downloading everything again.


Tomas Restrepo

Software developer located in Colombia. Sr. PFE at Microsoft.