Intermittent Mn/MnH win7-32 Automation Error: mozprocess timed out after 1000 seconds running (Exiting due to channel error)
Categories
(Testing :: Marionette Client and Harness, defect, P5)
Tracking
(Not tracked)
People
(Reporter: intermittent-bug-filer, Unassigned)
References
Details
(Keywords: intermittent-failure, regression, Whiteboard: [blocked by bug 1521447][stockwell unknown])
#[markdown(off)]
Filed by: hskupin [at] mozilla.com
https://treeherder.mozilla.org/logviewer.html#?job_id=227439568&repo=mozilla-central
Failures here are all happening due to channel errors:
22:59:37 INFO - 1549753177844 Marionette DEBUG 3 -> [0,6,"WebDriver:DeleteSession",{}]
22:59:37 INFO - 1549753177847 Marionette DEBUG 3 <- [1,6,null,{"value":null}]
22:59:37 INFO - Exiting due to channel error.
Maybe this is a hang in ProcessChild::QuickExit()?
James, could you have a look at this problem given that you added this feature? Currently this is a high frequent intermittent failure on Windows7 32bit only.
Here the current intermittent view (note that all failures have been classified for bug 1391545 so far:
There is actually bug 1521447, which covers the underlying problem in Firefox. So lets move the discussion over there.
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 6•6 years ago
|
||
There are 25 total failures in the last 7 days and 56 total failures in the last 30 days on windows7-32 all build types.
Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=232947961&repo=mozilla-inbound&lineNumber=31556
23:55:04 INFO - TEST-START | testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py TestQuitRestartWithWorkspace.test_restart_clean_creates_new_profile
23:55:04 INFO - 1552175704222 Marionette DEBUG 3 -> [0,2,"WebDriver:DeleteSession",{}]
23:55:04 INFO - 1552175704223 Marionette DEBUG 3 <- [1,2,null,{"value":null}]
23:55:04 INFO - 1552175704224 Marionette DEBUG Closed connection 3
23:55:04 INFO - 1552175704226 Marionette DEBUG Accepted connection 4 from 127.0.0.1:50862
23:55:04 INFO - 1552175704227 Marionette DEBUG 4 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
23:55:04 INFO - 1552175704236 Marionette TRACE [2147483649] Frame script loaded
23:55:04 INFO - 1552175704236 Marionette TRACE [2147483649] Frame script registered
23:55:04 INFO - 1552175704237 Marionette DEBUG 4 <- [1,1,null,{"sessionId":"3b60a8ae-46f9-442b-b630-de822a3c4784","capabilities":{"browserName":"firefox","browserVersion":"67.0a ... s\tmphxmqek.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
23:55:04 INFO - 1552175704238 Marionette DEBUG 4 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
23:55:04 INFO - 1552175704239 Marionette DEBUG 4 <- [1,2,null,{"value":null}]
23:55:04 INFO - 1552175704239 Marionette DEBUG 4 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
23:55:04 INFO - 1552175704240 Marionette DEBUG 4 <- [1,3,null,{"value":null}]
23:55:04 INFO - 1552175704241 Marionette DEBUG 4 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
23:55:04 INFO - 1552175704242 Marionette DEBUG 4 <- [1,4,null,{"value":null}]
23:55:04 INFO - 1552175704243 Marionette DEBUG 4 -> [0,5,"Marionette:GetContext",{}]
23:55:04 INFO - 1552175704244 Marionette DEBUG 4 <- [1,5,null,{"value":"content"}]
23:55:04 INFO - 1552175704244 Marionette DEBUG 4 -> [0,6,"WebDriver:DeleteSession",{}]
23:55:04 INFO - 1552175704245 Marionette DEBUG 4 <- [1,6,null,{"value":null}]
23:55:04 INFO - Exiting due to channel error.
00:11:44 INFO - Automation Error: mozprocess timed out after 1000 seconds running ['Z:\task_1552174753\build\venv\Scripts\python', '-u', 'Z:\task_1552174753\build\tests\marionette\harness\marionette_harness\runtests.py', '--gecko-log=-', '-vv', '--log-raw=Z:\task_1552174753\build\blobber_upload_dir\marionette_raw.log', '--log-errorsummary=Z:\task_1552174753\build\blobber_upload_dir\marionette_errorsummary.log', '--log-html=Z:\task_1552174753\build\blobber_upload_dir\report.html', '--binary=Z:\task_1552174753\build\application\firefox\firefox.exe', '--address=localhost:2828', '--symbols-path=https://queue.taskcluster.net/v1/task/XU6DI-5ORXamUIeWbGpjiw/artifacts/public/build/target.crashreporter-symbols.zip', 'Z:\task_1552174753\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit-tests.ini']
00:11:44 ERROR - timed out after 1000 seconds of no output
00:11:44 ERROR - Return code: 572
00:11:44 INFO - TinderboxPrint: marionette<br/><em class="testfail">T-FAIL</em>
00:11:44 INFO - gecko.log not found
00:11:44 INFO - TinderboxPrint: marionette<br/><em class="testfail">T-FAIL</em>
00:11:44 INFO - Marionette exited with return code 572: FAILURE
00:11:44 ERROR - # TBPL FAILURE #
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 9•6 years ago
|
||
There have been 34 failures within the last 7 days, all of them on Windows 7 x32
recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=234664378&repo=mozilla-central&lineNumber=41748
23:14:41 INFO - TEST-START | testing\marionette\harness\marionette_harness\tests\unit\test_profile_management.py TestSwitchProfileWithWorkspace.test_clone_existing_profile
23:14:41 INFO - 1552950881840 Marionette DEBUG Closed connection 4
23:14:41 INFO - 1552950881841 Marionette DEBUG Accepted connection 5 from 127.0.0.1:51121
23:14:41 INFO - 1552950881843 Marionette DEBUG 5 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
23:14:41 INFO - 1552950881847 Marionette TRACE [2147483649] Frame script loaded
23:14:41 INFO - 1552950881848 Marionette TRACE [2147483649] Frame script registered
23:14:41 INFO - 1552950881851 Marionette DEBUG 5 <- [1,1,null,{"sessionId":"06ae1982-9c61-4e77-aee5-3cf73a68c9ac","capabilities":{"browserName":"firefox","browserVersion":"68.0a ... p\tmpxy_98u.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
23:14:41 INFO - 1552950881853 Marionette DEBUG 5 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
23:14:41 INFO - 1552950881854 Marionette DEBUG 5 <- [1,2,null,{"value":null}]
23:14:41 INFO - 1552950881859 Marionette DEBUG 5 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
23:14:41 INFO - 1552950881862 Marionette DEBUG 5 <- [1,3,null,{"value":null}]
23:14:41 INFO - 1552950881863 Marionette DEBUG 5 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
23:14:41 INFO - 1552950881864 Marionette DEBUG 5 <- [1,4,null,{"value":null}]
23:14:41 INFO - Exiting due to channel error.
23:14:41 INFO - Exiting due to channel error.
23:31:21 INFO - Automation Error: mozprocess timed out after 1000 seconds running ['Z:\task_1552950053\build\venv\Scripts\python', '-u', 'Z:\task_1552950053\build\tests\marionette\harness\marionette_harness\runtests.py', '--gecko-log=-', '-vv', '--log-raw=Z:\task_1552950053\build\blobber_upload_dir\marionette_raw.log', '--log-errorsummary=Z:\task_1552950053\build\blobber_upload_dir\marionette_errorsummary.log', '--log-html=Z:\task_1552950053\build\blobber_upload_dir\report.html', '--binary=Z:\task_1552950053\build\application\firefox\firefox.exe', '--address=localhost:2828', '--symbols-path=Z:\task_1552950053\build\symbols', 'Z:\task_1552950053\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit-tests.ini']
23:31:21 ERROR - timed out after 1000 seconds of no output
23:31:21 ERROR - Return code: 572
23:31:21 INFO - TinderboxPrint: marionette<br/><em class="testfail">T-FAIL</em>
23:31:21 INFO - gecko.log not found
23:31:21 INFO - TinderboxPrint: marionette<br/><em class="testfail">T-FAIL</em>
23:31:21 INFO - Marionette exited with return code 572: FAILURE
23:31:21 ERROR - # TBPL FAILURE #
| Comment hidden (Intermittent Failures Robot) |
Comment 11•6 years ago
|
||
There have been 35 failures within the last 7 days, all of them on Windows 7 x32 and windows7-32-shippable.
recent log: https://treeherder.mozilla.org/logviewer.html#?job_id=236375311&repo=autoland
| Comment hidden (Intermittent Failures Robot) |
Comment 13•6 years ago
|
||
There are 36 total failures in the last 7 days on windows7-32 debug and windows7-32-shippable opt
Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=238505991&repo=autoland&lineNumber=42667
21:53:46 INFO - Exiting due to channel error.
21:53:46 INFO - Exiting due to channel error.
22:10:26 INFO - Automation Error: mozprocess timed out after 1000 seconds running ['Z:\task_1554499995\build\venv\Scripts\python', '-u', 'Z:\task_1554499995\build\tests\marionette\harness\marionette_harness\runtests.py', '--gecko-log=-', '-vv', '--log-raw=Z:\task_1554499995\build\blobber_upload_dir\marionette_raw.log', '--log-errorsummary=Z:\task_1554499995\build\blobber_upload_dir\marionette_errorsummary.log', '--log-html=Z:\task_1554499995\build\blobber_upload_dir\report.html', '--binary=Z:\task_1554499995\build\application\firefox\firefox.exe', '--address=localhost:2828', '--symbols-path=Z:\task_1554499995\build\symbols', 'Z:\task_1554499995\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit-tests.ini']
22:10:26 ERROR - timed out after 1000 seconds of no output
22:10:26 ERROR - Return code: 572
22:10:26 INFO - TinderboxPrint: marionette<br/><em class="testfail">T-FAIL</em>
22:10:26 INFO - gecko.log not found
22:10:26 INFO - TinderboxPrint: marionette<br/><em class="testfail">T-FAIL</em>
22:10:26 INFO - Marionette exited with return code 572: FAILURE
22:10:26 ERROR - # TBPL FAILURE #
22:10:26 WARNING - setting return code to 2
22:10:26 INFO - Running post-action listener: _package_coverage_data
22:10:26 INFO - Running post-action listener: _resource_record_post_action
22:10:26 INFO - Running post-action listener: process_java_coverage_data
22:10:26 INFO - [mozharness: 2019-04-05 22:10:26.641000Z] Finished run-tests step (success)
22:10:26 INFO - Running post-run listener: _resource_record_post_run
22:10:26 INFO - Total resource usage - Wall time: 1370s; CPU: 5.0%; Read bytes: 1987837952; Write bytes: 766724096; Read time: 19; Write time: 29
22:10:26 INFO - TinderboxPrint: CPU usage<br/>5.2%
22:10:26 INFO - TinderboxPrint: I/O read bytes / time<br/>1,987,837,952 / 19
22:10:26 INFO - TinderboxPrint: I/O write bytes / time<br/>766,724,096 / 29
22:10:26 INFO - TinderboxPrint: CPU idle<br/>10,387.7 (94.8%)
22:10:26 INFO - TinderboxPrint: CPU system<br/>123.7 (1.1%)
22:10:26 INFO - TinderboxPrint: CPU user<br/>447.2 (4.1%)
22:10:26 INFO - install - Wall time: 4s; CPU: 11.0%; Read bytes: 0; Write bytes: 89935872; Read time: 0; Write time: 1
22:10:26 INFO - run-tests - Wall time: 1367s; CPU: 5.0%; Read bytes: 1987837952; Write bytes: 530973184; Read time: 19; Write time: 27
22:10:27 WARNING - returning nonzero exit status 2
[taskcluster 2019-04-05T22:10:27.384Z] Exit Code: 2
[taskcluster 2019-04-05T22:10:27.384Z] User Time: 0s
[taskcluster 2019-04-05T22:10:27.384Z] Kernel Time: 0s
[taskcluster 2019-04-05T22:10:27.384Z] Wall Time: 30m10.3206193s
[taskcluster 2019-04-05T22:10:27.384Z] Result: FAILED
[taskcluster 2019-04-05T22:10:27.384Z] === Task Finished ===
[taskcluster 2019-04-05T22:10:27.384Z] Task Duration: 30m10.3236202s
[taskcluster 2019-04-05T22:10:28.310Z] Uploading artifact public/logs/localconfig.json from file logs\localconfig.json with content encoding "gzip", mime type "application/octet-stream" and expiry 2020-04-04T20:38:55.177Z
[taskcluster 2019-04-05T22:10:29.356Z] Uploading artifact public/test_info/marionette_errorsummary.log from file build\blobber_upload_dir\marionette_errorsummary.log with content encoding "gzip", mime type "text/plain" and expiry 2020-04-04T20:38:55.177Z
[taskcluster 2019-04-05T22:10:29.896Z] Uploading artifact public/test_info/marionette_raw.log from file build\blobber_upload_dir\marionette_raw.log with content encoding "gzip", mime type "text/plain" and expiry 2020-04-04T20:38:55.177Z
[taskcluster 2019-04-05T22:10:31.084Z] Uploading artifact public/test_info/report.html from file build\blobber_upload_dir\report.html with content encoding "gzip", mime type "text/html; charset=utf-8" and expiry 2020-04-04T20:38:55.177Z
[taskcluster 2019-04-05T22:10:31.583Z] Uploading artifact public/test_info/resource-usage.json from file build\blobber_upload_dir\resource-usage.json with content encoding "gzip", mime type "application/octet-stream" and expiry 2020-04-04T20:38:55.177Z
[taskcluster 2019-04-05T22:10:32.831Z] Uploading redirect artifact public/logs/live.log to URL https://queue.taskcluster.net/v1/task/SsM8Vy_pQpSPxC4PLNEvDg/runs/0/artifacts/public/logs/live_backing.log with mime type "text/plain; charset=utf-8" and expiry 2020-04-04T20:38:55.177Z
[taskcluster:error] exit status 2
Henrik is this something you can take a look at? Will it be fixed with bug 1521447?
| Comment hidden (Intermittent Failures Robot) |
(In reply to Andreea Pavel [:apavel] from comment #13)
Henrik is this something you can take a look at? Will it be fixed with bug 1521447?
This is all blocked by bug 1521447, right. There is nothing I can do at this point. I'm also not sure if gbrown or bc had luck the last weeks to get closer to the problem.
Comment 16•6 years ago
|
||
I updated bug 1521447 just now, but just with thoughts and feelings: I don't have any concrete progress to report, and haven't been finding time to get back to that investigation.
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Cosmin, can we please stop classifying failures against this bug which are not Marionette related? Thanks.
Comment 27•6 years ago
|
||
(In reply to Henrik Skupin (:whimboo) [⌚️UTC+2] from comment #26)
Cosmin, can we please stop classifying failures against this bug which are not Marionette related? Thanks.
I removed the classifications for the ones that were not marionette related.
Comment 28•6 years ago
|
||
Yes, sorry about that.
| Comment hidden (Intermittent Failures Robot) |
Note that all the failures for MacOS are related to bug 1495621. With the backout of the appropriate patch it's all good again.
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Most of the recent failures where all due to bug 1638148. The offending patch got backed out.
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
All the failures happen due to the following error:
[task 2020-12-18T04:58:46.105Z] 04:58:46 INFO - Exiting due to channel error.
[task 2020-12-18T04:58:46.105Z] 04:58:46 INFO - Exiting due to channel error.
[task 2020-12-18T04:58:46.112Z] 04:58:46 INFO - [5732, Main Thread] WARNING: Could not setup crash reporting
[task 2020-12-18T04:58:46.112Z] 04:58:46 INFO - : file /builds/worker/checkouts/gecko/toolkit/xre/nsEmbedFunctions.cpp:521
[task 2020-12-18T04:58:46.112Z] 04:58:46 INFO - [5732, IPC I/O Child] WARNING: failed to create pipe: 2: file /builds/worker/checkouts/gecko/ipc/chromium/src/chrome/common/ipc_channel_win.cc:238
[task 2020-12-18T04:58:46.113Z] 04:58:46 INFO - [5732, IPC I/O Child] WARNING: Unable to create pipe named "4368.13.70523074\1684086862" in client mode.: file /builds/worker/checkouts/gecko/ipc/chromium/src/chrome/common/ipc_channel_win.cc:71
[task 2020-12-18T05:15:26.133Z] 05:15:26 INFO - Automation Error: mozprocess timed out after 1000 seconds running ...
That refers to the following code:
James, it's been a while since you changed that code on bug 1354200, but do you have an idea why QuickExit() doesn't work here and causes a hang?
In cases when we don't hang forever (see bug 1675175) the Marionette server in Firefox and its active socket connection gets actually closed:
https://treeherder.mozilla.org/logviewer?job_id=324937807&repo=autoland&lineNumber=21661-21673
[task 2020-12-18T15:10:21.234Z] 15:10:21 INFO - 1608304221233 Marionette TRACE [82] Frame script loaded
[task 2020-12-18T15:10:21.253Z] 15:10:21 INFO - 1608304221242 Marionette TRACE Detected remoteness change. New browsing context: 82
[task 2020-12-18T15:10:30.549Z] 15:10:30 INFO - DEBUG: Adding blocker SessionFile: Finish writing Session Restore data for phase profile-before-change
[task 2020-12-18T15:10:30.552Z] 15:10:30 INFO - DEBUG: Completed blocker SessionFile: Finish writing Session Restore data for phase profile-before-change
[task 2020-12-18T15:10:32.547Z] 15:10:32 INFO - DEBUG: Adding blocker JSON store: writing data for phase profile-before-change
[task 2020-12-18T15:14:12.613Z] 15:14:12 INFO - DEBUG: Adding blocker places.sqlite#1: PlacesUtils: promiseKeywordsCache (1) for phase places.sqlite#1: waiting for clients
[task 2020-12-18T15:14:12.613Z] 15:14:12 INFO - DEBUG: Completed blocker places.sqlite#1: PlacesUtils: promiseKeywordsCache (1) for phase places.sqlite#1: waiting for clients
[task 2020-12-18T15:16:21.332Z] 15:16:21 INFO - 1608304581326 Marionette DEBUG Closed connection 20
[task 2020-12-18T15:17:32.351Z] 15:17:32 INFO - Exiting due to channel error.
[task 2020-12-18T15:17:32.351Z] 15:17:32 INFO - Exiting due to channel error.
[task 2020-12-18T15:17:32.478Z] 15:17:32 ERROR - TEST-UNEXPECTED-ERROR | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestNavigate.test_type_to_remote_tab | IOError: Process killed because the connection to Marionette server is lost. Check gecko.log for errors (Reason: Connection timed out after 360.0s)
Maybe there are cases when we leak the socket thread during quick shutdown?
(In reply to Henrik Skupin (:whimboo) [⌚️UTC+2] from comment #100)
All the failures happen due to the following error:
[task 2020-12-18T04:58:46.105Z] 04:58:46 INFO - Exiting due to channel error. [task 2020-12-18T04:58:46.105Z] 04:58:46 INFO - Exiting due to channel error. [task 2020-12-18T04:58:46.112Z] 04:58:46 INFO - [5732, Main Thread] WARNING: Could not setup crash reporting [task 2020-12-18T04:58:46.112Z] 04:58:46 INFO - : file /builds/worker/checkouts/gecko/toolkit/xre/nsEmbedFunctions.cpp:521 [task 2020-12-18T04:58:46.112Z] 04:58:46 INFO - [5732, IPC I/O Child] WARNING: failed to create pipe: 2: file /builds/worker/checkouts/gecko/ipc/chromium/src/chrome/common/ipc_channel_win.cc:238 [task 2020-12-18T04:58:46.113Z] 04:58:46 INFO - [5732, IPC I/O Child] WARNING: Unable to create pipe named "4368.13.70523074\1684086862" in client mode.: file /builds/worker/checkouts/gecko/ipc/chromium/src/chrome/common/ipc_channel_win.cc:71 [task 2020-12-18T05:15:26.133Z] 05:15:26 INFO - Automation Error: mozprocess timed out after 1000 seconds running ...That refers to the following code:
James, it's been a while since you changed that code on bug 1354200, but do you have an idea why QuickExit() doesn't work here and causes a hang?
No idea, sorry. I'm not sure who still knows about that stuff. Maybe @aklotz due to the windowsness here?
Comment 103•5 years ago
•
|
||
From the documentation for TerminateProcess:
This function stops execution of all threads within the process and requests cancellation of all pending I/O. The terminated process cannot exit until all pending I/O has been completed or canceled. When a process terminates, its kernel object is not destroyed until all processes that have open handles to the process have released those handles.
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Aaron, so it means that some Firefox process doesn't quit because there is some I/O that cannot be completed within 15 (and more) minutes during a shutdown? Would there be a way to figure out which process that is? Or is it not worth investigating this issue given the low amount of failures and that it only happens on Windows 7?
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Aaron, do you have any further feedback to my last question? Thanks.
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 117•4 years ago
|
||
(In reply to Henrik Skupin (:whimboo) [⌚️UTC+1] from comment #106)
Aaron, so it means that some Firefox process doesn't quit because there is some I/O that cannot be completed within 15 (and more) minutes during a shutdown? Would there be a way to figure out which process that is? Or is it not worth investigating this issue given the low amount of failures and that it only happens on Windows 7?
I guess I should back up and ask: are we piping any of Firefox's std handles? My train of thought here is that maybe it's waiting on a write to stdout to complete or something...
| Comment hidden (Intermittent Failures Robot) |
Hm, there seems to be something that's wrong in recent jobs. After the call to WebDriver:DeleteSession it just stops and no further logging appears until the covered failure by this bug. The question is if we really don't execute any following command, after creating a new session, or if stdout simply hangs and/or is not logged.
At least what I can see now is that the hang doesn't seem to happen when requesting a quit, but just after a test ended. Given that I have more important test failures to investigate that bug will be sitting on the back burner.
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
No more failures within the last year. As such closing as WFM.
Updated•3 years ago
|
Comment 129•2 years ago
|
||
Description
•