Closed Bug 1444600 Opened 6 years ago Closed 6 years ago

Intermittent test_loader_global_sharing.py TestLoaderGlobalSharing.test_global_sharing_settings | IOError: Process killed because the connection to Marionette server is lost. Check gecko.log for errors (Reason: [Errno 111] Connection refused)

Categories

(Testing :: Marionette Client and Harness, defect, P5)

Product:
Testing
Component:
Marionette Client and Harness
Version:
Version 3
Type:
defect

Tracking

(firefox64 fixed)

Status:
RESOLVED FIXED
Milestone:
mozilla64
Tracking Flags:
Tracking Status
firefox64 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: whimboo)

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell unknown]) 

Filed by: archaeopteryx [at] coole-files.de

https://treeherder.mozilla.org/logviewer.html#?job_id=167067847&repo=try

https://queue.taskcluster.net/v1/task/d_dWRR64QrWuDOXXrHgv5g/runs/0/artifacts/public/logs/live_backing.log

[task 2018-03-09T21:18:01.251Z] 21:18:01     INFO -  1520630281248	Marionette	TRACE	2 -> [0,23,"quitApplication",{"flags":["eRestart","eAttemptQuit"]}]
[task 2018-03-09T21:18:01.259Z] 21:18:01     INFO -  1520630281252	Marionette	DEBUG	New connections will no longer be accepted
[task 2018-03-09T21:18:01.288Z] 21:18:01     INFO -  1520630281276	addons.xpi	WARN	Exception running bootstrap method shutdown on activity-stream@mozilla.org: [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: resource://activity-stream/lib/SnippetsFeed.jsm :: uninit :: line 185"  data: no] Stack trace: uninit()@resource://activity-stream/lib/SnippetsFeed.jsm:185
[task 2018-03-09T21:18:01.289Z] 21:18:01     INFO -  onAction()@resource://activity-stream/lib/SnippetsFeed.jsm:201
[task 2018-03-09T21:18:01.289Z] 21:18:01     INFO -  _middleware/</<()@resource://activity-stream/lib/Store.jsm:49
[task 2018-03-09T21:18:01.290Z] 21:18:01     INFO -  Store/this[method]()@resource://activity-stream/lib/Store.jsm:28
[task 2018-03-09T21:18:01.290Z] 21:18:01     INFO -  uninit()@resource://activity-stream/lib/Store.jsm:151
[task 2018-03-09T21:18:01.291Z] 21:18:01     INFO -  uninit()@resource://activity-stream/lib/ActivityStream.jsm:294
[task 2018-03-09T21:18:01.292Z] 21:18:01     INFO -  uninit()@resource://gre/modules/addons/XPIProvider.jsm -> jar:file:///builds/worker/workspace/build/application/firefox/browser/features/activity-stream@mozilla.org.xpi!/bootstrap.js:73
[task 2018-03-09T21:18:01.293Z] 21:18:01     INFO -  shutdown()@resource://gre/modules/addons/XPIProvider.jsm -> jar:file:///builds/worker/workspace/build/application/firefox/browser/features/activity-stream@mozilla.org.xpi!/bootstrap.js:169
[task 2018-03-09T21:18:01.294Z] 21:18:01     INFO -  callBootstrapMethod()@resource://gre/modules/addons/XPIProvider.jsm:4422
[task 2018-03-09T21:18:01.294Z] 21:18:01     INFO -  observe()@resource://gre/modules/addons/XPIProvider.jsm:2275
[task 2018-03-09T21:18:01.295Z] 21:18:01     INFO -  GeckoDriver.prototype.quit()@driver.js:3300
[task 2018-03-09T21:18:01.295Z] 21:18:01     INFO -  despatch()@server.js:288
[task 2018-03-09T21:18:01.295Z] 21:18:01     INFO -  execute()@server.js:262
[task 2018-03-09T21:18:01.295Z] 21:18:01     INFO -  onPacket/<()@server.js:237
[task 2018-03-09T21:18:01.295Z] 21:18:01     INFO -  onPacket()@server.js:236
[task 2018-03-09T21:18:01.295Z] 21:18:01     INFO -  _onJSONObjectReady/<()@transport.js:500
[task 2018-03-09T21:18:01.364Z] 21:18:01     INFO -  1520630281360	Marionette	TRACE	2 <- [1,23,null,{"cause":"restart"}]
[task 2018-03-09T21:18:01.368Z] 21:18:01     INFO -  JavaScript error: jar:file:///builds/worker/workspace/build/application/firefox/omni.ja!/components/nsUrlClassifierListManager.js, line 589: TypeError: this.tablesData[table] is undefined
[task 2018-03-09T21:18:01.374Z] 21:18:01     INFO -  1520630281368	Marionette	DEBUG	Closed connection 2
[task 2018-03-09T21:18:01.552Z] 21:18:01     INFO -  *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping
[task 2018-03-09T21:18:01.650Z] 21:18:01     INFO -  1520630281646	Marionette	DEBUG	Received observer notification xpcom-will-shutdown
[task 2018-03-09T21:18:01.706Z] 21:18:01     INFO -  JavaScript error: resource://gre/modules/osfile/osfile_async_front.jsm, line 408: Error: OS.File has been shut down. Rejecting post to DirectoryIterator_prototype_close
[task 2018-03-09T21:18:01.707Z] 21:18:01     INFO -  JavaScript error: resource://gre/modules/osfile/osfile_async_front.jsm, line 408: Error: OS.File has been shut down. Rejecting post to DirectoryIterator_prototype_close
[task 2018-03-09T21:18:01.709Z] 21:18:01     INFO -  JavaScript error: resource://gre/modules/ProfileAge.jsm, line 174: Error: Unable to fetch oldest profile entry: Error: OS.File has been shut down. Rejecting request to DirectoryIterator_prototype_next
[task 2018-03-09T21:18:01.710Z] 21:18:01     INFO -  JavaScript error: resource://gre/modules/ProfileAge.jsm, line 174: Error: Unable to fetch oldest profile entry: Error: OS.File has been shut down. Rejecting request to DirectoryIterator_prototype_next
[task 2018-03-09T21:18:01.912Z] 21:18:01     INFO -  JavaScript error: resource://gre/modules/osfile/osfile_async_front.jsm, line 408: Error: OS.File has been shut down. Rejecting post to remove
[task 2018-03-09T21:18:01.914Z] 21:18:01     INFO -  JavaScript error: resource://gre/modules/osfile/osfile_async_front.jsm, line 408: Error: OS.File has been shut down. Rejecting post to remove
[task 2018-03-09T21:18:02.348Z] 21:18:02     INFO -  1520630282344	Marionette	DEBUG	Received observer notification profile-after-change
[task 2018-03-09T21:18:02.426Z] 21:18:02     INFO -  1520630282416	Marionette	DEBUG	Received observer notification command-line-startup
[task 2018-03-09T21:24:02.511Z] 21:24:02     INFO - TEST-UNEXPECTED-ERROR | js/xpconnect/tests/marionette/test_loader_global_sharing.py TestLoaderGlobalSharing.test_global_sharing_settings | IOError: Process killed because the connection to Marionette server is lost. Check gecko.log for errors (Reason: [Errno 111] Connection refused)
[task 2018-03-09T21:24:02.511Z] 21:24:02     INFO - Traceback (most recent call last):
[task 2018-03-09T21:24:02.512Z] 21:24:02     INFO -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 159, in run
[task 2018-03-09T21:24:02.512Z] 21:24:02     INFO -     testMethod()
[task 2018-03-09T21:24:02.512Z] 21:24:02     INFO -   File "/builds/worker/workspace/build/tests/marionette/tests/js/xpconnect/tests/marionette/test_loader_global_sharing.py", line 106, in test_global_sharing_settings
[task 2018-03-09T21:24:02.513Z] 21:24:02     INFO -     env={GLOBAL_SHARING_VAR: var})
[task 2018-03-09T21:24:02.513Z] 21:24:02     INFO -   File "/builds/worker/workspace/build/tests/marionette/tests/js/xpconnect/tests/marionette/test_loader_global_sharing.py", line 43, in restart
[task 2018-03-09T21:24:02.514Z] 21:24:02     INFO -     self.marionette.restart(in_app=True, clean=False)
[task 2018-03-09T21:24:02.514Z] 21:24:02     INFO -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/decorators.py", line 26, in _
[task 2018-03-09T21:24:02.514Z] 21:24:02     INFO -     return func(*args, **kwargs)
[task 2018-03-09T21:24:02.515Z] 21:24:02     INFO -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 1169, in restart
[task 2018-03-09T21:24:02.515Z] 21:24:02     INFO -     self.start_session()
[task 2018-03-09T21:24:02.515Z] 21:24:02     INFO -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/decorators.py", line 31, in _
[task 2018-03-09T21:24:02.516Z] 21:24:02     INFO -     m._handle_socket_failure()
[task 2018-03-09T21:24:02.517Z] 21:24:02     INFO -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 830, in _handle_socket_failure
[task 2018-03-09T21:24:02.519Z] 21:24:02     INFO -     reraise(IOError, message.format(returncode=returncode, reason=val), tb)
[task 2018-03-09T21:24:02.520Z] 21:24:02     INFO -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/decorators.py", line 26, in _
[task 2018-03-09T21:24:02.521Z] 21:24:02     INFO -     return func(*args, **kwargs)
[task 2018-03-09T21:24:02.522Z] 21:24:02     INFO -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 1222, in start_session
[task 2018-03-09T21:24:02.523Z] 21:24:02     INFO -     self.protocol, _ = self.client.connect()
[task 2018-03-09T21:24:02.524Z] 21:24:02     INFO -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/transport.py", line 195, in connect
[task 2018-03-09T21:24:02.525Z] 21:24:02     INFO -     self._sock.connect((self.host, self.port))
[task 2018-03-09T21:24:02.526Z] 21:24:02     INFO -   File "/usr/lib/python2.7/socket.py", line 228, in meth
[task 2018-03-09T21:24:02.527Z] 21:24:02     INFO -     return getattr(self._sock,name)(*args)
No `sessionstore-windows-restored` observer notification has been sent here during a restart of Firefox. Maybe bug 1433873 will help here.
Depends on: 1433873
See Also: → 1459610
As it looks like on August 18th we got an increase of this failure on Linux64. If the failure is still higher next week we might want to backfill.
There have been 32 failures in the last week, all on Linux 64 Asan.

Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=197516570&repo=mozilla-central&lineNumber=53849
Whiteboard: [stockwell needswork]
Depends on: 1489960
Most failures here are happening for Linux64 ASAN builds and need a fix on bug 1487243.
Depends on: 1487243
In the last 7 days there are 33 failures, all on Linux 64, mostly Asan, 3 opt and 2 pgo.
(In reply to Bogdan Tara[:bogdan_tara] from comment #33)
> In the last 7 days there are 33 failures, all on Linux 64, mostly Asan, 3
> opt and 2 pgo.

If you have a look at the depended bugs you will see that bug 1487243 is the underlying issue for the Linux64 ASAN builds.
Flags: needinfo?(btara)
Thank you, I'll "complain" on bug 1487243. :)
Flags: needinfo?(btara)
While the ASAN start-up hang is fixed other build types still show a hang due to a missing "sessionstore-windows-restored" notification during startup.
Depends on: 1382162
No more failures since my patch on bug 1433873 landed.
Assignee: nobody → hskupin
Status: NEW → RESOLVED
Closed: 6 years ago
status-firefox64: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla64
Product: Testing → Remote Protocol
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.