1401215 - Error: GDK_BACKEND does not match available displays while starting up Debugger Server for Browser Toolbox

Status: RESOLVED INACTIVE

(DevTools :: Framework, defect)

Description

[Joel Maher ( :jmaher ) (UTC -8)]

I have noticed persistent failures while running tests in the jsdcov platform (code coverage while using the javascript debugger to get specific test<->line mapping).

I looked over other linux64 runs and things work well, for example in:
https://public-artifacts.taskcluster.net/V7-mIzghTGeythg5fDWpcw/0/public/logs/live_backing.log

I see:
task 2017-09-19T10:06:09.459Z] 10:06:09     INFO - TEST-START | devtools/client/aboutdebugging/test/browser_addons_debug_bootstrapped.js
[task 2017-09-19T10:06:10.788Z] 10:06:10     INFO - GECKO(1237) | Debugger Server for Browser Toolbox listening on port: 37542
[task 2017-09-19T10:06:11.614Z] 10:06:11     INFO - GECKO(1237) | 1505815571603	Marionette	INFO	Enabled via MOZ_MARIONETTE
[task 2017-09-19T10:06:11.934Z] 10:06:11     INFO - GECKO(1237) | JavaScript error: resource://gre/modules/XPCOMUtils.jsm, line 192: TypeError: can't redefine non-configurable property "Services"
[task 2017-09-19T10:06:14.218Z] 10:06:14     INFO - GECKO(1237) | JavaScript error: resource:///modules/BrowserUsageTelemetry.jsm, line 341: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]
[task 2017-09-19T10:06:14.376Z] 10:06:14     INFO - GECKO(1237) | *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping
[task 2017-09-19T10:06:14.779Z] 10:06:14     INFO - GECKO(1237) | JavaScript error: resource://gre/modules/osfile/osfile_async_front.jsm, line 410: Error: OS.File has been shut down. Rejecting post to remove
[task 2017-09-19T10:06:14.780Z] 10:06:14     INFO - GECKO(1237) | JavaScript error: resource://gre/modules/osfile/osfile_async_front.jsm, line 410: Error: OS.File has been shut down. Rejecting post to remove
[task 2017-09-19T10:06:14.963Z] 10:06:14     INFO - GECKO(1237) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
[task 2017-09-19T10:06:14.964Z] 10:06:14     INFO - GECKO(1237) | MEMORY STAT | vsize 2130MB | residentFast 311MB | heapAllocated 135MB
[task 2017-09-19T10:06:14.967Z] 10:06:14     INFO - TEST-OK | devtools/client/aboutdebugging/test/browser_addons_debug_bootstrapped.js | took 5513ms



sadly for jsdcov, we see:
https://public-artifacts.taskcluster.net/R_0zI-sRReSBlKcVzkgizA/0/public/logs/live_backing.log

task 2017-09-19T10:08:53.462Z] 10:08:53     INFO - TEST-START | devtools/client/aboutdebugging/test/browser_addons_debug_bootstrapped.js
[task 2017-09-19T10:08:54.515Z] 10:08:54     INFO - GECKO(1193) | Debugger Server for Browser Toolbox listening on port: 36042
[task 2017-09-19T10:08:54.673Z] 10:08:54     INFO - GECKO(1193) | Error: GDK_BACKEND does not match available displays
[task 2017-09-19T10:25:34.711Z] 10:25:34     INFO - Automation Error: mozprocess timed out after 1000 seconds running ['/builds/worker/workspace/build/venv/bin/python', '-u', '/builds/worker/workspace/build/tests/mochitest/runtests.py', '--disable-e10s', '--total-chunks', '10', '--this-chunk', '3', '--jscov-dir-prefix=/builds/worker/workspace/build/blobber_upload_dir', '--appname=/builds/worker/workspace/build/application/firefox/firefox', '--utility-path=tests/bin', '--extra-profile-file=tests/bin/plugins', '--symbols-path=https://queue.taskcluster.net/v1/task/S9qB4AKuRtiQqC_NtLf8fQ/artifacts/public/build/target.crashreporter-symbols.zip', '--certificate-path=tests/certs', '--setpref=webgl.force-enabled=true', '--quiet', '--log-raw=/builds/worker/workspace/build/blobber_upload_dir/mochitest-devtools-chrome-coverage_raw.log', '--log-errorsummary=/builds/worker/workspace/build/blobber_upload_dir/mochitest-devtools-chrome-coverage_errorsummary.log', '--use-test-media-devices', '--screenshot-on-fail', '--cleanup-crashes', '--marionette-startup-timeout=180', '--work-path=/builds/worker/workspace/build', '--log-raw=-', '--flavor=browser', '--subsuite=devtools', '--chunk-by-runtime', '--timeout=1200']
[task 2017-09-19T10:25:34.744Z] 10:25:34    ERROR - timed out after 1000 seconds of no output



I am confused why this fails only in the jsdcov environment- we use the same builds as we do for linux64.

Comment 1

[Joel Maher ( :jmaher ) (UTC -8)]

:gmierz- if you get some time, could you look over how we run jsdcov and possibly there is a nugget of a config difference that might explain this?

Comment 2

[Greg Mierzwinski [:sparky]]

Sure thing, I'll leave the ni? open.

Comment 3

[Greg Mierzwinski [:sparky]]

This is pretty interesting. It looks like there used to be an error for this on Firefox before: [1], [2]. Actually, a quick search will find you quite a few different results. I'm going to try adding 'export DISPLAY=:10' to one of the config files.

I've looked into where this error is coming from and I'm going to get some logging information from there, [3].

I couldn't find any differences between the jsdcov variant and the normal build. The only real difference that I see is that we finalize the coverage collector after "all the tests are completed". We call the function at [4] to finalize it. Today we found out that this is called at the end of each manifest, not after _all_ the tests are completed, so maybe this is causing the error. Although, maybe 'all the tests' refers to all the tests in the manifest. (Regardless of this being the source of the error, I think it may be something that should be looked into).

[1]: https://forums.fedoraforum.org/showthread.php?t=312420
[2]: https://github.com/TIGRLab/admin/issues/661
[3]: https://dxr.mozilla.org/mozilla-central/search?q=GDK_BACKEND&redirect=true
[4]: https://dxr.mozilla.org/mozilla-central/source/testing/modules/CoverageUtils.jsm?q=path%3ACoverageUtils.jsm&redirect_type=single#226

Comment 4

[Joel Maher ( :jmaher ) (UTC -8)]

Thanks for all that information Greg- I would be curious if this error persists after we fix jsdcov to only collect coverage at the end, not after each manifest.  Likewise, I am curious about the results of |export DISPLAY=:10|

Comment 5

[Joel Maher ( :jmaher ) (UTC -8)]

:gmierz, any further updates on this bug- we disabled the 'g2' job in the meantime and some of the devtools tests, not ideal- maybe we just ignore this?

Comment 6

[Greg Mierzwinski [:sparky]]

No new updates from me, I was planning to play with this bug over the weekend. I think ignoring this for now is fine but it would be a good idea to continue looking at what part of jsdcov breaks this. The test tries to play with an environment variable from the looks of it and there's atleast one test that we have disabled for failing to get environment variables at [1], [2]. Maybe the failures are related.

[1]: https://dxr.mozilla.org/mozilla-central/source/toolkit/modules/subprocess/test/xpcshell/xpcshell.ini#10
[2]: https://dxr.mozilla.org/mozilla-central/source/toolkit/modules/subprocess/test/xpcshell/test_subprocess_getEnvironment.js

Comment 7

[Greg Mierzwinski [:sparky]]

After re-enabling and testing it today, I found that the failure has changed to this [1]:

[task 2017-11-19T21:39:43.382Z] 21:39:43     INFO - *** Start BrowserChrome Test Results ***
[task 2017-11-19T21:39:43.424Z] 21:39:43     INFO - checking window state
[task 2017-11-19T21:39:43.461Z] 21:39:43     INFO - TEST-START | devtools/client/aboutdebugging/test/browser_addons_debug_bootstrapped.js
[task 2017-11-19T21:39:44.410Z] 21:39:44     INFO - GECKO(1174) | Debugger Server for Browser Toolbox listening on port: 35608
[task 2017-11-19T21:39:44.609Z] 21:39:44     INFO - GECKO(1174) | Error: no DISPLAY environment variable specified
[task 2017-11-19T21:56:24.634Z] 21:56:24     INFO - Automation Error: mozprocess timed out after 1000 seconds running ['/builds/worker/workspace/build/venv/bin/python', '-u', '/builds/worker/workspace/build/tests/mochitest/runtests.py', '--disable-e10s', '--total-chunks', '8', '--this-chunk', '5', '--jscov-dir-prefix=/builds/worker/workspace/build/blobber_upload_dir', '--appname=/builds/worker/workspace/build/application/firefox/firefox', '--utility-path=tests/bin', '--extra-profile-file=tests/bin/plugins', '--symbols-path=https://queue.taskcluster.net/v1/task/dfIBuZ89QZy2VTcDYO7Idw/artifacts/public/build/target.crashreporter-symbols.zip', '--certificate-path=tests/certs', '--setpref=webgl.force-enabled=true', '--quiet', '--log-raw=/builds/worker/workspace/build/blobber_upload_dir/mochitest-devtools-chrome-coverage_raw.log', '--log-errorsummary=/builds/worker/workspace/build/blobber_upload_dir/mochitest-devtools-chrome-coverage_errorsummary.log', '--use-test-media-devices', '--screenshot-on-fail', '--cleanup-crashes', '--marionette-startup-timeout=180', '--sandbox-read-whitelist=/builds/worker/workspace/build', '--log-raw=-', '--flavor=browser', '--subsuite=devtools', '--chunk-by-runtime', '--timeout=1200']
[task 2017-11-19T21:56:24.676Z] 21:56:24    ERROR - timed out after 1000 seconds of no output
[task 2017-11-19T21:56:24.676Z] 21:56:24    ERROR - Return code: -15
[task 2017-11-19T21:56:24.678Z] 21:56:24    ERROR - No suite end message was emitted by this harness.
[task 2017-11-19T21:56:24.679Z] 21:56:24     INFO - TinderboxPrint: mochitest-mochitest-devtools-chrome-coverage<br/>26/0/0
[task 2017-11-19T21:56:24.679Z] 21:56:24    ERROR - # TBPL FAILURE #
[task 2017-11-19T21:56:24.680Z] 21:56:24  WARNING - setting return code to 2
[task 2017-11-19T21:56:24.681Z] 21:56:24    ERROR - The mochitest suite: mochitest-devtools-chrome-coverage ran with return status: FAILURE


The error is from here: https://dxr.mozilla.org/mozilla-central/source/toolkit/xre/nsAppRunner.cpp#3926

So, it does have something to do with the environment variable DISPLAY. I checked if finalizing the coverage collector elsewhere would change anything but nothing happened [2]. I'm testing to see if setting the variable helps anything here [3].

[1]: https://treeherder.mozilla.org/#/jobs?repo=try&revision=5fa0210eab9e83e6fdac203e44bd97c13aa2e09d
[2]: https://treeherder.mozilla.org/#/jobs?repo=try&revision=032d76f10884a8cc0d104a96fea7bc50a30da584
[3]: https://treeherder.mozilla.org/#/jobs?repo=try&revision=a68a5667fa640a67f2bf65c46ea9d68f45dab272

Comment 8

[Greg Mierzwinski [:sparky]]

Comment 7 [3] finished and didn't work. It's still the same error also. It's weird because I've set the variable in a couple places, and I can see it in the environment print out. I might not be setting it early enough.

Comment 9

[Jan Honza Odvarko [:Honza] (always need-info? me)]

This is likely fixed by work done in Bug 1120863 - Browser toolbox starts blank and doesn't function with pending updates
Feel free to reopen if you are still experiencing this issue.

Honza