Deadlock in datacollector.exe

[actionthomas]

Description

I have a particular project which hangs a test step in an Azure pipeline (On-prem Azure devops server). The build fails after a 1 hour timeout.

Steps to reproduce

Azure devops pipeline with a test task

Expected behavior

Test step completes

Actual behavior

Test step hung

Diagnostic logs

I can have the agent logs. I did a memory dump of datacollector.exe and made an analysis with debugdiag.

The following threads in datacollector.dmp are waiting to enter a .NET Lock

Note: this thread is blocked while also blocking other threads. This can lead to slow performance or deadlocks.( 0 )5,56% of threads blocked (1 threads) The current set of debugger scripts were not able to determine which thread is holding the lock

The following threads in datacollector.dmp are waiting to enter a .NET Lock which is owned by thread 0( 13 14 15 16 17 )27,78% of threads blocked (5 threads) Look at the callstack of thread 0 to see what the thread is waiting on and why it is not releasing the lock.

Entry point	datacollector!COM+_Entry_Point (datacollector+0x435e)
Create time	05/06/2020 18:09:37
Time spent in user mode	0 Days 00:00:00.593
Time spent in kernel mode	0 Days 00:00:00.203
.NET Call Stack

[[GCFrame]]
[[GCFrame]]
[[HelperMethodFrame_1OBJ] (System.Threading.Monitor.Enter)] System.Threading.Monitor.Enter(System.Object)
Microsoft.VisualStudio.TraceCollector.CommonDataCollector+LoggerWrapper.SendMessage(MessageCreator, Boolean)+5d
Microsoft.VisualStudio.TraceCollector.CommonDataCollector.DispatchMessage(MessageCreator)+ee
Microsoft.VisualStudio.TraceCollector.CommonDataCollector.OnSessionEnd(System.Object, Microsoft.VisualStudio.TestPlatform.ObjectModel.DataCollection.SessionEndEventArgs)+a9
[[DebuggerU2MCatchHandlerFrame]]
[[HelperMethodFrame_PROTECTOBJ] (System.RuntimeMethodHandle.InvokeMethod)] System.RuntimeMethodHandle.InvokeMethod(System.Object, System.Object[], System.Signature, Boolean)
mscorlib_ni!System.Reflection.RuntimeMethodInfo.UnsafeInvokeInternal(System.Object, System.Object[], System.Object[])+84
mscorlib_ni!System.Delegate.DynamicInvokeImpl(System.Object[])+a0
Microsoft.VisualStudio.TestPlatform.Utilities.MulticastDelegateUtilities.SafeInvoke(System.Delegate, System.Object, System.EventArgs, System.String)+c2
Microsoft.VisualStudio.TestPlatform.Common.DataCollector.TestPlatformDataCollectionEvents.RaiseEvent(Microsoft.VisualStudio.TestPlatform.ObjectModel.DataCollection.DataCollectionEventArgs)+6a
Microsoft.VisualStudio.TestPlatform.Common.DataCollector.DataCollectionManager.SessionEnded(Boolean)+106
Microsoft.VisualStudio.TestPlatform.CommunicationUtilities.DataCollection.DataCollectionRequestHandler.HandleAfterTestRunEnd(Microsoft.VisualStudio.TestPlatform.CommunicationUtilities.Message)+da
Microsoft.VisualStudio.TestPlatform.CommunicationUtilities.DataCollection.DataCollectionRequestHandler.ProcessRequests()+d1
Microsoft.VisualStudio.TestPlatform.DataCollector.DataCollectorMain.Run(System.String[])+490
Microsoft.VisualStudio.TestPlatform.DataCollector.Program.Main(System.String[])+38
[[GCFrame]]

Environment

Windows Server 2016 / Azure DevOps Agent with build tools 2019 Outil en ligne de commande d'exécution de tests Microsoft (R), version 16.7.0-preview-20200519-01 Microsoft (R) Coverage Collection Tool Version 16.0.30319.200

[nohwnd]

Are you sure it is datacollector causing the issue? It would be more likely that testhost.exe is hanging, are you able to get hang dump of that process if it is still running? It would definitely help to post the diagnostic logs.

[actionthomas]

On the test output, the last lines are

M i c r o s o f t   ( R )   C o v e r a g e   C o l l e c t i o n   T o o l   V e r s i o n   1 6 . 0 . 3 0 3 1 9 . 2 0 0 
 
 
 C o p y r i g h t   ( c )   M i c r o s o f t   C o r p o r a t i o n .     A l l   r i g h t s   r e s e r v e d . 

I added logs on the test execution, and from what I can see the test executes correctly (my [TestInitialize] and [TestCleanup] method are called correctly).

I took dumps oh both vstest.console.exe and datacollector.exe.

Here are the Debugdiag files : reports.zip

[cosminvlad]

I am seeing the same issue with the hosted Azure DevOps. Tests finish running, but datacollector.exe does not exit. A memory dump of the process shows the same call stack as the one shown in the issue description. I can provide the memory dump if needed.

[nohwnd]

@cosminvlad please provide the dump :)

[actionthomas]

@cosminvlad please provide the dump :)

I can do this too. Where do you want me to send the dmp files?

[nohwnd]

Any public share is fine. Or if you want to solve this privately, you should be able to start feedback ticket here, and post comment that is private to Microsoft. https://developercommunity.visualstudio.com/

[actionthomas]

Here they are https://send.firefox.com/download/0f2f00ade063d59f/#QhFiPkZDI8BZOjUnA6gzcg (the password is this issue number without the pound)

[actionthomas]

Since the above link expired, here's a new one with a recent dump (version 16.10.0-release-20210422-02 of vstest) https://1drv.ms/u/s!AmkLUmtsd16u2eka1MnYJXrr2rE6FQ?e=KSDFI4

[Evangelink]

Hey @actionthomas, sorry for the really late reply. Are you still experiencing the issue with newer versions of the Test Platform?

[Evangelink]

I am closing this issue. Feel free to reopen/comment if you are still experiencing any issue.