1312633 - Intermittent test_about_pages.py TestAboutPages.test_navigate_shortcut_key | IOError: Process killed because the connection to Marionette server is lost. Check gecko.log for errors (Reason: Connection timed out after 60.0s)

Status: RESOLVED FIXED

(Testing :: Marionette Client and Harness, defect)

Description

[Treeherder Bug Filer]

Filed by: philringnalda [at] gmail.com

https://treeherder.mozilla.org/logviewer.html#?job_id=5605862&repo=autoland

https://archive.mozilla.org/pub/firefox/tinderbox-builds/autoland-win32-debug/1477353022/autoland_win7_vm-debug_test-marionette-e10s-bm139-tests1-windows-build346.txt.gz

Comment 1

[Henrik Skupin [:whimboo][⌚️UTC+1]]

The stack shows again that we have an issue with get when navigating:

 18:21:32    ERROR -  TEST-UNEXPECTED-ERROR | test_about_pages.py TestAboutPages.test_navigate_shortcut_key | IOError: Process killed because the connection to Marionette server is lost. Check gecko.log for errors (Reason: Connection timed out after 60.0s)
 18:21:32     INFO -  Traceback (most recent call last):
 18:21:32     INFO -    File "c:\slave\test\build\venv\lib\site-packages\marionette\marionette_test\testcases.py", line 144, in run
 18:21:32     INFO -      self.setUp()
 18:21:32     INFO -    File "c:\slave\test\build\tests\marionette\tests\testing\marionette\harness\marionette\tests\unit\test_about_pages.py", line 21, in setUp
 18:21:32     INFO -      self.marionette.navigate(self.remote_uri)
 18:21:32     INFO -    File "c:\slave\test\build\venv\lib\site-packages\marionette_driver\marionette.py", line 1589, in navigate
 18:21:32 INFO - self._send_message("get", {"url": url}) 

From Gecko log:

1477358366605	Marionette	TRACE	conn383 -> [0,5,"get",{"url":"http://127.0.0.1:49334/javascriptPage.html"}]
--DOMWINDOW == 43 (11D5C400) [pid = 988] [serial = 78] [outer = 00000000] [url = about:blank]
[Child 3760] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005: file c:/builds/moz2_slave/autoland-w32-d-000000000000000/build/src/toolkit/xre/nsXREDirProvider.cpp, line 1703
[Child 3760] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005: file c:/builds/moz2_slave/autoland-w32-d-000000000000000/build/src/xpcom/base/nsSystemInfo.cpp, line 116
++DOCSHELL 09F2E800 == 1 [pid = 3760] [id = 1]
++DOMWINDOW == 1 (09F2F000) [pid = 3760] [serial = 1] [outer = 00000000]
++DOMWINDOW == 2 (0ADDA400) [pid = 3760] [serial = 2] [outer = 09F2F000]
[Child 3760] WARNING: site security information will not be persisted: file c:/builds/moz2_slave/autoland-w32-d-000000000000000/build/src/security/manager/ssl/nsSiteSecurityService.cpp, line 268
###!!! ERROR: Potential deadlock detected:
=== Cyclical dependency starts at
--- Mutex : nsThread.mLock (currently acquired)
 calling context
  [stack trace unavailable]

--- Next dependency:
--- Mutex : mozilla.ipc.MessageChannel.mMonitor (currently acquired)
 calling context
  [stack trace unavailable]

=== Cycle completed at
--- Mutex : nsThread.mLock (currently acquired)
 calling context
  [stack trace unavailable]

###!!! Deadlock may happen NOW!

I wonder if the potential deadlock could have been the reason for this hang. Kanru, do you have an idea?

Comment 2

[Henrik Skupin [:whimboo][⌚️UTC+1]]

Looks like we got a lot of those issues lately. Did something change for IPC in the last 24 hours? Got any kind of patch landed which could have caused such a regression?

Comment 3

[Henrik Skupin [:whimboo][⌚️UTC+1]]

Checking autoland on Treeherder gives me the feeling that with the landing of the patches on bug 1198381 the number of hangs in Marionette has been increased. And that happens again randomly in any kind of test which uses navigate().

I think I will file a new bug so we can better add dependencies.

Comment 4

[BMO Automation]

Moving bug to Testing::Marionette Client and Harness component per bug 1815831.