Медленная сборка теста TFS, зависание на "vstest.console.exe, TcpClientExtensions.MessageLoopAsync: опрос на remoteEndPoint:" в течение нескольких минут - PullRequest
1 голос
/ 03 мая 2019

У меня есть определение сборки около ~ 250 тестовых наборов, которые начали выполнять тестовые тесты очень медленно.Он запускает почти 100 тестовых примеров, прежде чем, наконец, потребуется ~ 8 минут на тестовый пример.На данный момент у нас более 100 тестов, и это не то, с чем мы можем жить.Мне удалось получить некоторые журналы на сервере, и как только он начинает работать медленно, он регистрирует в журнале diag:

...
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 Standard с обновленной последней версией Visual Studio 2017 Enterprise (15.9.11).

Я попытался найти информацию о проблеме в Интернете, очевидно, и предпринял некоторые мерыс тех пор;

  • Обновлен Visual Studio на компьютере сборки.

  • Изменено определение сборки для использования шага сборки "Установщик платформы VSTest" (с версией 16.0).1) и использовать «Установлено установщиком инструментов» для этапа сборки «Test Assemblies».

  • Обновлены пакеты nuget MSTest.TestAdapter и MSTest.TestFramework до последних версийion (2.0.0 beta4)

  • vstest.console.exe - версия 15.0.0.

Я с удовольствием предоставлю дополнительную информацию илинапример, при необходимости ...

РЕДАКТИРОВАТЬ:

Я на самом деле могу воспроизвести эту проблему только в режиме выпуска, и она воспроизводима даже из Visual Studio, когда в режиме выпуска, даже при запуске одного теста, что предполагает другие области ошибки, чем я изначально думал.При локальном запуске тестового примера отчеты на сервер TFS не передаются, поэтому что-то не так.

1 Ответ

0 голосов
/ 06 мая 2019

Кажется, что действительно странная проблема с внутренним тестовым кодом, мы используем MSMQ для проверки связи с агентами, которые отслеживают среду тестирования (системные тесты), и по какой-то причине отправка MSMQ занимает очень много времени тестовые случаи при сборке в режиме релиза. Если кто-то видит это, потому что ищет ответ на что-то похожее, извините, я даже не знаю, в чем собственно проблема.

...