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

Occasional "Error: Timeout occurred when executing test file" under vstest.console.exe #817

Open
M0ns1gn0r opened this issue Jun 23, 2022 · 0 comments

Comments

@M0ns1gn0r
Copy link

I occasionally get Error: Timeout occurred when executing test file on the build machine which runs the tests via vstest.console.exe. I can't really find the pattern, it's very sporadic, therefore I enabled tracing in the Chutzpah.json:

{
  "Engine": "Chrome",
  "EngineOptions": {
    "ChromeBrowserPath": "C:\\Program Files\\Google\\Chrome\\Application\\chrome.exe"
  },
  "EnableTracing": true
}

Here are log excerpts from a successful and a failing run.

Successful run

vstest.console.exe Information: 0 : Time:11:32:38.4929608; Thread:8; Message:Invoking headless browser on test harness 'C:\_agents\<redacted>\_Chutzpah.87ef6c34eb5ec093d62ffa993dcf1e82baa79268.test.html' for file 'C:\_agents\<redacted>\RestoringCursorPositionTests.js'
vstest.console.exe Information: 0 : Time:11:32:38.5179625; Thread:8; Message:Started headless browser: <path_to_Chutzpah.4.4.12>\Node\x86\node.exe with PID: 5576 using args:  "<path_to_Chutzpah.4.4.12>\ChutzpahJSRunners\Chrome\qunitRunner.js" "http://localhost:9876/_agents/<redacted>/_Chutzpah.87ef6c34eb5ec093d62ffa993dcf1e82baa79268.test.html" execution 10000 True False "C:\Program Files\Google\Chrome\Application\chrome.exe" "" ""
vstest.console.exe Information: 0 : Time:11:32:40.6261499; Thread:10; Message:Phantom Log - Using Chrome Install : C:\Program Files\Google\Chrome\Application\chrome.exe
vstest.console.exe Information: 0 : Time:11:32:40.6431518; Thread:10; Message:Phantom Log - puppeteer browser args: ["--disable-web-security","--no-sandbox"]
vstest.console.exe Information: 0 : Time:11:32:42.5073186; Thread:10; Message:Phantom Log - Resource Received: http://localhost:9876/_agents/<redacted>/_Chutzpah.87ef6c34eb5ec093d62ffa993dcf1e82baa79268.test.html
vstest.console.exe Information: 0 : Time:11:32:42.5573229; Thread:10; Message:Phantom Log - isQunitLoaded
vstest.console.exe Information: 0 : Time:11:32:42.6563311; Thread:10; Message:Phantom Log - Resource Received: http://localhost:9876/_agents/<redacted>/TargetEditor.css?sha=5cb878ddd5a62ea6ef9e128e2d834cab766009a7
vstest.console.exe Information: 0 : Time:11:32:42.6713315; Thread:10; Message:Phantom Log - Resource Received: http://localhost:9876/__chutzpah__/chutzpah_boot.js?sha=6befcd00fd543581d2a8ac76e852d5909901f326
vstest.console.exe Information: 0 : Time:11:32:42.6973347; Thread:10; Message:Phantom Log - isQunitLoaded
vstest.console.exe Information: 0 : Time:11:32:42.8493485; Thread:10; Message:Phantom Log - Resource Received: http://localhost:9876/__chutzpah__/QUnit/v1/qunit.css?sha=59fa172bfe0e043feb694fbff923fd3d221c0026
vstest.console.exe Information: 0 : Time:11:32:42.9043536; Thread:10; Message:Phantom Log - Resource Received: http://localhost:9876/_agents/<redacted>/Utils/preInit.js?sha=9b6369360c4ada3815cbdaa2d503b72af48ce370
...many similar lines skipped...
vstest.console.exe Information: 0 : Time:11:32:47.3227469; Thread:8; Message:Test harness 'C:\_agents\<redacted>\_Chutzpah.87ef6c34eb5ec093d62ffa993dcf1e82baa79268.test.html' for file 'C:\_agents\<redacted>\RestoringCursorPositionTests.js' finished with 35 passed, 0 failed and 0 errors
vstest.console.exe Information: 0 : Time:11:32:47.3447504; Thread:8; Message:Finished running headless browser on test harness 'C:\_agents\<redacted>\_Chutzpah.87ef6c34eb5ec093d62ffa993dcf1e82baa79268.test.html' for file 'C:\_agents\<redacted>\RestoringCursorPositionTests.js'
vstest.console.exe Information: 0 : Time:11:32:47.3627507; Thread:8; Message:Finished test run for C:\_agents\<redacted>\RestoringCursorPositionTests.js in Execution mode

Failed run

vstest.console.exe Information: 0 : Time:12:23:43.1363162; Thread:8; Message:Invoking headless browser on test harness 'C:\_agents\<redacted>\_Chutzpah.87ef6c34eb5ec093d62ffa993dcf1e82baa79268.test.html' for file 'C:\_agents\<redacted>\RestoringCursorPositionTests.js'
vstest.console.exe Information: 0 : Time:12:23:43.8383799; Thread:8; Message:Started headless browser: <path_to_Chutzpah.4.4.12>\Node\x86\node.exe with PID: 1792 using args:  "<path_to_Chutzpah.4.4.12>\ChutzpahJSRunners\Chrome\qunitRunner.js" "http://localhost:9876/_agents/<redacted>/_Chutzpah.87ef6c34eb5ec093d62ffa993dcf1e82baa79268.test.html" execution 10000 True False "C:\Program Files\Google\Chrome\Application\chrome.exe" "" ""
vstest.console.exe Information: 0 : Time:12:23:46.5776240; Thread:6; Message:Phantom Log - Using Chrome Install : C:\Program Files\Google\Chrome\Application\chrome.exe
vstest.console.exe Information: 0 : Time:12:23:46.6176283; Thread:6; Message:Phantom Log - puppeteer browser args: ["--disable-web-security","--no-sandbox"]
vstest.console.exe Error: 0 : Time:12:23:57.1475751; Thread:8; Message:Test file 'C:\_agents\<redacted>\RestoringCursorPositionTests.js' timed out after running for 10502.9452 milliseconds
vstest.console.exe Information: 0 : Time:12:23:57.1985723; Thread:8; Message:Ended headless browser: <path_to_Chutzpah.4.4.12>\Node\x86\node.exe with PID: 1792 using args:  "<path_to_Chutzpah.4.4.12>\ChutzpahJSRunners\Chrome\qunitRunner.js" "http://localhost:9876/_agents/<redacted>/_Chutzpah.87ef6c34eb5ec093d62ffa993dcf1e82baa79268.test.html" execution 10000 True False "C:\Program Files\Google\Chrome\Application\chrome.exe" "" ""
vstest.console.exe Error: 0 : Time:12:23:57.2395754; Thread:8; Message:Headless browser returned with an error: Timeout occurred when executing test file
vstest.console.exe Information: 0 : Time:12:23:57.2875808; Thread:8; Message:Test harness 'C:\_agents\<redacted>\_Chutzpah.87ef6c34eb5ec093d62ffa993dcf1e82baa79268.test.html' for file 'C:\_agents\<redacted>\RestoringCursorPositionTests.js' finished with 0 passed, 0 failed and 1 errors
vstest.console.exe Information: 0 : Time:12:23:57.3205833; Thread:8; Message:Finished running headless browser on test harness 'C:\_agents\<redacted>\_Chutzpah.87ef6c34eb5ec093d62ffa993dcf1e82baa79268.test.html' for file 'C:\_agents\<redacted>\RestoringCursorPositionTests.js'
vstest.console.exe Information: 0 : Time:12:23:57.3595865; Thread:8; Message:Finished test run for C:\_agents\<redacted>\RestoringCursorPositionTests.js in Execution mode

Basically, there are no Resource Received: http://... entries in the failed run log. Looks like the harness didn't even start to load. Are there any ideas on what other diagnostics I could perform?

P.S. I had to clean-up and simplify the logs to paste them here publicly. I can provide the full logs if needed.

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

1 participant