Intermittent [tier 2] MnFr testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestPageLoadStrategy.test_none | IOError: Process killed because the connection to Marionette server is lost.
Categories
(Testing :: Marionette Client and Harness, defect, P5)
Tracking
(firefox85 fixed)
Tracking | Status | |
---|---|---|
firefox85 | --- | fixed |
People
(Reporter: intermittent-bug-filer, Assigned: whimboo)
References
Details
(Keywords: intermittent-failure, Whiteboard: [stockwell disable-recommended])
Attachments
(1 file)
(deleted),
text/x-phabricator-request
|
Details |
Filed by: rmaries [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=320671294&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/WHunAw2XQQ6_GgvqPJwRFQ/runs/0/artifacts/public/logs/live_backing.log
[task 2020-11-04T02:33:38.443Z] 02:33:38 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestPageLoadStrategy.test_none
[task 2020-11-04T02:37:31.351Z] 02:37:31 INFO - DEBUG: Completed blocker places.sqlite#2: PlacesUtils: promiseKeywordsCache (0) for phase places.sqlite#2: waiting for clients
[task 2020-11-04T02:39:38.564Z] 02:39:38 INFO - 1604457578557 Marionette DEBUG Closed connection 26
[task 2020-11-04T02:40:49.694Z] 02:40:49 ERROR - TEST-UNEXPECTED-ERROR | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestPageLoadStrategy.test_none | IOError: Process killed because the connection to Marionette server is lost. Check gecko.log for errors (Reason: Connection timed out after 360.0s)
[task 2020-11-04T02:40:49.694Z] 02:40:49 INFO - Traceback (most recent call last):
[task 2020-11-04T02:40:49.695Z] 02:40:49 INFO - File "C:\Users\task_1604449495\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 214, in run
[task 2020-11-04T02:40:49.696Z] 02:40:49 INFO - testMethod()
[task 2020-11-04T02:40:49.696Z] 02:40:49 INFO - File "C:\Users\task_1604449495\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit\test_navigation.py", line 925, in test_none
[task 2020-11-04T02:40:49.696Z] 02:40:49 INFO - message="Target page has not been loaded",
[task 2020-11-04T02:40:49.697Z] 02:40:49 INFO - File "C:\Users\task_1604449495\build\venv\lib\site-packages\marionette_driver\wait.py", line 134, in until
[task 2020-11-04T02:40:49.697Z] 02:40:49 INFO - rv = condition(self.marionette)
[task 2020-11-04T02:40:49.697Z] 02:40:49 INFO - File "C:\Users\task_1604449495\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit\test_navigation.py", line 924, in <lambda>
[task 2020-11-04T02:40:49.697Z] 02:40:49 INFO - lambda _: self.marionette.get_url() == self.test_page_slow_resource,
[task 2020-11-04T02:40:49.697Z] 02:40:49 INFO - File "C:\Users\task_1604449495\build\venv\lib\site-packages\marionette_driver\marionette.py", line 1464, in get_url
[task 2020-11-04T02:40:49.697Z] 02:40:49 INFO - return self._send_message("WebDriver:GetCurrentURL", key="value")
[task 2020-11-04T02:40:49.697Z] 02:40:49 INFO - File "C:\Users\task_1604449495\build\venv\lib\site-packages\marionette_driver\decorators.py", line 37, in _
[task 2020-11-04T02:40:49.697Z] 02:40:49 INFO - m._handle_socket_failure()
[task 2020-11-04T02:40:49.697Z] 02:40:49 INFO - File "C:\Users\task_1604449495\build\venv\lib\site-packages\marionette_driver\marionette.py", line 712, in _handle_socket_failure
[task 2020-11-04T02:40:49.697Z] 02:40:49 INFO - IOError, IOError(message.format(returncode=returncode, reason=exc)), tb
[task 2020-11-04T02:40:49.698Z] 02:40:49 INFO - File "C:\Users\task_1604449495\build\venv\lib\site-packages\marionette_driver\decorators.py", line 27, in _
[task 2020-11-04T02:40:49.698Z] 02:40:49 INFO - return func(*args, **kwargs)
[task 2020-11-04T02:40:49.698Z] 02:40:49 INFO - File "C:\Users\task_1604449495\build\venv\lib\site-packages\marionette_driver\marionette.py", line 617, in _send_message
[task 2020-11-04T02:40:49.698Z] 02:40:49 INFO - msg = self.client.request(name, params)
[task 2020-11-04T02:40:49.698Z] 02:40:49 INFO - File "C:\Users\task_1604449495\build\venv\lib\site-packages\marionette_driver\transport.py", line 288, in request
[task 2020-11-04T02:40:49.698Z] 02:40:49 INFO - return self.receive()
[task 2020-11-04T02:40:49.698Z] 02:40:49 INFO - File "C:\Users\task_1604449495\build\venv\lib\site-packages\marionette_driver\transport.py", line 192, in receive
[task 2020-11-04T02:40:49.698Z] 02:40:49 INFO - "Connection timed out after {}s".format(self.socket_timeout)
[task 2020-11-04T02:40:49.698Z] 02:40:49 INFO - TEST-INFO took 431250ms
[task 2020-11-04T02:40:49.698Z] 02:40:49 INFO - Application command: C:\Users\task_1604449495\build\application\firefox\firefox.exe -no-remote -marionette --wait-for-browser -profile c:\users\task_1604449495\appdata\local\temp\tmp6r5mzw.mozrunner
[task 2020-11-04T02:40:49.859Z] 02:40:49 INFO - DEBUG: Adding blocker OS.File: flush pending requests, warn about unclosed files, shut down service. for phase xpcom-will-shutdown
[task 2020-11-04T02:40:49.859Z] 02:40:49 INFO - DEBUG: Adding blocker OS.File: flush I/O queued before profileBeforeChange for phase profile-before-change
[task 2020-11-04T02:40:49.859Z] 02:40:49 INFO - DEBUG: Adding blocker AddonManager: shutting down. for phase profile-before-change
[task 2020-11-04T02:40:49.878Z] 02:40:49 INFO - DEBUG: Adding blocker ClientManagerService: start destroying IPC actors early for phase xpcom-will-shutdown
[task 2020-11-04T02:40:49.928Z] 02:40:49 INFO - DEBUG: Adding blocker Flush WebExtension StartupCache for phase profile-before-change
[task 2020-11-04T02:40:50.018Z] 02:40:50 INFO - DEBUG: Adding blocker JSON store: writing data for phase AddonManager: Waiting for providers to shut down.
[task 2020-11-04T02:40:50.023Z] 02:40:50 INFO - DEBUG: Adding blocker Update add-on blocklist state into add-on DB for phase AddonManager: Waiting to start provider shutdown.
[task 2020-11-04T02:40:50.023Z] 02:40:50 INFO - DEBUG: Completed blocker Update add-on blocklist state into add-on DB for phase AddonManager: Waiting to start provider shutdown.
[task 2020-11-04T02:40:50.028Z] 02:40:50 INFO - DEBUG: Adding blocker XPIProvider shutdown for phase quit-application-granted
[task 2020-11-04T02:40:50.028Z] 02:40:50 INFO - DEBUG: Adding blocker XPIProvider for phase AddonManager: Waiting for providers to shut down.
[task 2020-11-04T02:40:50.028Z] 02:40:50 INFO - DEBUG: Adding blocker PluginProvider for phase AddonManager: Waiting for providers to shut down.
[task 2020-11-04T02:40:50.030Z] 02:40:50 INFO - DEBUG: Adding blocker ServiceWorkerRegistrar: Flushing data for phase profile-before-change
[task 2020-11-04T02:40:50.032Z] 02:40:50 INFO - DEBUG: Adding blocker CrashMonitor: Writing notifications to file after receiving profile-before-change for phase OS.File: Waiting for clients before profileBeforeChange
[task 2020-11-04T02:40:50.051Z] 02:40:50 INFO - DEBUG: Adding blocker TelemetryController: shutting down for phase profile-before-change-telemetry
[task 2020-11-04T02:40:50.074Z] 02:40:50 INFO - DEBUG: Adding blocker EnvironmentAddonBuilder for phase AddonManager: Waiting to start provider shutdown.
[task 2020-11-04T02:40:50.084Z] 02:40:50 INFO - DEBUG: Adding blocker RemoteSettingsClient - finish IDB access. for phase profile-before-change```
Assignee | ||
Comment 1•4 years ago
|
||
Hangs when trying to get the current URL:
[task 2020-11-04T02:33:38.544Z] 02:33:38 INFO - 1604457218541 Marionette DEBUG 26 -> [0,4,"WebDriver:GetCurrentURL",{}]
[task 2020-11-04T02:33:38.544Z] 02:33:38 INFO - 1604457218542 Marionette TRACE [90] Frame script unloaded
[task 2020-11-04T02:33:38.548Z] 02:33:38 INFO - 1604457218546 Marionette TRACE [90] Frame script loaded
[task 2020-11-04T02:33:38.548Z] 02:33:38 INFO - 1604457218546 Marionette TRACE Detected remoteness change. New browsing context: 90
To get this fixed our actors have to be enabled for all builds. See bug 1669169.
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 4•4 years ago
|
||
Those failures were only logged on November 4th. Since then no more failures seem to have happened. Lets close the bug as incomplete for now.
Assignee | ||
Comment 6•4 years ago
|
||
The recent failures are:
[task 2020-11-16T19:12:24.990Z] 19:12:24 INFO - 1605553944985 Marionette DEBUG 26 -> [0,4,"WebDriver:GetCurrentURL",{}]
[task 2020-11-16T19:12:24.990Z] 19:12:24 INFO - 1605553944988 Marionette TRACE [90] Frame script unloaded
[task 2020-11-16T19:12:25.009Z] 19:12:25 INFO - 1605553944997 Marionette TRACE [90] Frame script loaded
[task 2020-11-16T19:12:25.016Z] 19:12:25 INFO - 1605553945008 Marionette TRACE Detected remoteness change. New browsing context: 90
..
[task 2020-11-16T19:18:25.069Z] 19:18:25 INFO - 1605554305033 Marionette DEBUG Closed connection 26
So due to a browsing context swap the Get Current URL
doesn't seem to return. Usually that shouldn't happen given that the actor gets destroyed and the proxy retries the command for the new browsing context.
Maybe lets wait for bug 1674329 being fixed.
Comment hidden (Intermittent Failures Robot) |
Comment 8•4 years ago
|
||
This bug failed 47 times in the last 7 days. Occurs on linux1804-64, macosx1014-64-qr, windows10-64 and windows7-32 on opt build types.
Recent log:
https://treeherder.mozilla.org/logviewer?job_id=322919120&repo=autoland&lineNumber=22277
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 10•4 years ago
|
||
This only affects MnFr jobs now that are running as Tier 2. Lets see how often this happens. If it fails still too often we should skip the test when actors aren't enabled.
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 12•4 years ago
|
||
It's not worth the time to fix this particular bug in the old
framescript code that will go away early next year.
Updated•4 years ago
|
Comment 13•4 years ago
|
||
Pushed by hskupin@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/907b02c68bfb [marionette] Disable TestPageLoadStrategy.test_none when actors are disabled. r=marionette-reviewers,jgraham
Comment 14•4 years ago
|
||
bugherder |
Comment hidden (Intermittent Failures Robot) |
Updated•2 years ago
|
Comment 16•2 years ago
|
||
Moving bug to Testing::Marionette Client and Harness component per bug 1815831.
Description
•