search

microsoft / azure-pipelines-tasks

Tasks for Azure Pipelines
https://aka.ms/tfbuild
MIT License
3.43k stars 2.59k forks source link

Selenium Tests are not running anymore #10001

Closed sescandell closed 5 years ago

sescandell commented 5 years ago

Required Information

Question, Bug, or Feature?
Type: Bug

Enter Task Name: VSTestV2 Version: 2.149.6

Environment

Issue Description

We have a Visual Studio test suite running Selenium tests on Chrome (MSTest).

Starting two weeks ago, all our automated tests ran from Azure Devops stopped to pass. It seems something doesn't succeed anymore to communicate between Chromedriver <=> Chrome and/or the "tests runner" <=> chromedriver. Error is Assert.Fail failed. Unexpected Error : The HTTP request to the remote WebDriver server for URL http://localhost:3723/session/c121c86b25ece8424dbb8771c2ef16b3/window/current/maximize timed out after 60 seconds.

If I remote connect to the host, and run the command in CLI via vstest.console.exe MyTestSuite.dll everything is working and passing well (so not issue about chromedriver and Chrome version apparently).

If I run tests from Azure Pipelines DTAExecutionHost is run and tests are timing out (see logs below).

Task logs

2019-04-02T07:02:51.4448821Z ##[section]Starting: Run UI Tests
2019-04-02T07:02:51.4466958Z ==============================================================================
2019-04-02T07:02:51.4467132Z Task         : Visual Studio Test
2019-04-02T07:02:51.4467246Z Description  : Run unit and functional tests (Selenium, Appium, Coded UI test, etc.) using the Visual Studio Test (VsTest) runner. Test frameworks that have a Visual Studio test adapter such as MsTest, xUnit, NUnit, Chutzpah (for JavaScript tests using QUnit, Mocha and Jasmine), etc. can be run. Tests can be distributed on multiple agents using this task (version 2).
2019-04-02T07:02:51.4467491Z Version      : 2.149.6
2019-04-02T07:02:51.4467612Z Author       : Microsoft Corporation
2019-04-02T07:02:51.4467734Z Help         : [More information](https://go.microsoft.com/fwlink/?LinkId=835764)
2019-04-02T07:02:51.4467916Z ==============================================================================
2019-04-02T07:02:53.0105040Z SystemVssConnection exists true
2019-04-02T07:02:53.2177272Z SystemVssConnection exists true
2019-04-02T07:02:53.3607476Z SystemVssConnection exists true
2019-04-02T07:02:53.5279941Z In distributed testing flow
2019-04-02T07:02:53.5280227Z ======================================================
2019-04-02T07:02:53.5281101Z Test selector : Test plan
2019-04-02T07:02:53.5281452Z Test plan Id : 120
2019-04-02T07:02:53.5281784Z Test plan configuration Id : 1
2019-04-02T07:02:53.5282079Z Test suite Id selected: 121
2019-04-02T07:02:53.5282458Z Search folder : D:\agent-04\_work\r1\a
2019-04-02T07:02:53.5284903Z VisualStudio version selected for test execution : latest
2019-04-02T07:02:53.7884430Z Distributed test execution, number of agents in job : 1
2019-04-02T07:02:53.7922853Z Run in parallel : false
2019-04-02T07:02:53.7924129Z Run in isolation : false
2019-04-02T07:02:53.7927143Z Path to custom adapters : null
2019-04-02T07:02:53.7935703Z Other console options : null
2019-04-02T07:02:53.7939578Z Code coverage enabled : false
2019-04-02T07:02:53.7946849Z Diagnostics enabled : true
2019-04-02T07:02:53.8509935Z ======================================================
2019-04-02T07:02:53.8511227Z Source filter: **\Awesome.UI.Tests.dll
2019-04-02T07:02:53.9824089Z SystemVssConnection exists true
2019-04-02T07:02:53.9880445Z [command]D:\agent-04\_work\_tasks\VSTest_ef087383-ee5e-42c7-9a53-ab56c98420f9\2.149.6\Modules\DTAExecutionHost.exe --inputFile D:\agent-04\_work\_temp\input_56299271-5515-11e9-b71c-292706c41bc5.json
2019-04-02T07:02:54.0719110Z ##########################################################################
2019-04-02T07:02:54.7242268Z ##[warning]Advanced diagnostics data collection requires test platform version 15.9 or higher.
2019-04-02T07:02:56.0021950Z ===========================================
2019-04-02T07:02:56.0022623Z AgentName: WIN-AFFCJLIC91K-r2d2-agent01-agent04-30
2019-04-02T07:02:56.0022887Z ServiceUrl: https://dev.azure.com/fake-name-cicd/
2019-04-02T07:02:56.0023055Z TestPlatformVersion: 15.8.0
2019-04-02T07:02:56.0023232Z EnvironmentUri: vstest://env/fake-name/_apis/release/1/1608/6123/1
2019-04-02T07:02:56.0023352Z QueryForTaskIntervalInMilliseconds: 3000
2019-04-02T07:02:56.0023469Z MaxQueryForTaskIntervalInMilliseconds: 10000
2019-04-02T07:02:56.0023602Z QueueNotFoundDelayTimeInMilliseconds: 3000
2019-04-02T07:02:56.0023722Z MaxQueueNotFoundDelayTimeInMilliseconds: 50000
2019-04-02T07:02:56.0023840Z ===========================================
2019-04-02T07:02:56.7024754Z TestExecutionHost.Execute: Registered TestAgent : 40 : WIN-AFFCJLIC91K-r2d2-agent01-agent04-30
2019-04-02T07:02:56.7739688Z IsValidServiceResponse: Received None command..Service Workflow is not active
2019-04-02T07:02:56.9372820Z Updated Run Settings:
2019-04-02T07:02:56.9406486Z <RunSettings>
2019-04-02T07:02:56.9407328Z   
2019-04-02T07:02:56.9407645Z   <RunConfiguration>
2019-04-02T07:02:56.9407924Z     <CustomSlicing enabled="true" maxagents="1" numberOfTestCasesPerSlice="0" isTimeBasedSlicing="False" sliceTime="0" />
2019-04-02T07:02:56.9409954Z     <BatchSize>1000</BatchSize>
2019-04-02T07:02:56.9410128Z     <ResultsDirectory>D:\agent-04\_work\_temp\TR_e9891b1e-51f9-4d63-9f1d-46e028f46084</ResultsDirectory>
2019-04-02T07:02:56.9410275Z   </RunConfiguration>
2019-04-02T07:02:56.9410416Z </RunSettings>
2019-04-02T07:02:56.9899216Z Run Settings File Path : C:\Windows\ServiceProfiles\NetworkService\AppData\Local\Temp\tmpF133.runsettings
2019-04-02T07:02:57.2364530Z Creating run for selected test plan with following parameters
2019-04-02T07:02:57.2368545Z Test plan ID: 120
2019-04-02T07:02:57.2368952Z Test suite ID: 121
2019-04-02T07:02:57.2370025Z Test configuration ID: 1
2019-04-02T07:02:58.1331909Z test configuration mapping: 
2019-04-02T07:02:58.1392831Z Run title: Tests UI
2019-04-02T07:02:58.1396801Z test settings id : 1000048
2019-04-02T07:02:58.1397364Z Build location: D:\agent-04\_work\r1\a
2019-04-02T07:02:58.1400193Z Build Id: 2322
2019-04-02T07:02:59.5081787Z Test run with Id 1000244 associated
2019-04-02T07:03:07.8123453Z Received the command : Start
2019-04-02T07:03:07.8154171Z TestExecutionHost.ProcessCommand. Start Command handled
2019-04-02T07:03:07.9677000Z Slice with id = 39, of type = 'Execution' received.
2019-04-02T07:03:08.2210822Z Count of test sources found: 1
2019-04-02T07:03:08.2651509Z =================================================================
2019-04-02T07:03:08.2657691Z Discovering tests from sources
2019-04-02T07:03:08.2740040Z Using new test platform for test execution
2019-04-02T07:03:11.3599956Z Number of testcases discovered : 11
2019-04-02T07:03:11.4083093Z Discovered tests 11 from sources
2019-04-02T07:03:11.4083984Z =================================================================
2019-04-02T07:03:11.4955691Z [RunStatistics]This execution slice with id '39', received '11' testcases to execute out of which '11' is discovered.
2019-04-02T07:03:11.5043401Z **************** Starting test execution *********************
2019-04-02T07:03:11.5208597Z Using new test platform for test execution
2019-04-02T07:06:44.1894038Z Failed    Awesome.UI.Tests.Connection.ConectionTests.ConnectionViaForm_UserWithLoginAndMdp_LogOnTheWall    ConnectionViaForm_UserWithLoginAndMdp_LogOnTheWall
2019-04-02T07:10:10.2223856Z Failed    Awesome.UI.Tests.Connection.ConectionTests.ConnectionViaO365_UserWithLoginAndMdp_LogOnTheWall    ConnectionViaO365_UserWithLoginAndMdp_LogOnTheWall
2019-04-02T07:13:36.3480819Z Failed    Awesome.UI.Tests.Connection.ConectionTests.ConnectionViaForm_InactiveUser_ErrorMessageDisplayed    ConnectionViaForm_InactiveUser_ErrorMessageDisplayed
2019-04-02T07:17:02.4611029Z Failed    Awesome.UI.Tests.Connection.ConectionTests.ConnectionViaForm_UserWithoutCompany_ErrorMessageDisplayed    ConnectionViaForm_UserWithoutCompany_ErrorMessageDisplayed
2019-04-02T07:20:28.4278358Z Failed    Awesome.UI.Tests.Sharing.SharingTests.Sharing_ConnectTwitterAccount_TwitterAccountIsConnected    Sharing_ConnectTwitterAccount_TwitterAccountIsConnected
2019-04-02T07:23:54.3835581Z Failed    Awesome.UI.Tests.Sharing.SharingTests.Sharing_ShareContentWithoutComment_ShareSucceded    Sharing_ShareContentWithoutComment_ShareSucceded
2019-04-02T07:27:20.3192832Z Failed    Awesome.UI.Tests.Sharing.SharingTests.Sharing_ShareContentWithComment_ShareSucceded    Sharing_ShareContentWithComment_ShareSucceded
2019-04-02T07:29:46.9786970Z ##[error]The operation was canceled.
2019-04-02T07:29:46.9844684Z ##[section]Finishing: Run UI Tests

For information, when logged in to the host, I can see in task manager all the 3 processes (DTAExecutionHost, chromedriver and Chrome, but no "activity" like CPU or memory moving): image

Troubleshooting

Using system.debug flag, there is no interesting additional log.

Please, advice what could be wrong :)

Allendorf231 commented 5 years ago

We've got the same issue here.

BennyM commented 5 years ago

Same here. Stopped working a few days ago. If I go to the agent myself and run from the command line it works, but not when the pipeline is running.

kaadhina commented 5 years ago

Hi, was there a change in how the agent was configured on the machines? Any change of credentials (admin account vs non-admin account)?

kaadhina commented 5 years ago

The specified versions do not look like compatible versions. http://chromedriver.chromium.org/downloads lists 2.46 as supported version for chrome version 73. Have you tried using newer drier version?

sescandell commented 5 years ago

Hi,

Well... I thought I doubled check versions collisions... but it seems I misconfused myself. Indeed, the version used while running through DevOps is not the same as the one when I ran the command from the CLI.

I'll double check all of this and let you know (and close the ticket if required).

Thanks,

sescandell commented 5 years ago

Hi,

TL;DR: it still not working when launched from DevOps while working on CLI with the same configuration.

Details:

I double checked versions, command executed etc: when we launche the task from Azure DevOps this is the Output of the execution:

2019-04-05T16:02:25.5592518Z ##[section]Starting: Run Tests
2019-04-05T16:02:25.5610932Z ==============================================================================
2019-04-05T16:02:25.5611125Z Task         : Visual Studio Test
2019-04-05T16:02:25.5611245Z Description  : Run unit and functional tests (Selenium, Appium, Coded UI test, etc.) using the Visual Studio Test (VsTest) runner. Test frameworks that have a Visual Studio test adapter such as MsTest, xUnit, NUnit, Chutzpah (for JavaScript tests using QUnit, Mocha and Jasmine), etc. can be run. Tests can be distributed on multiple agents using this task (version 2).
2019-04-05T16:02:25.5611400Z Version      : 2.149.6
2019-04-05T16:02:25.5611570Z Author       : Microsoft Corporation
2019-04-05T16:02:25.5611699Z Help         : [More information](https://go.microsoft.com/fwlink/?LinkId=835764)
2019-04-05T16:02:25.5611841Z ==============================================================================
2019-04-05T16:02:26.6938924Z SystemVssConnection exists true
2019-04-05T16:02:26.8678970Z SystemVssConnection exists true
2019-04-05T16:02:27.0620380Z SystemVssConnection exists true
2019-04-05T16:02:27.2110582Z Running tests using vstest.console.exe runner.
2019-04-05T16:02:27.2112933Z ======================================================
2019-04-05T16:02:27.2114027Z Test selector : Test assemblies
2019-04-05T16:02:27.2114396Z Test filter criteria : null
2019-04-05T16:02:27.2115355Z Search folder : D:\agent-01\_work\r19\a
2019-04-05T16:02:27.2124785Z VisualStudio version selected for test execution : 15.0
2019-04-05T16:02:27.3394738Z Run in parallel : false
2019-04-05T16:02:27.3395402Z Run in isolation : false
2019-04-05T16:02:27.3396389Z Path to custom adapters : null
2019-04-05T16:02:27.3404610Z Other console options : null
2019-04-05T16:02:27.3449135Z Code coverage enabled : false
2019-04-05T16:02:27.3450502Z Diagnostics enabled : true
2019-04-05T16:02:27.3451883Z SystemVssConnection exists true
2019-04-05T16:02:27.3482043Z Run the tests locally using vstest.console.exe
2019-04-05T16:02:27.3484437Z ========================================================
2019-04-05T16:02:27.3507610Z Test selector : Test assemblies
2019-04-05T16:02:27.3514247Z Test assemblies : **\Awesome.UI.Tests.dll
2019-04-05T16:02:27.3515288Z Test filter criteria : null
2019-04-05T16:02:27.3524630Z Search folder : D:\agent-01\_work\r19\a
2019-04-05T16:02:27.3528015Z Run settings file : D:\agent-01\_work\r19\a
2019-04-05T16:02:27.3532319Z Run in parallel : false
2019-04-05T16:02:27.3536240Z Run in isolation : false
2019-04-05T16:02:27.3584145Z Path to custom adapters : null
2019-04-05T16:02:27.3584596Z Other console options : null
2019-04-05T16:02:27.3588722Z Code coverage enabled : false
2019-04-05T16:02:27.3589433Z Diagnostics enabled : false
2019-04-05T16:02:27.3598286Z Rerun failed tests: false
2019-04-05T16:02:27.3603653Z VisualStudio version selected for test execution : 15.0
2019-04-05T16:02:27.7124227Z ========================================================
2019-04-05T16:02:27.8085660Z ======================================================
2019-04-05T16:02:28.0128313Z [command]"C:\Program Files (x86)\Microsoft Visual Studio\2017\Enterprise\Common7\IDE\CommonExtensions\Microsoft\TestWindow\vstest.console.exe" @D:\agent-01\_work\_temp\35a2f151-57bc-11e9-9931-777582184583.txt
2019-04-05T16:02:28.4113521Z Microsoft (R) Test Execution Command Line Tool Version 15.8.0
2019-04-05T16:02:28.4119124Z Copyright (c) Microsoft Corporation.  All rights reserved.
2019-04-05T16:02:28.4119677Z 
2019-04-05T16:02:28.4174514Z vstest.console.exe 
2019-04-05T16:02:28.4176346Z "D:\agent-01\_work\r19\a\_Projet - UI Tests 2\drop\Release\Awesome.UI.Tests.dll"
2019-04-05T16:02:28.4177100Z /logger:"trx"
2019-04-05T16:02:28.4177365Z /TestAdapterPath:"D:\agent-01\_work\r19\a"
2019-04-05T16:02:28.7579828Z Starting test execution, please wait...
2019-04-05T16:02:31.8142048Z Starting ChromeDriver 73.0.3683.68 (47787ec04b6e38e22703e856e101e840b65afe72) on port 16064
2019-04-05T16:02:31.8142287Z Only local connections are allowed.
2019-04-05T16:02:31.8143569Z Please protect ports used by ChromeDriver and related test frameworks to prevent access by malicious code.
2019-04-05T16:05:57.9742663Z Failed   ConnectionViaForm_UserWithLoginAndMdp_LogOnTheWall
2019-04-05T16:05:57.9774895Z Error Message:
2019-04-05T16:05:57.9775660Z  Assert.Fail failed. Unexpected Error : The HTTP request to the remote WebDriver server for URL http://localhost:16064/session/f53a5f4d05c533f44f5fe805ace7ccf5/window/current/maximize timed out after 60 seconds.
2019-04-05T16:05:57.9776724Z Stack Trace:
2019-04-05T16:05:57.9778267Z    at Awesome.UI.Tests.common.UITestHelper.ManageException(Exception e, String source) in D:\agent-07\_work\16\s\Awesome.UI.Tests\Common\UITestHelper.cs:line 118
2019-04-05T16:05:57.9778945Z    at Awesome.UI.Tests.Connection.ConectionTests.ConnectionViaForm_UserWithLoginAndMdp_LogOnTheWall() in D:\agent-07\_work\16\s\Awesome.UI.Tests\Connection\ConnectionTests.cs:line 39
2019-04-05T16:05:57.9780013Z 
2019-04-05T16:05:57.9802195Z Standard Output Messages:
2019-04-05T16:05:57.9802509Z  
2019-04-05T16:05:57.9802982Z 
2019-04-05T16:05:57.9803267Z Debug Trace:
2019-04-05T16:05:57.9803450Z vstest.console.exe Error: 0 : Awesome.UI.Tests.Connection.ConectionTests - Unexpected Error
2019-04-05T16:05:57.9804392Z  OpenQA.Selenium.WebDriverException=WebDriverException 
2019-04-05T16:05:57.9804708Z Message=The HTTP request to the remote WebDriver server for URL http://localhost:16064/session/f53a5f4d05c533f44f5fe805ace7ccf5/window/current/maximize timed out after 60 seconds. 
2019-04-05T16:05:57.9804893Z Source=WebDriver 
2019-04-05T16:05:57.9805427Z StackTrace:
2019-04-05T16:05:57.9805577Z       at OpenQA.Selenium.Remote.HttpCommandExecutor.MakeHttpRequest(HttpRequestInfo requestInfo)
2019-04-05T16:05:57.9805745Z       at OpenQA.Selenium.Remote.HttpCommandExecutor.Execute(Command commandToExecute)
2019-04-05T16:05:57.9805890Z       at OpenQA.Selenium.Remote.DriverServiceCommandExecutor.Execute(Command commandToExecute)
2019-04-05T16:05:57.9806061Z       at OpenQA.Selenium.Remote.RemoteWebDriver.Execute(String driverCommandToExecute, Dictionary`2 parameters)
2019-04-05T16:05:57.9806198Z       at OpenQA.Selenium.Remote.RemoteWindow.Maximize()
2019-04-05T16:05:57.9806370Z       at Awesome.ServicesTests.TestBase.TargetBrowser(String browser) in D:\agent-07\_work\16\s\Awesome.UI.Tests\TestBase.cs:line 146
2019-04-05T16:05:57.9806534Z       at Awesome.UI.Tests.Connection.ConectionTests.ConnectionViaForm_UserWithLoginAndMdp_LogOnTheWall() in D:\agent-07\_work\16\s\Awesome.UI.Tests\Connection\ConnectionTests.cs:line 29 
2019-04-05T16:05:57.9806693Z Inner Exception=WebException 
2019-04-05T16:05:57.9806853Z    Message=The operation has timed out 
2019-04-05T16:05:57.9806991Z    Source=System 
2019-04-05T16:05:57.9807186Z    StackTrace:
2019-04-05T16:05:57.9807322Z           at System.Net.HttpWebRequest.GetResponse()
2019-04-05T16:05:57.9807485Z           at OpenQA.Selenium.Remote.HttpCommandExecutor.MakeHttpRequest(HttpRequestInfo requestInfo) 
2019-04-05T16:05:57.9807602Z 
2019-04-05T16:05:57.9807742Z ============================================================
2019-04-05T16:05:57.9807885Z  vstest.console.exe Error: 0 : Awesome.UI.Tests.Connection.ConectionTests - Unable to make a screeshoot
2019-04-05T16:05:57.9808039Z  OpenQA.Selenium.WebDriverException=WebDriverException 
2019-04-05T16:05:57.9808193Z Message=The HTTP request to the remote WebDriver server for URL http://localhost:16064/session/f53a5f4d05c533f44f5fe805ace7ccf5/screenshot timed out after 60 seconds. 
2019-04-05T16:05:57.9808329Z Source=WebDriver 
2019-04-05T16:05:57.9808515Z StackTrace:
2019-04-05T16:05:57.9808656Z       at OpenQA.Selenium.Remote.HttpCommandExecutor.MakeHttpRequest(HttpRequestInfo requestInfo)
2019-04-05T16:05:57.9808798Z       at OpenQA.Selenium.Remote.HttpCommandExecutor.Execute(Command commandToExecute)
2019-04-05T16:05:57.9808958Z       at OpenQA.Selenium.Remote.DriverServiceCommandExecutor.Execute(Command commandToExecute)
2019-04-05T16:05:57.9810436Z       at OpenQA.Selenium.Remote.RemoteWebDriver.Execute(String driverCommandToExecute, Dictionary`2 parameters)
2019-04-05T16:05:57.9810578Z       at OpenQA.Selenium.Remote.RemoteWebDriver.GetScreenshot()
2019-04-05T16:05:57.9810726Z       at Awesome.ServicesTests.TestBase.SaveScreenshotOnFailure() in D:\agent-07\_work\16\s\Awesome.UI.Tests\TestBase.cs:line 119 
2019-04-05T16:05:57.9810889Z Inner Exception=WebException 
2019-04-05T16:05:57.9811020Z    Message=The operation has timed out 
2019-04-05T16:05:57.9811143Z    Source=System 
2019-04-05T16:05:57.9811268Z    StackTrace:
2019-04-05T16:05:57.9811451Z           at System.Net.HttpWebRequest.GetResponse()
2019-04-05T16:05:57.9811597Z           at OpenQA.Selenium.Remote.HttpCommandExecutor.MakeHttpRequest(HttpRequestInfo requestInfo) 
2019-04-05T16:05:57.9811687Z 
2019-04-05T16:05:57.9811819Z ============================================================
2019-04-05T16:05:57.9811906Z 
2019-04-05T16:05:57.9812007Z 
2019-04-05T16:05:58.5324030Z Starting ChromeDriver 73.0.3683.68 (47787ec04b6e38e22703e856e101e840b65afe72) on port 16084
2019-04-05T16:05:58.5324377Z Only local connections are allowed.
2019-04-05T16:05:58.5324473Z Please protect ports used by ChromeDriver and related test frameworks to prevent access by malicious code.
2019-04-05T16:07:28.6849296Z ##[error]The operation was canceled.
2019-04-05T16:07:28.6923953Z ##[section]Finishing: Run Tests

As you can see from the logs, ChromeDriver version used is 73.0.3683.68

While the task was running, connected on the machine, I copied / pasted the file 35a2f151-57bc-11e9-9931-777582184583.txt. Still connected on the machine, I open a CMD and run the following command (exactly the same as visible in logs):

]"C:\Program Files (x86)\Microsoft Visual Studio\2017\Enterprise\Common7\IDE\CommonExtensions\Microsoft\TestWindow\vstest.console.exe" @D:\copied-file.txt

And here, everything is working as expected: image

Any other idea?

While writing this post, I see that I'm executing the command as an administrator. That is probably not the situation from Azure DevOps. Could it be the reason of this failure (as suggested @kaadhina) ? Nothing have been changed about admin / non-admin credentials on the machine and the machine is running for almost 100 days.

kaadhina commented 5 years ago

I tried the below versions and this works (tried both using vstest.console and dtaexecutionhost) chrome=73.0.3683.75 chromedriver=73.0.3683 The agent was setup as non-admin. It could be possible that the issue appears only for admin agents. So please try as non-admin as well.

Can you please confirm the above setup does not work for you.

DeV1L commented 5 years ago

I have the same issue. Tests has stopped working at all six build agents at the same time. The problem started about two weeks ago.

I've just tested with ChromeDriver 2.45.615291 and ChromeDriver 73.0.3683.68. Result is the same. But the test works well if I run it from command line.

image

Agent log.

2019-04-09T13:31:50.2220518Z ##[section]Starting: Tests
2019-04-09T13:31:50.2577537Z ==============================================================================
2019-04-09T13:31:50.2577731Z Task         : Visual Studio Test
2019-04-09T13:31:50.2577845Z Description  : Run unit and functional tests (Selenium, Appium, Coded UI test, etc.) using the Visual Studio Test (VsTest) runner. Test frameworks that have a Visual Studio test adapter such as MsTest, xUnit, NUnit, Chutzpah (for JavaScript tests using QUnit, Mocha and Jasmine), etc. can be run. Tests can be distributed on multiple agents using this task (version 2).
2019-04-09T13:31:50.2578007Z Version      : 2.149.6
2019-04-09T13:31:50.2578092Z Author       : Microsoft Corporation
2019-04-09T13:31:50.2578228Z Help         : [More information](https://go.microsoft.com/fwlink/?LinkId=835764)
2019-04-09T13:31:50.2578372Z ==============================================================================
2019-04-09T13:32:02.0244169Z SystemVssConnection exists true
2019-04-09T13:32:02.2272629Z SystemVssConnection exists true
2019-04-09T13:32:02.4285983Z SystemVssConnection exists true
2019-04-09T13:32:02.6092015Z Running tests using vstest.console.exe runner.
2019-04-09T13:32:02.6092805Z ======================================================
2019-04-09T13:32:02.6118974Z Test selector : Test assemblies
2019-04-09T13:32:02.6127739Z Test filter criteria : TestCategory=VstsApiGameTests
2019-04-09T13:32:02.6150739Z Search folder : C:\vsts-agent\_work\r915\a\qa-arena-5.0-tests\build
2019-04-09T13:32:02.6223226Z VisualStudio version selected for test execution : latest
2019-04-09T13:32:03.1208761Z Run in parallel : false
2019-04-09T13:32:03.1217328Z Run in isolation : false
2019-04-09T13:32:03.1218877Z Path to custom adapters : null
2019-04-09T13:32:03.1231603Z Other console options : null
2019-04-09T13:32:03.1238960Z Code coverage enabled : false
2019-04-09T13:32:03.1253620Z Diagnostics enabled : true
2019-04-09T13:32:03.1281914Z SystemVssConnection exists true
2019-04-09T13:32:03.1364824Z Run the tests locally using vstest.console.exe
2019-04-09T13:32:03.1365886Z ========================================================
2019-04-09T13:32:03.1396680Z Test selector : Test assemblies
2019-04-09T13:32:03.1408059Z Test assemblies : **\*qa-arena5.0-tests.dll
2019-04-09T13:32:03.1414956Z Test filter criteria : TestCategory=VstsApiGameTests
2019-04-09T13:32:03.1443188Z Search folder : C:\vsts-agent\_work\r915\a\qa-arena-5.0-tests\build
2019-04-09T13:32:03.1443893Z Run settings file : C:\vsts-agent\_work\r915\a
2019-04-09T13:32:03.1444299Z Run in parallel : false
2019-04-09T13:32:03.1450832Z Run in isolation : false
2019-04-09T13:32:03.1575462Z Path to custom adapters : null
2019-04-09T13:32:03.1577878Z Other console options : null
2019-04-09T13:32:03.1585682Z Code coverage enabled : false
2019-04-09T13:32:03.1588132Z Diagnostics enabled : false
2019-04-09T13:32:03.1624628Z Rerun failed tests: false
2019-04-09T13:32:03.1638094Z VisualStudio version selected for test execution : latest
2019-04-09T13:32:04.1893978Z ========================================================
2019-04-09T13:32:04.2485298Z ======================================================
2019-04-09T13:32:04.3826458Z [command]"C:\Program Files (x86)\Microsoft Visual Studio\2017\Professional\Common7\IDE\CommonExtensions\Microsoft\TestWindow\vstest.console.exe" @C:\vsts-agent\_work\_temp\dcd7c561-5acb-11e9-aa95-c9612ba7a8dc.txt
2019-04-09T13:32:07.0726986Z Microsoft (R) Test Execution Command Line Tool Version 15.7.2
2019-04-09T13:32:07.0735245Z Copyright (c) Microsoft Corporation.  All rights reserved.
2019-04-09T13:32:07.0735798Z 
2019-04-09T13:32:07.0819261Z vstest.console.exe 
2019-04-09T13:32:07.0820065Z "C:\vsts-agent\_work\r915\a\qa-arena-5.0-tests\build\qa-arena5.0-tests.dll"
2019-04-09T13:32:07.0821448Z /TestCaseFilter:"TestCategory=VstsApiGameTests"
2019-04-09T13:32:07.0821780Z /logger:"trx"
2019-04-09T13:32:07.0822006Z /TestAdapterPath:"C:\vsts-agent\_work\r915\a\qa-arena-5.0-tests\build"
2019-04-09T13:32:07.8443801Z Starting test execution, please wait...
2019-04-09T13:32:08.8336773Z NUnit VS Adapter 2.1.1.0 executing tests is started
2019-04-09T13:32:09.6258740Z Loading tests from C:\vsts-agent\_work\r915\a\qa-arena-5.0-tests\build\qa-arena5.0-tests.dll
2019-04-09T13:32:10.0577751Z TFS Filter detected: LoadedTestCases 86, Filterered Test Cases 1
2019-04-09T13:32:10.0794847Z Run started: C:\vsts-agent\_work\r915\a\qa-arena-5.0-tests\build\qa-arena5.0-tests.dll
2019-04-09T13:32:10.7310018Z Starting on the PC in Chrome browser
2019-04-09T13:32:11.7955120Z Starting ChromeDriver 2.45.615291 (ec3682e3c9061c10f26ea9e5cdcf3c53f3f74387) on port 13423
2019-04-09T13:32:11.7955742Z Only local connections are allowed.
2019-04-09T13:35:15.5693411Z OpenQA.Selenium.WebDriverException: The HTTP request to the remote WebDriver server for URL http://localhost:13423/session/3a97f32e15c7e5c89254717e6db7ba44/window/current/maximize timed out after 180 seconds. ---> System.Net.WebException: The operation has timed out
2019-04-09T13:35:15.5694414Z    at System.Net.HttpWebRequest.GetResponse()
2019-04-09T13:35:15.5697118Z    at OpenQA.Selenium.Remote.HttpCommandExecutor.MakeHttpRequest(HttpRequestInfo requestInfo)
2019-04-09T13:35:15.5697767Z    --- End of inner exception stack trace ---
2019-04-09T13:35:15.5698052Z    at OpenQA.Selenium.Remote.HttpCommandExecutor.MakeHttpRequest(HttpRequestInfo requestInfo)
2019-04-09T13:35:15.5698203Z    at OpenQA.Selenium.Remote.HttpCommandExecutor.Execute(Command commandToExecute)
2019-04-09T13:35:15.5698882Z    at OpenQA.Selenium.Remote.DriverServiceCommandExecutor.Execute(Command commandToExecute)
2019-04-09T13:35:15.5700414Z    at OpenQA.Selenium.Remote.RemoteWebDriver.Execute(String driverCommandToExecute, Dictionary`2 parameters)
2019-04-09T13:35:15.5700841Z    at OpenQA.Selenium.Remote.RemoteWindow.Maximize()
2019-04-09T13:35:15.5701863Z    at qa_arena5_tests.Framework.BrowserFactory.Chrome.InitBrowser(Boolean proxyStatus) in C:\vsts-agent\_work\1497\s\Framework\BrowserFactory\Chrome.cs:line 18
2019-04-09T13:35:15.5702234Z    at qa_arena5_tests.Framework.Driver.StartWebDriver() in C:\vsts-agent\_work\1497\s\Framework\Driver.cs:line 76
2019-04-09T13:35:15.5702474Z    at qa_arena5_tests.Framework.Driver.Start() in C:\vsts-agent\_work\1497\s\Framework\Driver.cs:line 42
2019-04-09T13:35:15.5702634Z    at qa_arena5_tests.Tests.PC.TestBase.StartBrowser() in C:\vsts-agent\_work\1497\s\Tests\PC\TestBase.cs:line 24
2019-04-09T13:35:16.6928043Z Can't Kill Process
2019-04-09T13:35:16.6928722Z Can't Kill ProcessObject reference not set to an instance of an object.
2019-04-09T13:35:16.6930398Z Start new driver: Object reference not set to an instance of an object.
2019-04-09T13:35:16.7867130Z Starting on the PC in Chrome browser
2019-04-09T13:35:16.8636092Z Starting ChromeDriver 2.45.615291 (ec3682e3c9061c10f26ea9e5cdcf3c53f3f74387) on port 13450
2019-04-09T13:38:20.4744992Z Only local connections are allowed.
2019-04-09T13:38:20.4745734Z Can't Kill Process
2019-04-09T13:38:20.4746173Z Can't Kill ProcessObject reference not set to an instance of an object.
2019-04-09T13:38:20.4746575Z Dismiss Freezed Driver: Object reference not set to an instance of an object.
2019-04-09T13:38:20.6131885Z NUnit VS Adapter 2.1.1.0 executing tests is finished
2019-04-09T13:38:21.1554536Z Failed   http://arenax-challenges_arkadium_com/en/games/bridge?version=0_50
2019-04-09T13:38:21.1596211Z Error Message:
2019-04-09T13:38:21.1597162Z  SetUp : OpenQA.Selenium.WebDriverException : The HTTP request to the remote WebDriver server for URL http://localhost:13450/session/a81b38d21b4de5789a185b3df67b4d65/window/current/maximize timed out after 180 seconds.
2019-04-09T13:38:21.1597805Z   ----> System.Net.WebException : The request was aborted: The operation has timed out.
2019-04-09T13:38:21.1600826Z TearDown : System.NullReferenceException : Object reference not set to an instance of an object.
2019-04-09T13:38:21.1606996Z Stack Trace:
2019-04-09T13:38:21.1607672Z at OpenQA.Selenium.Remote.HttpCommandExecutor.MakeHttpRequest(HttpRequestInfo requestInfo)
2019-04-09T13:38:21.1609956Z at OpenQA.Selenium.Remote.HttpCommandExecutor.Execute(Command commandToExecute)
2019-04-09T13:38:21.1610545Z at OpenQA.Selenium.Remote.DriverServiceCommandExecutor.Execute(Command commandToExecute)
2019-04-09T13:38:21.1611126Z at OpenQA.Selenium.Remote.RemoteWebDriver.Execute(String driverCommandToExecute, Dictionary`2 parameters)
2019-04-09T13:38:21.1615069Z at OpenQA.Selenium.Remote.RemoteWindow.Maximize()
2019-04-09T13:38:21.1616149Z at qa_arena5_tests.Framework.BrowserFactory.Chrome.InitBrowser(Boolean proxyStatus) in C:\vsts-agent\_work\1497\s\Framework\BrowserFactory\Chrome.cs:line 18
2019-04-09T13:38:21.1616710Z at qa_arena5_tests.Framework.Driver.StartWebDriver() in C:\vsts-agent\_work\1497\s\Framework\Driver.cs:line 76
2019-04-09T13:38:21.1617410Z at qa_arena5_tests.Framework.Driver.ReStartDriver() in C:\vsts-agent\_work\1497\s\Framework\Driver.cs:line 111
2019-04-09T13:38:21.1617903Z at qa_arena5_tests.Tests.PC.TestBase.StartBrowser() in C:\vsts-agent\_work\1497\s\Tests\PC\TestBase.cs:line 30
2019-04-09T13:38:21.1618400Z --WebException
2019-04-09T13:38:21.1618915Z at System.Net.HttpWebRequest.GetResponse()
2019-04-09T13:38:21.1619407Z at OpenQA.Selenium.Remote.HttpCommandExecutor.MakeHttpRequest(HttpRequestInfo requestInfo)
2019-04-09T13:38:21.1619831Z --TearDown
2019-04-09T13:38:21.1620313Z at qa_arena5_tests.Framework.Driver.DismissDriver() in C:\vsts-agent\_work\1497\s\Framework\Driver.cs:line 176
2019-04-09T13:38:21.1620640Z at qa_arena5_tests.Tests.PC.TestBase.CloseOtherWindowsAfterFb() in C:\vsts-agent\_work\1497\s\Tests\PC\TestBase.cs:line 41
2019-04-09T13:38:21.1620825Z 
2019-04-09T13:38:21.1639416Z Standard Output Messages:
2019-04-09T13:38:21.1639779Z  Starting on the PC in Chrome browser
2019-04-09T13:38:21.1640131Z OpenQA.Selenium.WebDriverException: The HTTP request to the remote WebDriver server for URL http://localhost:13423/session/3a97f32e15c7e5c89254717e6db7ba44/window/current/maximize timed out after 180 seconds. ---> System.Net.WebException: The operation has timed out
2019-04-09T13:38:21.1640318Z     at System.Net.HttpWebRequest.GetResponse()
2019-04-09T13:38:21.1640463Z     at OpenQA.Selenium.Remote.HttpCommandExecutor.MakeHttpRequest(HttpRequestInfo requestInfo)
2019-04-09T13:38:21.1640671Z     --- End of inner exception stack trace ---
2019-04-09T13:38:21.1640814Z     at OpenQA.Selenium.Remote.HttpCommandExecutor.MakeHttpRequest(HttpRequestInfo requestInfo)
2019-04-09T13:38:21.1640951Z     at OpenQA.Selenium.Remote.HttpCommandExecutor.Execute(Command commandToExecute)
2019-04-09T13:38:21.1641152Z     at OpenQA.Selenium.Remote.DriverServiceCommandExecutor.Execute(Command commandToExecute)
2019-04-09T13:38:21.1641298Z     at OpenQA.Selenium.Remote.RemoteWebDriver.Execute(String driverCommandToExecute, Dictionary`2 parameters)
2019-04-09T13:38:21.1641449Z     at OpenQA.Selenium.Remote.RemoteWindow.Maximize()
2019-04-09T13:38:21.1643450Z     at qa_arena5_tests.Framework.BrowserFactory.Chrome.InitBrowser(Boolean proxyStatus) in C:\vsts-agent\_work\1497\s\Framework\BrowserFactory\Chrome.cs:line 18
2019-04-09T13:38:21.1643722Z     at qa_arena5_tests.Framework.Driver.StartWebDriver() in C:\vsts-agent\_work\1497\s\Framework\Driver.cs:line 76
2019-04-09T13:38:21.1643963Z     at qa_arena5_tests.Framework.Driver.Start() in C:\vsts-agent\_work\1497\s\Framework\Driver.cs:line 42
2019-04-09T13:38:21.1644111Z     at qa_arena5_tests.Tests.PC.TestBase.StartBrowser() in C:\vsts-agent\_work\1497\s\Tests\PC\TestBase.cs:line 24
2019-04-09T13:38:21.1644228Z Can't Kill Process
2019-04-09T13:38:21.1644405Z Can't Kill ProcessObject reference not set to an instance of an object.
2019-04-09T13:38:21.1644537Z Start new driver: Object reference not set to an instance of an object.
2019-04-09T13:38:21.1646293Z Starting on the PC in Chrome browser
2019-04-09T13:38:21.1646484Z Can't Kill Process
2019-04-09T13:38:21.1646615Z Can't Kill ProcessObject reference not set to an instance of an object.
2019-04-09T13:38:21.1648139Z Dismiss Freezed Driver: Object reference not set to an instance of an object.
2019-04-09T13:38:21.1648229Z 
2019-04-09T13:38:21.1648299Z 
2019-04-09T13:38:21.7097595Z Results File: C:\vsts-agent\_work\r915\a\TestResults\tfsservice_NY-VSOBUILD02_2019-04-09_06_38_21.trx
2019-04-09T13:38:21.7235055Z 
2019-04-09T13:38:21.7239852Z Total tests: 1. Passed: 0. Failed: 1. Skipped: 0.
2019-04-09T13:38:21.7254927Z Test Run Failed.
2019-04-09T13:38:21.7272226Z Test execution time: 6.2200 Minutes
2019-04-09T13:38:31.7997221Z The STDIO streams did not close within 10 seconds of the exit event from process 'C:\Program Files (x86)\Microsoft Visual Studio\2017\Professional\Common7\IDE\CommonExtensions\Microsoft\TestWindow\vstest.console.exe'. This may indicate a child process inherited the STDIO streams and has not yet exited.
2019-04-09T13:38:31.8345028Z ##[warning]Vstest failed with error. Check logs for failures. There might be failed tests.
2019-04-09T13:38:31.9132161Z ##[error]Error: The process 'C:\Program Files (x86)\Microsoft Visual Studio\2017\Professional\Common7\IDE\CommonExtensions\Microsoft\TestWindow\vstest.console.exe' failed with exit code 1
2019-04-09T13:38:34.3433382Z ##[error]VsTest task failed.
2019-04-09T13:38:34.6729422Z Publishing test results to test run '1013604'
2019-04-09T13:38:34.6729786Z Test results remaining: 1. Test run id: 1013604
2019-04-09T13:38:35.9982899Z Published Test Run : https://tfsprodweusu4.visualstudio.com/A7ca298fe-0375-43ed-a418-90a0ad2a198a/Phoenix%20Games/_TestManagement/Runs#runId=1013604&_a=runCharts
2019-04-09T13:38:39.3752830Z ##[section]Async Command Start: Publish test results
2019-04-09T13:38:39.3753144Z ##[section]Async Command End: Publish test results
2019-04-09T13:38:39.3755772Z ##[section]Finishing: Tests
DeV1L commented 5 years ago

I found that the tests work when VSTS agent is running from command line (not as Windows Service). But all was Ok with working as the service for a years.

kaadhina commented 5 years ago

Hi, thank you for the info. I am able to reproduce this issue with agent running as service. I understand this did not use to require an interactive session. I'm trying to find what changed that caused this break in behaviour. I tried this with an older agent (but newer browser) and can still reproduce the issue. Can you please confirm what changed between before and after the break? Was there a browser update? (I will also try to repro this on older version to confirm this, but if you already have this info, it will help)

Meanwhile to workaround this for now, as mentioned above, you can set up the agent to run in interactive mode (not as service)

DeV1L commented 5 years ago

Hi! The browsers are updating automatically on the agents. I can share release logs before and after the problem had appeared. Would it be helpful?

As workaround I switched the tests to Firefox. It works without any problem.

sescandell commented 5 years ago

Can you please confirm what changed between before and after the break? Was there a browser update? (I will also try to repro this on older version to confirm this, but if you already have this info, it will help)

Nothing as changed about agent configuration. So we can probably think a browser update happened.

Thanks for your time

DeV1L commented 5 years ago

Hi, thank you for the info. I am able to reproduce this issue with agent running as service. I understand this did not use to require an interactive session. I'm trying to find what changed that caused this break in behaviour. I tried this with an older agent (but newer browser) and can still reproduce the issue. Can you please confirm what changed between before and after the break? Was there a browser update? (I will also try to repro this on older version to confirm this, but if you already have this info, it will help)

Meanwhile to workaround this for now, as mentioned above, you can set up the agent to run in interactive mode (not as service)

Hello @kaadhina,

Do you have any updates on the issue?

Thanks!

kaadhina commented 5 years ago

Hi, I've confirmed that the differentiating factor is the browser version. The issue reproduces with older version of agent, driver but a newer version of chrome. At the moment I have no clue about what might have changed in the browser. The workarounds I can think of for the time being are:

  1. Use agent in interactive mode (not as service)
  2. Downgrade browser to previously working version
  3. Try the "headless" option in selenium chrome driver options. (Haven't tried this yet)
DeV1L commented 5 years ago

Thanks for your participation here!

So what we can do except a workaround? Is Microsoft going to work on it? Or should we report the issue to Chrome or Selenium team?

kaadhina commented 5 years ago

Since this is not a change from the agent side and the breaking change is confined to Chrome/Selenium, we think it would be best for you to report this directly to the concerned owners. Thank you.

staff0rd commented 5 years ago

Confirmed I get the same result with headless mode.

mikeblakeuk commented 5 years ago

Can we not force the dotnet test to stop?

ycjcl868 commented 4 years ago

+1

mikeblakeuk commented 4 years ago

@kaadhina why was this closed?

marcelbeekerplanit commented 4 years ago

Hi! The browsers are updating automatically on the agents. I can share release logs before and after the problem had appeared. Would it be helpful?

As workaround I switched the tests to Firefox. It works without any problem.

I had the same problem as you had. Using FireFox now too. It solves my problem too. Too bad Microsoft haven't solve this problem yet.

deepaklohani1985 commented 2 years ago

is solution to above problem available? I have been struggling for many days

mikeblakeuk commented 1 year ago

TBC.

This issue has come back now we are using Windows 2019, Agent v3.220.1 Chrome 113.0.5672.63, ChromeDriver 4/25/2023, net6 "--headless=new"

  Error Message:
   OneTimeSetUp: OpenQA.Selenium.WebDriverException : The HTTP request to the remote WebDriver server for URL http://localhost:52610/session/9c26c9e692e3ae6742f4eda76f195f4c/refresh timed out after 180 seconds.
  ----> System.Threading.Tasks.TaskCanceledException : The request was canceled due to the configured HttpClient.Timeout of 180 seconds elapsing.

Tasks

[debug]Task 'DownloadPipelineArtifact' already downloaded at 'C:\agent_work_tasks\DownloadPipelineArtifact_61f2a582-95ae-4948-b34d-a1b3c4f6a737\2.198.0'.

[debug]Task 'AzureKeyVault' already downloaded at 'C:\agent_work_tasks\AzureKeyVault_1e244d32-2dd4-4165-96fb-b7441ca9331e\1.219.0'.

[debug]Task 'PowerShell' already downloaded at 'C:\agent_work_tasks\PowerShell_e213ff0f-5d5c-4791-802d-52ea3e7be1f1\2.220.0'.

[debug]Task 'UseDotNet' already downloaded at 'C:\agent_work_tasks\UseDotNet_b0ce7256-7898-45d3-9cb5-176b752bfea6\2.219.0'.

[debug]Task 'CmdLine' already downloaded at 'C:\agent_work_tasks\CmdLine_d9bafed4-0b18-4f58-968d-86655b4d2ce9\2.212.0'.

[debug]Task 'AzurePowerShell' already downloaded at 'C:\agent_work_tasks\AzurePowerShell_72a1931b-effb-4d2e-8fd8-f8472a07cb62\5.220.0'.

[debug]Task 'VisualStudioTestPlatformInstaller' already downloaded at 'C:\agent_work_tasks\VisualStudioTestPlatformInstaller_2c65196a-54fd-4a02-9be8-d9d1837b7111\1.215.0'.

[debug]Task 'FileTransform' already downloaded at 'C:\agent_work_tasks\FileTransform_8ce97e91-56cc-4743-bfab-9a9315be5f27\1.220.0'.

[debug]Task 'VSTest' already downloaded at 'C:\agent_work_tasks\VSTest_ef087383-ee5e-42c7-9a53-ab56c98420f9\2.220.0'.

cdeisler commented 7 months ago

Still an issue here, now the test runs correctly the first time (has been working for years), now after first run, the second run triggers the error:

An unknown exception was encountered sending an HTTP request to the remote WebDriver server for URL http://localhost:50016/session/d53c8019d289a7676ddb886636f524a6/element/005E894875B459B920B051F9F5D9BE12_element_125/click. The exception message was: An error occurred while sending the request.:    at OpenQA.Selenium.Remote.HttpCommandExecutor.Execute(Command commandToExecute)
   at OpenQA.Selenium.Remote.DriverServiceCommandExecutor.Execute(Command commandToExecute)
   at OpenQA.Selenium.WebDriver.Execute(String driverCommandToExecute, Dictionary`2 parameters)
   at OpenQA.Selenium.WebDriver.InternalExecute(String driverCommandToExecute, Dictionary`2 parameters)
   at OpenQA.Selenium.WebElement.Execute(String commandToExecute, Dictionary`2 parameters)
   at OpenQA.Selenium.WebElement.Click()

Restarting the VM where the build agent runs will reset the issue, after first run it will trigger the error again.