Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

vstest.console.exe on cmd gives - An existing connection was forcibly closed #2324

Closed
mygithub07 opened this issue Feb 11, 2020 · 4 comments
Closed
Assignees

Comments

@mygithub07
Copy link

Description

IMPORTANT: if the defect is reproduced only in a workflow from within the Visual Studio IDE then do not report the issue here - instead, please report it using Visual Studio's "Send Feedback" option that can be accessed from the Help menu OR using this link https://developercommunity.visualstudio.com.

For a defect reproducable from the vstest command line, describe the issue you've observed.

Steps to reproduce

Run vstest.console.exe from command line using below settings and environment
Command:

"C:\Program Files (x86)\Microsoft Visual Studio\2019\TestAgent\Common7\IDE\CommonExtensions\Microsoft\TestWindow\vstest.console.exe" YourExeName.exe /Tests:testName 
/Settings:"C:\Users\..\..\..\app.runsettings" /Diag:"C:\Users\..\..\..\tracelogs.txt"

.runsettings I used
Note: I have tried disabling DataCollectors and MaxCpuCount but the result is same System.IO.IOException as described below

<?xml version="1.0" encoding="utf-8"?>
<RunSettings>
  <!-- Configurations that affect the Test Framework -->
  <RunConfiguration>
     <!--
    <MaxCpuCount>1</MaxCpuCount>
	-->
    <!-- Path relative to solution directory -->
    <ResultsDirectory>.\TestResults</ResultsDirectory>

    <!-- [x86] | x64
      - You can also change it from menu Test, Test Settings, Default Processor Architecture -->
    <TargetPlatform>x64</TargetPlatform>

    <!-- Framework35 | [Framework40] | Framework45 -->
    <TargetFrameworkVersion>.NETFramework,Version=v4.7.2</TargetFrameworkVersion>

    <!-- Path to Test Adapters -->
    <TestAdaptersPaths>C:\Users\..\..\MSTest.TestAdapter.2.1.0\build\_common\</TestAdaptersPaths>
  </RunConfiguration>

  <!-- Configurations for data collectors -->
  <!--
  <DataCollectionRunSettings>
    <DataCollectors>
      <DataCollector friendlyName="Code Coverage" uri="datacollector://Microsoft/CodeCoverage/2.0" assemblyQualifiedName="Microsoft.VisualStudio.Coverage.DynamicCoverageDataCollector, Microsoft.VisualStudio.TraceCollector, Version=11.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a">
        <Configuration>
          <CodeCoverage>
            <ModulePaths>
              <Exclude>
                <ModulePath>.*CPPUnitTestFramework.*</ModulePath>
              </Exclude>
            </ModulePaths>
			-->
            <!-- We recommend you do not change the following values: -->
<!--		
          <UseVerifiableInstrumentation>True</UseVerifiableInstrumentation>
            <AllowLowIntegrityProcesses>True</AllowLowIntegrityProcesses>
            <CollectFromChildProcesses>True</CollectFromChildProcesses>
            <CollectAspDotNet>False</CollectAspDotNet>

          </CodeCoverage>
        </Configuration>
      </DataCollector>

    </DataCollectors>
  </DataCollectionRunSettings>
-->
  <!-- Parameters used by tests at runtime -->
  <TestRunParameters>
    <Parameter name="webAppUrl" value="http://localhost" />
    <Parameter name="webAppUserName" value="Admin" />
    <Parameter name="webAppPassword" value="Password" />
  </TestRunParameters>

  <!-- Adapter Specific sections -->

  <!-- MSTest adapter -->
  <MSTest>
    <MapInconclusiveToFailed>True</MapInconclusiveToFailed>
    <CaptureTraceOutput>True</CaptureTraceOutput>
    <DeleteDeploymentDirectoryAfterTestRunIsComplete>False</DeleteDeploymentDirectoryAfterTestRunIsComplete>
    <DeploymentEnabled>False</DeploymentEnabled>
    <AssemblyResolution>
      <Directory path="C:\Users\..\" includeSubDirectories="false"/>
    </AssemblyResolution>
  </MSTest>

</RunSettings>

Expected behavior

Test should run

Actual behavior

I am seeing System.Net.Sockets.SocketException error in tracelogs. As suggested in some of questions and blogs , I have tried disabling DataCollectors and MaxCpuCount but the result is same as below

Diagnostic logs

Full trace logs:

TcpClientExtensions.MessageLoopAsync: NotifyDataAvailable remoteEndPoint: 127.0.0.1:50691 localEndPoint: 127.0.0.1:50690
TpTrace Error: 0 : 5148, 7, 2020/02/10, 19:55:41.962, 37607744678, vstest.console.exe, Socket: Message loop: failed to receive message due to socket error System.IO.IOException: Unable to read data from the transport connection: An existing connection was forcibly closed by the remote host. ---> System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host
   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.LengthPrefixCommunicationChannel.NotifyDataAvailable()
   at Microsoft.VisualStudio.TestPlatform.CommunicationUtilities.TcpClientExtensions.MessageLoopAsync(TcpClient client, ICommunicationChannel channel, Action`1 errorHandler, CancellationToken cancellationToken), remoteEndPoint: 127.0.0.1:50691 localEndPoint: 127.0.0.1:50690
TpTrace Information: 0 : 5148, 7, 2020/02/10, 19:55:41.962, 37607745086, vstest.console.exe, SocketServer.PrivateStop: Stopp server endPoint: 127.0.0.1:50690 error: System.IO.IOException: Unable to read data from the transport connection: An existing connection was forcibly closed by the remote host. ---> System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host
   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.LengthPrefixCommunicationChannel.NotifyDataAvailable()
   at Microsoft.VisualStudio.TestPlatform.CommunicationUtilities.TcpClientExtensions.MessageLoopAsync(TcpClient client, ICommunicationChannel channel, Action`1 errorHandler, CancellationToken cancellationToken)
TpTrace Verbose: 0 : 5148, 7, 2020/02/10, 19:55:41.962, 37607745490, vstest.console.exe, LengthPrefixCommunicationChannel.Dispose: Dispose reader and writer.
TpTrace Information: 0 : 5148, 7, 2020/02/10, 19:55:41.963, 37607745817, vstest.console.exe, SocketServer.Stop: Raise disconnected event endPoint: 127.0.0.1:50690 error: System.IO.IOException: Unable to read data from the transport connection: An existing connection was forcibly closed by the remote host. ---> System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host
   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.LengthPrefixCommunicationChannel.NotifyDataAvailable()
   at Microsoft.VisualStudio.TestPlatform.CommunicationUtilities.TcpClientExtensions.MessageLoopAsync(TcpClient client, ICommunicationChannel channel, Action`1 errorHandler, CancellationToken cancellationToken)
TpTrace Verbose: 0 : 5148, 7, 2020/02/10, 19:55:41.964, 37607748605, vstest.console.exe, TestRequestSender: OnTestRunAbort: Set operation complete.
TpTrace Verbose: 0 : 5148, 7, 2020/02/10, 19:55:41.964, 37607748828, vstest.console.exe, TestRequestSender.SetOperationComplete: Setting operation complete.
TpTrace Information: 0 : 5148, 7, 2020/02/10, 19:55:41.964, 37607749003, vstest.console.exe, SocketServer.Stop: Stop server endPoint: 127.0.0.1:50690
TpTrace Verbose: 0 : 5148, 7, 2020/02/10, 19:55:41.965, 37607750088, vstest.console.exe, TestRequestSender: GetAbortErrorMessage: Exception: System.IO.IOException: Unable to read data from the transport connection: An existing connection was forcibly closed by the remote host. ---> System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host
   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.LengthPrefixCommunicationChannel.NotifyDataAvailable()
   at Microsoft.VisualStudio.TestPlatform.CommunicationUtilities.TcpClientExtensions.MessageLoopAsync(TcpClient client, ICommunicationChannel channel, Action`1 errorHandler, CancellationToken cancellationToken)
TpTrace Verbose: 0 : 5148, 7, 2020/02/10, 19:55:41.965, 37607750311, vstest.console.exe, TestRequestSender: GetAbortErrorMessage: Client has disconnected. Wait for standard error.
TpTrace Warning: 0 : 5148, 6, 2020/02/10, 19:55:41.968, 37607756565, vstest.console.exe, TestHostManagerCallbacks.ErrorReceivedCallback Test host standard error line: 
TpTrace Error: 0 : 5148, 9, 2020/02/10, 19:55:41.981, 37607782588, vstest.console.exe, TestHostManagerCallbacks.ExitCallBack: Testhost processId: 3800 exited with exitcode: 42 error: ''
TpTrace Information: 0 : 5148, 9, 2020/02/10, 19:55:41.982, 37607782927, vstest.console.exe, TestRequestSender.OnClientProcessExit: Test host process exited. Standard error: 
TpTrace Information: 0 : 5148, 9, 2020/02/10, 19:55:41.982, 37607783119, vstest.console.exe, SocketServer.Stop: Stop server endPoint: 127.0.0.1:50690
TpTrace Information: 0 : 5148, 7, 2020/02/10, 19:55:41.982, 37607783308, vstest.console.exe, TestRequestSender: GetAbortErrorMessage: Received test host error message.
TpTrace Error: 0 : 5148, 7, 2020/02/10, 19:55:41.982, 37607784586, vstest.console.exe, TestRequestSender: Aborting test run because Test host process crashed
TpTrace Verbose: 0 : 5148, 7, 2020/02/10, 19:55:41.983, 37607785511, vstest.console.exe, TestRunRequest:SendTestRunMessage: Starting.
TpTrace Information: 0 : 5148, 7, 2020/02/10, 19:55:41.983, 37607785798, vstest.console.exe, TestRunRequest:SendTestRunMessage: Completed.
TpTrace Warning: 0 : 5148, 7, 2020/02/10, 19:55:42.000, 37607819750, vstest.console.exe, ProxyOperationManager: Timed out waiting for test host to exit. Will terminate process.
TpTrace Verbose: 0 : 5148, 7, 2020/02/10, 19:55:42.022, 37607861508, vstest.console.exe, TestRunRequest:TestRunComplete: Starting. IsAborted:True IsCanceled:False.
TpTrace Warning: 0 : 5148, 7, 2020/02/10, 19:55:42.022, 37607861888, vstest.console.exe, ProxyOperationManager: Timed out waiting for test host to exit. Will terminate process.
TpTrace Verbose: 0 : 5148, 7, 2020/02/10, 19:55:42.022, 37607862322, vstest.console.exe, TestLoggerManager.HandleTestRunComplete: Ignoring as the object is disposed.
TpTrace Information: 0 : 5148, 7, 2020/02/10, 19:55:42.023, 37607863818, vstest.console.exe, TestRunRequest:TestRunComplete: Completed.
TpTrace Verbose: 0 : 5148, 7, 2020/02/10, 19:55:42.023, 37607864031, vstest.console.exe, TcpClientExtensions.MessageLoopAsync: exiting MessageLoopAsync remoteEndPoint: 127.0.0.1:50691 localEndPoint: 127.0.0.1:50690
TpTrace Verbose: 0 : 5148, 1, 2020/02/10, 19:55:42.024, 37607866050, vstest.console.exe, TestRunRequest.Dispose: Starting.
TpTrace Information: 0 : 5148, 1, 2020/02/10, 19:55:42.024, 37607866316, vstest.console.exe, TestRunRequest.Dispose: Completed.
TpTrace Information: 0 : 5148, 1, 2020/02/10, 19:55:42.025, 37607866539, vstest.console.exe, TestRequestManager.RunTests: run tests completed.
TpTrace Verbose: 0 : 5148, 1, 2020/02/10, 19:55:42.025, 37607866902, vstest.console.exe, Executor.Execute: Exiting with exit code of 1

Environment

OS Version : Windows Server 2012 R2 Standard
vstest.console version - 16.0.29724.72

@nohwnd
Copy link
Member

nohwnd commented Feb 14, 2020

Hello, thanks for reporting, are you able to reproduce this after restart? Are could you also try to reproduce this using a newer version of test console, ideally the latest one? The console is shipped in this nuget package that you can extract as a zip file, for example using 7zip. https://www.nuget.org/packages/Microsoft.TestPlatform/16.5.0

@carlosrfernandez
Copy link

Something similar to this happens under MacOS, but the runner just shuts down with Stack Overflow. Using the latest version of the dotnet tools.

I've been able to reproduce this problem using this project: https://github.com/carlosrfernandez/AspNet.Test.StackOverflow

I believe that there's an issue with discovering assemblies at some point in the process. The sample project uses MediatR to register a message request handler and it just fails as soon as it tries to instantiate the handler using reflection.

To reproduce just execute dotnet test using that project in MacOS with dotnet core /aspnet core runtime 3.1.1 (latest)

The crash reports is extensive and I can provide it if it will prove useful.

Note I am using both Microsoft.TestPlatform 16.5 as well as Microsoft.NET.Test.Sdk 16.5...

I'm worried that there's an underlying issue in the runtime somewhere that I can't understand yet...

@nohwnd
Copy link
Member

nohwnd commented Feb 18, 2020

Note to self: This should be the main problem. Seem similar vstest console errors reported when testhost was not able to start because of incorrect setup. See what the exit code means, hopefully not the answer to the ultimate question of life, the universe and everything.

TpTrace Error: 0 : 5148, 9, 2020/02/10, 19:55:41.981, 37607782588, vstest.console.exe, TestHostManagerCallbacks.ExitCallBack: Testhost processId: 3800 exited with exitcode: 42 error: ''

@godrose
Copy link

godrose commented Mar 10, 2020

Same here. What's up with this issue?

@Evangelink Evangelink added needs-triage This item should be discussed in the next triage meeting. and removed needs-triage This item should be discussed in the next triage meeting. labels Jul 26, 2022
@Evangelink Evangelink self-assigned this Jul 27, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

5 participants