TFS 测试构建缓慢,在 "vstest.console.exe, TcpClientExtensions.MessageLoopAsync: Polling on remoteEndPoint:" 上挂起几分钟

TFS test build slow, hangs on "vstest.console.exe, TcpClientExtensions.MessageLoopAsync: Polling on remoteEndPoint:" for minutes

我有一个大约 250 个测试用例的构建定义,这些测试用例已经开始 运行 测试用例真的很慢。它 运行 将近 100 个测试用例,最终每个测试用例花费约 8 分钟。此时有超过 100 个测试用例,这不是我们可以忍受的。 我设法在服务器上获得一些日志记录,一旦它开始变慢,它就会记录在诊断日志中:

...
9060, 5, 2019/05/03, 09:52:32.127, 179576170847, vstest.console.exe, TestRunRequest:SendTestRunStatsChange: Completed.
...
18356, 5, 2019/05/03, 09:59:27.108, 169578763371, vstest.console.exe, TcpClientExtensions.MessageLoopAsync: Polling on remoteEndPoint: 127.0.0.1:51949 localEndPoint: 127.0.0.1:51948
18356, 5, 2019/05/03, 09:59:28.108, 169581006890, vstest.console.exe, TcpClientExtensions.MessageLoopAsync: Polling on remoteEndPoint: 127.0.0.1:51949 localEndPoint: 127.0.0.1:51948
18356, 5, 2019/05/03, 09:59:29.108, 169583250453, vstest.console.exe, TcpClientExtensions.MessageLoopAsync: Polling on remoteEndPoint: 127.0.0.1:51949 localEndPoint: 127.0.0.1:51948
18356, 5, 2019/05/03, 09:59:30.108, 169585493854, vstest.console.exe, TcpClientExtensions.MessageLoopAsync: Polling on remoteEndPoint: 127.0.0.1:51949 localEndPoint: 127.0.0.1:51948
...

并且在主机日志中:


...
TpTrace Verbose: 0 : 18304, 9, 2019/05/03, 09:59:28.405, 169581673025, testhost.exe, TcpClientExtensions.MessageLoopAsync: Polling on remoteEndPoint: 127.0.0.1:51948 localEndPoint: 127.0.0.1:51949
TpTrace Verbose: 0 : 18304, 9, 2019/05/03, 09:59:29.405, 169583916411, testhost.exe, TcpClientExtensions.MessageLoopAsync: Polling on remoteEndPoint: 127.0.0.1:51948 localEndPoint: 127.0.0.1:51949
TpTrace Verbose: 0 : 18304, 9, 2019/05/03, 09:59:30.405, 169586159896, testhost.exe, TcpClientExtensions.MessageLoopAsync: Polling on remoteEndPoint: 127.0.0.1:51948 localEndPoint: 127.0.0.1:51949
TpTrace Verbose: 0 : 18304, 9, 2019/05/03, 09:59:30.936, 169587383747, testhost.exe, TcpClientExtensions.MessageLoopAsync: NotifyDataAvailable remoteEndPoint: 127.0.0.1:51948 localEndPoint: 127.0.0.1:51949
TpTrace Error: 0 : 18304, 9, 2019/05/03, 09:59:30.983, 169587459527, testhost.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.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:51948 localEndPoint: 127.0.0.1:51949
TpTrace Information: 0 : 18304, 9, 2019/05/03, 09:59:30.983, 169587461935, testhost.exe, SocketClient.PrivateStop: Stop communication from server endpoint: 127.0.0.1:051948, 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.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 Information: 0 : 18304, 28, 2019/05/03, 09:59:30.983, 169587468526, testhost.exe, DefaultEngineInvoker.SetParentProcessExitCallback: ParentProcess '18356' Exited.
TpTrace Verbose: 0 : 18304, 9, 2019/05/03, 09:59:30.983, 169587472928, testhost.exe, LengthPrefixCommunicationChannel.Dispose: Dispose reader and writer.
TpTrace Verbose: 0 : 18304, 9, 2019/05/03, 09:59:30.983, 169587473097, testhost.exe, TcpClientExtensions.MessageLoopAsync: exiting MessageLoopAsync remoteEndPoint: 127.0.0.1:51948 localEndPoint: 127.0.0.1:51949

问题总是从同一个地方开始,而且它似乎与测试用例无关,我当时尝试忽略一些测试用例,它会跳过那些但仍然 运行 遇到同样的问题。

构建服务器是 Windows 2012 R2 标准安装,最新版本为 Visual studio 2017 企业版更新 (15.9.11)。

显然我已经尝试在网上查找有关该问题的信息,并且已经采取了一些措施;

我很乐意提供更多信息或需要的信息...

编辑:

我实际上只能在 Release 模式下重现这个问题,即使在 Visual studio 处于 Release 模式时,即使 运行 宁单个测试用例,它也可以重现,这表明其他方面的错误比我最初想的要多。 运行在本地测试用例时,没有向 TFS 服务器报告,所以有些地方不对劲。

内部测试代码似乎有一个非常奇怪的问题,我们使用MSMQ来ping跟踪测试环境(系统测试)的代理,并且由于某种原因,MSMQ发送需要很长时间对于以发布模式构建的某些测试用例。如果有人看到这个是因为他们正在寻找类似问题的答案,对不起,我自己都不知道实际问题是什么。