Closed
Bug 1458725
Opened 7 years ago
Closed 7 years ago
Intermittent testing/marionette/harness/marionette_harness/tests/unit/test_quit_restart.py TestServerQuitApplication.test_attempt_quit | IOError: Process killed after 120s because no connection to Marionette server could be established.
Categories
(Testing :: Marionette Client and Harness, defect, P5)
Tracking
(firefox61 wontfix, firefox63 fixed, firefox64 fixed)
RESOLVED
FIXED
mozilla64
People
(Reporter: intermittent-bug-filer, Assigned: stransky)
References
Details
(Keywords: intermittent-failure)
Filed by: apavel [at] mozilla.com
https://treeherder.mozilla.org/logviewer.html#?job_id=176646411&repo=autoland
https://queue.taskcluster.net/v1/task/D6SoBRCwTi62lVq4uaTHVg/runs/0/artifacts/public/logs/live_backing.log
[task 2018-05-02T22:30:27.537Z] 22:30:27 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_quit_restart.py TestServerQuitApplication.test_attempt_quit
[task 2018-05-02T22:30:27.539Z] 22:30:27 INFO - 1525300227537 Marionette DEBUG Closed connection 2
[task 2018-05-02T22:30:27.547Z] 22:30:27 INFO - 1525300227542 Marionette DEBUG Accepted connection 3 from 127.0.0.1:49584
[task 2018-05-02T22:30:27.556Z] 22:30:27 INFO - 1525300227550 Marionette TRACE 3 -> [0,1,"WebDriver:NewSession",{}]
[task 2018-05-02T22:30:27.563Z] 22:30:27 INFO - 1525300227558 Marionette DEBUG Register listener.js for window 2147483649
[task 2018-05-02T22:30:27.572Z] 22:30:27 INFO - 1525300227565 Marionette TRACE 3 <- [1,1,null,{"sessionId":"4707b68e-3cc6-41a9-b42a-f02542a31729","capabilities":{"browserName":"firefox","browserVersion":"61.0a ... ssID":5335,"moz:profile":"/tmp/tmpFr9QFs.mozrunner","moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
[task 2018-05-02T22:30:27.572Z] 22:30:27 INFO - 1525300227568 Marionette TRACE 3 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2018-05-02T22:30:27.574Z] 22:30:27 INFO - 1525300227569 Marionette TRACE 3 <- [1,2,null,{}]
[task 2018-05-02T22:30:27.575Z] 22:30:27 INFO - 1525300227571 Marionette TRACE 3 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2018-05-02T22:30:27.585Z] 22:30:27 INFO - 1525300227576 Marionette TRACE 3 <- [1,3,null,{}]
[task 2018-05-02T22:30:27.587Z] 22:30:27 INFO - 1525300227578 Marionette TRACE 3 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2018-05-02T22:30:27.588Z] 22:30:27 INFO - 1525300227579 Marionette TRACE 3 <- [1,4,null,{}]
[task 2018-05-02T22:30:27.591Z] 22:30:27 INFO - 1525300227581 Marionette TRACE 3 -> [0,5,"quit",{"flags":["eAttemptQuit"]}]
[task 2018-05-02T22:30:27.592Z] 22:30:27 INFO - 1525300227583 Marionette DEBUG New connections will no longer be accepted
[task 2018-05-02T22:30:27.793Z] 22:30:27 INFO - 1525300227784 Marionette TRACE 3 <- [1,5,null,{"cause":"shutdown"}]
[task 2018-05-02T22:30:27.811Z] 22:30:27 INFO - 1525300227803 Marionette DEBUG Closed connection 3
[task 2018-05-02T22:30:28.278Z] 22:30:28 INFO - *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping
[task 2018-05-02T22:30:28.476Z] 22:30:28 INFO - 1525300228468 Marionette DEBUG Received observer notification xpcom-will-shutdown
[task 2018-05-02T22:30:29.802Z] 22:30:29 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -no-remote -marionette -profile /tmp/tmpFr9QFs.mozrunner
[task 2018-05-02T22:32:29.848Z] 22:32:29 INFO - TEST-UNEXPECTED-ERROR | testing/marionette/harness/marionette_harness/tests/unit/test_quit_restart.py TestServerQuitApplication.test_attempt_quit | IOError: Process killed after 120s because no connection to Marionette server could be established. Check gecko.log for errors
[task 2018-05-02T22:32:29.848Z] 22:32:29 INFO - Traceback (most recent call last):
[task 2018-05-02T22:32:29.849Z] 22:32:29 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 190, in run
[task 2018-05-02T22:32:29.850Z] 22:32:29 INFO - self.tearDown()
[task 2018-05-02T22:32:29.851Z] 22:32:29 INFO - File "/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_quit_restart.py", line 15, in tearDown
[task 2018-05-02T22:32:29.852Z] 22:32:29 INFO - self.marionette.start_session()
[task 2018-05-02T22:32:29.853Z] 22:32:29 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/decorators.py", line 26, in _
[task 2018-05-02T22:32:29.853Z] 22:32:29 INFO - return func(*args, **kwargs)
[task 2018-05-02T22:32:29.854Z] 22:32:29 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 1211, in start_session
[task 2018-05-02T22:32:29.855Z] 22:32:29 INFO - self.start_binary(timeout)
[task 2018-05-02T22:32:29.857Z] 22:32:29 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 640, in start_binary
[task 2018-05-02T22:32:29.858Z] 22:32:29 INFO - reraise(IOError, msg.format(timeout), tb)
[task 2018-05-02T22:32:29.859Z] 22:32:29 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 631, in start_binary
[task 2018-05-02T22:32:29.860Z] 22:32:29 INFO - self.raise_for_port(timeout=timeout)
[task 2018-05-02T22:32:29.861Z] 22:32:29 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 711, in raise_for_port
[task 2018-05-02T22:32:29.862Z] 22:32:29 INFO - self.host, self.port))
[task 2018-05-02T22:32:29.863Z] 22:32:29 INFO - TEST-INFO took 122314ms
[task 2018-05-02T22:32:29.864Z] 22:32:29 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_quit_restart.py TestServerQuitApplication.test_empty_default
[task 2018-05-02T22:32:29.865Z] 22:32:29 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -no-remote -marionette -profile /tmp/tmpKkrnxE.mozrunner
[task 2018-05-02T22:32:32.009Z] 22:32:32 INFO - 1525300352003 Marionette DEBUG Received observer notification profile-after-change
[task 2018-05-02T22:32:32.167Z] 22:32:32 INFO - 1525300352155 Marionette DEBUG Received observer notification command-line-startup
[task 2018-05-02T22:32:32.167Z] 22:32:32 INFO - 1525300352155 Marionette DEBUG Received observer notification nsPref:changed
[task 2018-05-02T22:32:35.665Z] 22:32:35 INFO - 1525300355654 Marionette DEBUG Received observer notification sessionstore-windows-restored
[task 2018-05-02T22:32:37.608Z] 22:32:37 INFO - 1525300357594 Marionette DEBUG New connections are accepted
[task 2018-05-02T22:32:37.608Z] 22:32:37 INFO - 1525300357595 Marionette INFO Listening on port 2828
[task 2018-05-02T22:32:37.649Z] 22:32:37 INFO - 1525300357641 Marionette DEBUG Accepted connection 0 from 127.0.0.1:52198
[task 2018-05-02T22:32:37.665Z] 22:32:37 INFO - 1525300357661 Marionette DEBUG Accepted connection 1 from 127.0.0.1:52200
[task 2018-05-02T22:32:37.665Z] 22:32:37 INFO - 1525300357663 Marionette DEBUG Closed connection 0
[task 2018-05-02T22:32:37.698Z] 22:32:37 INFO - 1525300357686 Marionette TRACE 1 -> [0,1,"WebDriver:NewSession",{}]
[task 2018-05-02T22:32:38.004Z] 22:32:38 INFO - 1525300358001 Marionette DEBUG Register listener.js for window 2147483649
[task 2018-05-02T22:32:38.045Z] 22:32:38 INFO - 1525300358041 Marionette TRACE 1 <- [1,1,null,{"sessionId":"3c4b3c71-0b7d-43e4-a3ef-857e055b297d","capabilities":{"browserName":"firefox","browserVersion":"61.0a ... ssID":5483,"moz:profile":"/tmp/tmpKkrnxE.mozrunner","moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
[task 2018-05-02T22:32:38.106Z] 22:32:38 INFO - 1525300358100 Marionette TRACE 1 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2018-05-02T22:32:38.107Z] 22:32:38 INFO - 1525300358104 Marionette TRACE 1 <- [1,2,null,{}]
[task 2018-05-02T22:32:38.124Z] 22:32:38 INFO - 1525300358119 Marionette TRACE 1 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2018-05-02T22:32:38.125Z] 22:32:38 INFO - 1525300358122 Marionette TRACE 1 <- [1,3,null,{}]
[task 2018-05-02T22:32:38.141Z] 22:32:38 INFO - 1525300358135 Marionette TRACE 1 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2018-05-02T22:32:38.142Z] 22:32:38 INFO - 1525300358139 Marionette TRACE 1 <- [1,4,null,{}]
[task 2018-05-02T22:32:38.160Z] 22:32:38 INFO - 1525300358156 Marionette TRACE 1 -> [0,5,"quit",{"flags":[]}]
[task 2018-05-02T22:32:38.160Z] 22:32:38 INFO - 1525300358157 Marionette DEBUG New connections will no longer be accepted
[task 2018-05-02T22:32:38.412Z] 22:32:38 INFO - 1525300358407 Marionette TRACE 1 <- [1,5,null,{"cause":"shutdown"}]
[task 2018-05-02T22:32:38.440Z] 22:32:38 INFO - 1525300358435 Marionette DEBUG Closed connection 1
[task 2018-05-02T22:32:39.002Z] 22:32:39 INFO - JavaScript error: resource://gre/modules/JSONFile.jsm, line 159: Error: Data is not ready.
[task 2018-05-02T22:32:39.003Z] 22:32:39 INFO - JavaScript error: resource://gre/modules/JSONFile.jsm, line 159: Error: Data is not ready.
[task 2018-05-02T22:32:39.005Z] 22:32:39 INFO - JavaScript error: resource://gre/modules/JSONFile.jsm, line 159: Error: Data is not ready.
[task 2018-05-02T22:32:39.182Z] 22:32:39 INFO - *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping
[task 2018-05-02T22:32:39.364Z] 22:32:39 INFO - 1525300359360 Marionette DEBUG Received observer notification xpcom-will-shutdown
[task 2018-05-02T22:32:40.747Z] 22:32:40 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -no-remote -marionette -profile /tmp/tmpKkrnxE.mozrunner
[task 2018-05-02T22:32:41.843Z] 22:32:41 INFO - 1525300361838 Marionette DEBUG Received observer notification profile-after-change
[task 2018-05-02T22:32:41.921Z] 22:32:41 INFO - 1525300361916 Marionette DEBUG Received observer notification command-line-startup
[task 2018-05-02T22:32:41.921Z] 22:32:41 INFO - 1525300361917 Marionette DEBUG Received observer notification nsPref:changed
[task 2018-05-02T22:32:43.617Z] 22:32:43 INFO - 1525300363606 Marionette DEBUG Received observer notification sessionstore-windows-restored
[task 2018-05-02T22:32:45.585Z] 22:32:45 INFO - 1525300365573 Marionette DEBUG New connections are accepted
[task 2018-05-02T22:32:45.587Z] 22:32:45 INFO - 1525300365575 Marionette INFO Listening on port 2828
[task 2018-05-02T22:32:45.609Z] 22:32:45 INFO - 1525300365605 Marionette DEBUG Accepted connection 0 from 127.0.0.1:52312
[task 2018-05-02T22:32:45.630Z] 22:32:45 INFO - 1525300365627 Marionette DEBUG Accepted connection 1 from 127.0.0.1:52314
[task 2018-05-02T22:32:45.638Z] 22:32:45 INFO - 1525300365632 Marionette DEBUG Closed connection 0
[task 2018-05-02T22:32:45.670Z] 22:32:45 INFO - 1525300365658 Marionette TRACE 1 -> [0,1,"WebDriver:NewSession",{}]
[task 2018-05-02T22:32:45.969Z] 22:32:45 INFO - 1525300365958 Marionette DEBUG Register listener.js for window 2147483649
[task 2018-05-02T22:32:46.066Z] 22:32:46 INFO - 1525300366062 Marionette TRACE 1 <- [1,1,null,{"sessionId":"e9fd84d1-6307-459b-a2da-fd0d6f9243d3","capabilities":{"browserName":"firefox","browserVersion":"61.0a ... ssID":5606,"moz:profile":"/tmp/tmpKkrnxE.mozrunner","moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
[task 2018-05-02T22:32:46.090Z] 22:32:46 INFO - 1525300366087 Marionette TRACE 1 -> [0,2,"WebDriver:DeleteSession",{}]
[task 2018-05-02T22:32:46.108Z] 22:32:46 INFO - TEST-PASS | testing/marionette/harness/marionette_harness/tests/unit/test_quit_restart.py TestServerQuitApplication.test_empty_default | took 16253ms
Comment 1•7 years ago
|
||
Complete hang during startup of Firefox.
status-firefox61:
--- → affected
Depends on: 1414495
| 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 20•7 years ago
|
||
All recent failures are start-up hangs of Linux64 ASAN builds. It needs a fix on bug 1487243.
Depends on: 1487243
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 23•7 years ago
|
||
This failure should be fixed now with the patch on bug 1495404 for both central and beta, given that it was ASAN only related.
Assignee: nobody → stransky
Status: NEW → RESOLVED
Closed: 7 years ago
status-firefox63:
--- → fixed
status-firefox64:
--- → fixed
No longer depends on: 1414495
Resolution: --- → FIXED
Target Milestone: --- → mozilla64
| Comment hidden (Intermittent Failures Robot) |
Updated•3 years ago
|
Product: Testing → Remote Protocol
Comment 25•3 years ago
|
||
Moving bug to Testing::Marionette Client and Harness component per bug 1815831.
Component: Marionette → Marionette Client and Harness
Product: Remote Protocol → Testing
You need to log in
before you can comment on or make changes to this bug.
Description
•