Vstest: VSTest.console.exe fails due to connection timeout.

[smadala]

Description

• When vstest.console.exe running on slow machines(E.g: Hosted agents), Intermittently it is failing various timeouts.

Following are the various error messages appears.

• Timeout while connecting to testhost.

 Microsoft.VisualStudio.TestPlatform.ObjectModel.TestPlatformException: Failed to initialize client proxy: could not connect to test process.
    at Microsoft.VisualStudio.TestPlatform.CrossPlatEngine.Client.ProxyOperationManager.SetupChannel(IEnumerable`1 sources, CancellationToken cancellationToken)
    at Microsoft.VisualStudio.TestPlatform.CrossPlatEngine.Client.ProxyExecutionManager.StartTestRun(TestRunCriteria testRunCriteria, ITestRunEventsHandler eventHandler)

• Timeout while negotiating protocol with testhost.

Microsoft.VisualStudio.TestPlatform.ObjectModel.TestPlatformException: Failed to negotiate protocol. Wait for response timed out.
   at Microsoft.VisualStudio.TestPlatform.CommunicationUtilities.TestRequestSender.CheckVersionWithTestHost()
   at Microsoft.VisualStudio.TestPlatform.CrossPlatEngine.Client.ProxyOperationManager.SetupChannel(IEnumerable`1 sources, CancellationToken cancellationToken)
   at Microsoft.VisualStudio.TestPlatform.CrossPlatEngine.Client.ProxyExecutionManager.StartTestRun(TestRunCriteria testRunCriteria, ITestRunEventsHandler eventHandler)

• Timeout while connecting to datacollector.

Failed to connect to datacollector process.

• Timeout while datacollector connecting to vstest.console.

System.IO.IOException: Unable to read data from the transport connection: An established connection was aborted by the software in your host machine. ---> System.Net.Sockets.SocketException: An established connection was aborted by the software in your host machine
   at System.Net.Sockets.Socket.Receive(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)
   at System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size)
   --- End of inner exception stack trace ---
   at System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size)
   at System.IO.Stream.ReadByte()
   at System.IO.BinaryReader.ReadByte()
   at System.IO.BinaryReader.Read7BitEncodedInt()
   at System.IO.BinaryReader.ReadString()
   at Microsoft.VisualStudio.TestPlatform.CommunicationUtilities.SocketCommunicationManager.ReceiveMessage()
   at Microsoft.VisualStudio.TestPlatform.CommunicationUtilities.DataCollection.DataCollectionRequestSender.SendBeforeTestRunStartAndGetResult(String settingsXml, ITestMessageEventHandler runEventsHandler)
   at Microsoft.VisualStudio.TestPlatform.CrossPlatEngine.DataCollection.ProxyDataCollectionManager.<>c__DisplayClass16_0.<BeforeTestRunStart>b__0()
   at Microsoft.VisualStudio.TestPlatform.CrossPlatEngine.DataCollection.ProxyDataCollectionManager.InvokeDataCollectionServiceAction(Action action, ITestMessageEventHandler runEventsHandler)
Logging TestHost Diagnostics in file: C:\Users\ICEVSOBuild\AppData\Local\Temp\7e0a0100-37a0-11e8-af1b-8f08e3320c5b.host.18-04-04_00-39-45_31022_1.txt

System.IO.IOException: Unable to write data to the transport connection: An established connection was aborted by the software in your host machine. ---> System.Net.Sockets.SocketException: An established connection was aborted by the software in your host machine
   at System.Net.Sockets.Socket.Send(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)
   at System.Net.Sockets.NetworkStream.Write(Byte[] buffer, Int32 offset, Int32 size)
   --- End of inner exception stack trace ---
   at System.Net.Sockets.NetworkStream.Write(Byte[] buffer, Int32 offset, Int32 size)
   at System.IO.BufferedStream.Flush()
   at System.IO.BinaryWriter.Flush()
   at Microsoft.VisualStudio.TestPlatform.CommunicationUtilities.SocketCommunicationManager.WriteAndFlushToChannel(String rawMessage)
   at Microsoft.VisualStudio.TestPlatform.CommunicationUtilities.SocketCommunicationManager.SendMessage(String messageType, Object payload)
   at Microsoft.VisualStudio.TestPlatform.CommunicationUtilities.DataCollection.DataCollectionRequestSender.SendAfterTestRunStartAndGetResult(ITestMessageEventHandler runEventsHandler, Boolean isCancelled)
   at Microsoft.VisualStudio.TestPlatform.CrossPlatEngine.DataCollection.ProxyDataCollectionManager.<>c__DisplayClass15_0.<AfterTestRunEnd>b__0()
   at Microsoft.VisualStudio.TestPlatform.CrossPlatEngine.DataCollection.ProxyDataCollectionManager.InvokeDataCollectionServiceAction(Action action, ITestMessageEventHandler runEventsHandler)

Steps to reproduce

• Run tests on slowmachines.

Expected behavior

• Show right error message and provide option to increase timeout.

Actual behavior

• No proper error message appears.

More details. here

[smadala]

Fixed in https://github.com/Microsoft/vstest/pull/1538 .
Increased timeout to 90 seconds and made all the connection timeouts configurable by environment variable VSTEST_CONNECTION_TIMEOUT .

[scale-tone]

After adding an integration test to my Azure DevOps Release Pipeline, I am now observing this issue constantly (even though my only one test contains only one WriteLine() line of code). Tried 3 times.
So it is not intermittent.

How do I set that VSTEST_CONNECTION_TIMEOUT variable?
What is the measurement unit of it? Should it be seconds?
Where do I find documentation for this variable?

[scale-tone]

Set that environment variable to 6000.
Validated that it takes effect via a separate pipeline task:

2019-05-18T19:24:40.3660729Z This is the VSTEST Connection Timeout:
2019-05-18T19:24:40.3661744Z 6000

Still constantly getting from Visual Studio Test pipeline task:

2019-05-18T19:24:44.1423502Z [command]"C:\Program Files (x86)\Microsoft Visual Studio\2017\Enterprise\Common7\IDE\CommonExtensions\Microsoft\TestWindow\vstest.console.exe" @D:\a_temp\97305221-79a2-11e9-ad92-83842385922b.txt
2019-05-18T19:24:49.5634020Z Microsoft (R) Test Execution Command Line Tool Version 15.9.1
2019-05-18T19:24:49.5636551Z Copyright (c) Microsoft Corporation. All rights reserved.
2019-05-18T19:24:49.5636604Z
2019-05-18T19:24:49.7310298Z vstest.console.exe
2019-05-18T19:24:49.7310501Z "D:\a\r1\a\WhatIfDemo-Functions\drop\unzipped\bin\WhatIfDemo-Functions.IntegrationTest.dll"
2019-05-18T19:24:49.7310601Z /logger:"trx"
2019-05-18T19:24:49.7310663Z /TestAdapterPath:"D:\a\r1\a"
2019-05-18T19:24:53.1078330Z Starting test execution, please wait...
2019-05-18T19:24:57.2133034Z vstest.console process failed to connect to testhost process after _6000 seconds_. This may occur due to machine slowness, please set environment variable VSTEST_CONNECTION_TIMEOUT to increase timeout.
2019-05-18T19:24:58.4517886Z Results File: D:\a\r1\a\TestResults\VssAdministrator_fv-az606_2019-05-18_19_24_58.trx
2019-05-18T19:24:58.4537177Z
2019-05-18T19:24:58.4550420Z Test Run Aborted.
2019-05-18T19:24:58.5511292Z ##[warning]Vstest failed with error. Check logs for failures. There might be failed tests.
2019-05-18T19:24:58.5689948Z ##[error]Error: The process 'C:\Program Files (x86)\Microsoft Visual Studio\2017\Enterprise\Common7\IDE\CommonExtensions\Microsoft\TestWindow\vstest.console.exe' failed with exit code 1
2019-05-18T19:24:59.1681225Z ##[warning]Invalid results file. Make sure the result format of the file 'D:\a\r1\a\TestResults\VssAdministrator_fv-az606_2019-05-18_19_24_58.trx' matches 'VSTest' test results format.
2019-05-18T19:24:59.1766100Z ##[error]VsTest task failed.

What am I missing?

[jmaragon]

I am observing the same behaviour in one of the agents (out of 5) of our private hosted pool. The only difference is this has Visual Studio 2017 v 15.19.12 and the rest is 15.19.11
Any reason why this bug has been closed?

[mrbcmorris]

@smadala I'm experiencing the same faults as @scale-tone. You can see from his logs that it fails out with this error message well before the defined timeout time.

Appears to have resolved after turning off code coverage. I would like to get coverage enabled again, but at least my pipelines can continue to function wile running tests.

[carlowahlstedt]

@smadala I've got someone in my company who also came to be with the issue. Looks like it might be more wide spread or there's some fix we're not aware of?

[optiks]

I'm hitting this issue in Azure DevOps after upgrading to .NET Core 3.1. Help!?

[A30001835]

Visual Studio 2017 Enterprise Version, Integration Test project with .NET Core 2.2

Same issue here. Could someone help, please?

[code-bringer]

@optiks @A30001835 I am not entirely sure but the following issue looks similar https://github.com/microsoft/vstest/issues/2022
So, it looks like "*.runtimeconfig.json" file is missing