Closed Bug 1161702 Opened 10 years ago Closed 10 years ago

Intermittent luciddream AssertionError: Timed out waiting for port!

Categories

(Testing :: General, defect)

Unspecified
Linux
defect
Not set
normal

Tracking

(firefox39 fixed, firefox40 fixed, firefox41 fixed, firefox-esr38 unaffected)

RESOLVED FIXED
mozilla41
Tracking Status
firefox39 --- fixed
firefox40 --- fixed
firefox41 --- fixed
firefox-esr38 --- unaffected

People

(Reporter: KWierso, Assigned: jgriffin)

References

Details

(Keywords: intermittent-failure)

Attachments

(2 files)

10:15:41 INFO - 2015-05-05 10:15:41: basic_code_modules.cc:88: INFO: No module at 0x18db79ee 10:15:41 INFO - 2015-05-05 10:15:41: basic_code_modules.cc:88: INFO: No module at 0xffdaf1d4 10:15:41 INFO - 2015-05-05 10:15:41: basic_code_modules.cc:88: INFO: No module at 0x8000ffff 10:15:41 INFO - 2015-05-05 10:15:41: basic_code_modules.cc:88: INFO: No module at 0x618fd860 10:15:41 INFO - 2015-05-05 10:15:41: basic_code_modules.cc:88: INFO: No module at 0x5c0726b8 10:15:41 INFO - 2015-05-05 10:15:41: basic_code_modules.cc:88: INFO: No module at 0x5f9d46a0 10:15:41 INFO - 2015-05-05 10:15:41: basic_code_modules.cc:88: INFO: No module at 0xd 10:15:41 INFO - 2015-05-05 10:15:41: basic_code_modules.cc:88: INFO: No module at 0x5ac2e2b8 10:15:41 INFO - 2015-05-05 10:15:41: basic_code_modules.cc:88: INFO: No module at 0x5c0d3120 10:15:41 INFO - 2015-05-05 10:15:41: basic_code_modules.cc:88: INFO: No module at 0xffdaf0a8 10:15:41 INFO - 2015-05-05 10:15:41: basic_code_modules.cc:88: INFO: No module at 0xffda0008 10:15:41 INFO - 2015-05-05 10:15:41: basic_code_modules.cc:88: INFO: No module at 0x5 10:15:48 INFO - [OK] rjs optimize 10:15:52 INFO - Finished: test ui config file: ./dev_apps/test-agent/config.json 10:15:52 INFO - Finished: Generating extensions 10:15:52 INFO - test -d .git && cp tools/pre-commit .git/hooks/pre-commit && chmod +x .git/hooks/pre-commit || true 10:15:53 INFO - Profile Ready: please run [b2g|firefox] -profile /builds/slave/test/gaia/profile 10:15:53 INFO - Return code: 0 10:15:53 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/luciddream/luciddream/runluciddream.py', '--log-raw=/builds/slave/test/build/luciddream_raw.log', '--b2g-desktop-path', '/builds/slave/test/build/b2gdesktop/b2g/b2g', '--browser-path', '/builds/slave/test/build/application/firefox/firefox', '--gaia-profile', '/builds/slave/test/gaia/profile', '/builds/slave/test/build/tests/luciddream/example-tests/luciddream.ini'] 10:15:53 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/tests/luciddream/luciddream/runluciddream.py --log-raw=/builds/slave/test/build/luciddream_raw.log --b2g-desktop-path /builds/slave/test/build/b2gdesktop/b2g/b2g --browser-path /builds/slave/test/build/application/firefox/firefox --gaia-profile /builds/slave/test/gaia/profile /builds/slave/test/build/tests/luciddream/example-tests/luciddream.ini 10:15:53 INFO - Using env: {'CCACHE_DIR': '/builds/ccache', 10:15:53 INFO - 'CCACHE_UMASK': '002', 10:15:53 INFO - 'DISPLAY': ':0', 10:15:53 INFO - 'HOME': '/home/cltbld', 10:15:53 INFO - 'LANG': 'en_US.UTF-8', 10:15:53 INFO - 'LOGNAME': 'cltbld', 10:15:53 INFO - 'MAIL': '/var/mail/cltbld', 10:15:53 INFO - 'MOZ_HIDE_RESULTS_TABLE': '1', 10:15:53 INFO - 'MOZ_NODE_PATH': '/usr/bin/node', 10:15:53 INFO - 'MOZ_NO_REMOTE': '1', 10:15:53 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 10:15:53 INFO - 'NO_FAIL_ON_TEST_ERRORS': '1', 10:15:53 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 10:15:53 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 10:15:53 INFO - 'PWD': '/builds/slave/test', 10:15:53 INFO - 'SHELL': '/bin/bash', 10:15:53 INFO - 'SHLVL': '1', 10:15:53 INFO - 'TERM': 'linux', 10:15:53 INFO - 'TMOUT': '86400', 10:15:53 INFO - 'USER': 'cltbld', 10:15:53 INFO - 'XDG_SESSION_COOKIE': '9ca12473fbb1d023794ffd180000023c-1430845571.290996-1195966919', 10:15:53 INFO - '_': '/tools/buildbot/bin/python'} 10:15:53 INFO - Calling ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/luciddream/luciddream/runluciddream.py', '--log-raw=/builds/slave/test/build/luciddream_raw.log', '--b2g-desktop-path', '/builds/slave/test/build/b2gdesktop/b2g/b2g', '--browser-path', '/builds/slave/test/build/application/firefox/firefox', '--gaia-profile', '/builds/slave/test/gaia/profile', '/builds/slave/test/build/tests/luciddream/example-tests/luciddream.ini'] with output_timeout 1000 10:16:59 INFO - Traceback (most recent call last): 10:16:59 INFO - File "/builds/slave/test/build/tests/luciddream/luciddream/runluciddream.py", line 151, in <module> 10:16:59 INFO - main() 10:16:59 INFO - File "/builds/slave/test/build/tests/luciddream/luciddream/runluciddream.py", line 148, in main 10:16:59 INFO - run(**vars(args)) 10:16:59 INFO - File "/builds/slave/test/build/tests/luciddream/luciddream/runluciddream.py", line 141, in run 10:16:59 INFO - runner.run_tests([manifest]) 10:16:59 INFO - File "/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette/runner/base.py", line 755, in run_tests 10:16:59 INFO - self.start_marionette() 10:16:59 INFO - File "/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette/runner/base.py", line 700, in start_marionette 10:16:59 INFO - self.marionette = self.driverclass(**self._build_kwargs()) 10:16:59 INFO - File "/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette_driver/marionette.py", line 602, in __init__ 10:16:59 INFO - assert(self.wait_for_port()), "Timed out waiting for port!" 10:16:59 INFO - AssertionError: Timed out waiting for port! 10:17:06 ERROR - Return code: 1 10:17:06 INFO - TinderboxPrint: luciddream: <em class="testfail">T-FAIL</em> 10:17:06 ERROR - Luciddream exited with return code 1: harness failures 10:17:06 ERROR - # TBPL FAILURE # 10:17:06 INFO - Running post-action listener: _resource_record_post_action 10:17:06 INFO - Running post-run listener: _resource_record_post_run 10:17:07 INFO - Total resource usage - Wall time: 262s; CPU: 99.0%; Read bytes: 80424960; Write bytes: 762126336; Read time: 248564; Write time: 7611684 10:17:07 INFO - install - Wall time: 60s; CPU: 100.0%; Read bytes: 0; Write bytes: 144629760; Read time: 0; Write time: 664100 10:17:07 INFO - run-tests - Wall time: 203s; CPU: 99.0%; Read bytes: 79753216; Write bytes: 607846400; Read time: 248308; Write time: 6923528 10:17:07 INFO - Running post-run listener: _upload_blobber_files 10:17:07 INFO - Blob upload gear active.
Jonathan, any idea what's going on here?
Flags: needinfo?(jgriffin)
I'll add some more logging here; nothing jumps out.
Depends on: 1177789
Have landed some additional logging; will look again if this recurs.
Flags: needinfo?(jgriffin)
These tests are completely CPU bound on the low-end AWS instances we currently use. The second binary we're launching seems to be hanging, but it may just be temporary. I'm going to increase the timeout and see if this resolves the problem.
Assignee: nobody → jgriffin
Status: NEW → ASSIGNED
I'm fixing this in two parts. One, I'm adding a --startup-timeout parameter to Marionette. Currently, there's no way to set this programatically. Two, in order to use this, I'm adding an in-tree config to luciddream. Green try run: https://treeherder.mozilla.org/#/jobs?repo=try&revision=0c3045ca5a1c
Bug 1161702 - Add --startup-timeout arg for Marionette; add in-tree config for luciddream
Attachment #8629072 - Flags: review?(ahalberstadt)
Comment on attachment 8629074 [details] MozReview Request: Bug 1161702 - Add --startup-timeout arg for Marionette; add in-tree config for luciddream Bug 1161702 - Add --startup-timeout arg for Marionette; add in-tree config for luciddream
Attachment #8629074 - Flags: review?(ahalberstadt)
Comment on attachment 8629072 [details] [diff] [review] Make luciddream mozharness script use in-tree config, Review of attachment 8629072 [details] [diff] [review]: ----------------------------------------------------------------- Lgtm! In-tree configs will be merged into regular configs once mozharness is live in-tree, but we can land this as an intermediate step and merge luciddream along with everything else. ::: scripts/luciddream_unittest.py @@ +228,4 @@ > ld_parser = self.parser_class(config=self.config, > log_obj=self.log_obj, > error_list=BaseErrorList) > + nit: whitespace
Attachment #8629072 - Flags: review?(ahalberstadt) → review+
Comment on attachment 8629074 [details] MozReview Request: Bug 1161702 - Add --startup-timeout arg for Marionette; add in-tree config for luciddream https://reviewboard.mozilla.org/r/12523/#review11307 Ship It!
Attachment #8629074 - Flags: review?(ahalberstadt) → review+
(In reply to Pulsebot from comment #30) > https://hg.mozilla.org/integration/mozilla-inbound/rev/6aa0c715afce I'll land the mozharness change after this gets merged around (and I guess to the in-tree mozharness copy as well?)
Keywords: leave-open
No occurrences in a couple of weeks; I'm calling this fixed.
Status: ASSIGNED → RESOLVED
Closed: 10 years ago
Resolution: --- → FIXED
Keywords: leave-open
Target Milestone: --- → mozilla41
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: