Closed Bug 1257922 Opened 8 years ago Closed 8 years ago

Marionette runs on ASAN fail due to fatal NS_ERROR_NOT_IMPLEMENTED JavascriptException

Categories

(Remote Protocol :: Marionette, defect)

Version 3
defect
Not set
normal

Tracking

(firefox48 fixed, firefox49 fixed)

RESOLVED FIXED
mozilla49
Tracking Status
firefox48 --- fixed
firefox49 --- fixed

People

(Reporter: RyanVM, Assigned: impossibus)

Details

Attachments

(1 file)

lastRunCrashID is in crashreporter code, which we don't build on ASAN.
http://hg.mozilla.org/mozilla-central/file/9c5d494d0548/build/unix/mozconfig.asan#l24

Can we maybe silently ignore the failure? I'm not sure what other test harnesses do to avoid issues. Ted, any thoughts?

https://treeherder.mozilla.org/logviewer.html#?job_id=156524&repo=ash

09:18:24     INFO -  Initial Profile Destination is "/tmp/tmpqPI5PQ.mozrunner"
09:18:24     INFO -  starting httpd
09:18:24     INFO -  running httpd on http://127.0.0.1:32784/
09:18:25     INFO -  Failure during test execution.
09:18:25     INFO -  Traceback (most recent call last):
09:18:25     INFO -    File "/builds/slave/test/build/tests/marionette/marionette/runtests.py", line 68, in run
09:18:25     INFO -      runner.run_tests(tests)
09:18:25     INFO -    File "/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette/runner/base.py", line 872, in run_tests
09:18:25     INFO -      self.add_test(test)
09:18:25     INFO -    File "/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette/runner/base.py", line 1013, in add_test
09:18:25     INFO -      e10s = self.appinfo.get('browserTabsRemoteAutostart', False)
09:18:25     INFO -    File "/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette/runner/base.py", line 677, in appinfo
09:18:25     INFO -      }""")
09:18:25     INFO -    File "/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette_driver/marionette.py", line 1669, in execute_script
09:18:25     INFO -      rv = self._send_message("executeScript", body, key="value")
09:18:25     INFO -    File "/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette_driver/decorators.py", line 36, in _
09:18:25     INFO -      return func(*args, **kwargs)
09:18:25     INFO -    File "/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette_driver/marionette.py", line 757, in _send_message
09:18:25     INFO -      self._handle_error(err)
09:18:25     INFO -    File "/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette_driver/marionette.py", line 818, in _handle_error
09:18:25     INFO -      raise errors.lookup(error)(message, stacktrace=stacktrace)
09:18:25    ERROR -  JavascriptException: JavascriptException: [Exception... "Component returned failure code: 0x80004001 (NS_ERROR_NOT_IMPLEMENTED) [nsIXULRuntime.lastRunCrashID]"  nsresult: "0x80004001 (NS_ERROR_NOT_IMPLEMENTED)"  location: "JS frame :: chrome://marionette/content/element.js :: EM_wrapValue :: line 229"  data: no]
09:18:25     INFO -  stacktrace:
09:18:25     INFO -  	execute_script @base.py, line 677
09:18:25     INFO -  	inline javascript, line 229
09:18:25     INFO -  	src: "undefined"
09:18:25     INFO -  	Stack:
09:18:25     INFO -  	EM_wrapValue@chrome://marionette/content/element.js:229:13
09:18:25     INFO -  	GeckoDriver.prototype.executeScriptInSandbox@chrome://marionette/content/driver.js:829:23
09:18:25     INFO -  	GeckoDriver.prototype.execute@chrome://marionette/content/driver.js:920:5
09:18:25     INFO -  	TaskImpl_run@resource://gre/modules/Task.jsm:319:40
09:18:25     INFO -  	TaskImpl@resource://gre/modules/Task.jsm:280:3
09:18:25     INFO -  	createAsyncFunction/asyncFunction@resource://gre/modules/Task.jsm:254:14
09:18:25     INFO -  	Task_spawn@resource://gre/modules/Task.jsm:168:12
09:18:25     INFO -  	TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:388:16
09:18:25     INFO -  	TaskImpl_run@resource://gre/modules/Task.jsm:327:13
09:18:25     INFO -  	TaskImpl@resource://gre/modules/Task.jsm:280:3
09:18:25     INFO -  	createAsyncFunction/asyncFunction@resource://gre/modules/Task.jsm:254:14
09:18:25     INFO -  	Task_spawn@resource://gre/modules/Task.jsm:168:12
09:18:25     INFO -  	Dispatcher.prototype.execute@chrome://marionette/content/dispatcher.js:120:13
09:18:25     INFO -  	Dispatcher.prototype.onPacket@chrome://marionette/content/dispatcher.js:91:5
09:18:25     INFO -  	DebuggerTransport.prototype._onJSONObjectReady/<@chrome://marionette/content/server.js -> resource://devtools/shared/transport/transport.js:479:9
09:18:25     INFO -  	exports.makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/ThreadSafeDevToolsUtils.js:101:14
09:18:25     INFO -  	exports.makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/ThreadSafeDevToolsUtils.js:101:14
09:18:25    ERROR -  {"thread": "MainThread", "level": "ERROR", "pid": 1915, "source": "Marionette test runner", "time": 1458317905062, "action": "log", "message": "Failure during harness setup", "stack": "Traceback (most recent call last):\n\n  File \"/builds/slave/test/build/tests/marionette/marionette/runtests.py\", line 88, in cli\n    failed = harness_class(runner_class, parser_class, args=args).run()\n\n  File \"/builds/slave/test/build/tests/marionette/marionette/runtests.py\", line 68, in run\n    runner.run_tests(tests)\n\n  File \"/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette/runner/base.py\", line 872, in run_tests\n    self.add_test(test)\n\n  File \"/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette/runner/base.py\", line 1013, in add_test\n    e10s = self.appinfo.get('browserTabsRemoteAutostart', False)\n\n  File \"/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette/runner/base.py\", line 677, in appinfo\n    }\"\"\")\n\n  File \"/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette_driver/marionette.py\", line 1669, in execute_script\n    rv = self._send_message(\"executeScript\", body, key=\"value\")\n\n  File \"/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette_driver/decorators.py\", line 36, in _\n    return func(*args, **kwargs)\n\n  File \"/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette_driver/marionette.py\", line 757, in _send_message\n    self._handle_error(err)\n\n  File \"/builds/slave/test/build/venv/local/lib/python2.7/site-packages/marionette_driver/marionette.py\", line 818, in _handle_error\n    raise errors.lookup(error)(message, stacktrace=stacktrace)\n\nJavascriptException: JavascriptException: [Exception... \"Component returned failure code: 0x80004001 (NS_ERROR_NOT_IMPLEMENTED) [nsIXULRuntime.lastRunCrashID]\"  nsresult: \"0x80004001 (NS_ERROR_NOT_IMPLEMENTED)\"  location: \"JS frame :: chrome://marionette/content/element.js :: EM_wrapValue :: line 229\"  data: no]\nstacktrace:\n\texecute_script @base.py, line 677\n\tinline javascript, line 229\n\tsrc: \"undefined\"\n\tStack:\n\tEM_wrapValue@chrome://marionette/content/element.js:229:13\n\tGeckoDriver.prototype.executeScriptInSandbox@chrome://marionette/content/driver.js:829:23\n\tGeckoDriver.prototype.execute@chrome://marionette/content/driver.js:920:5\n\tTaskImpl_run@resource://gre/modules/Task.jsm:319:40\n\tTaskImpl@resource://gre/modules/Task.jsm:280:3\n\tcreateAsyncFunction/asyncFunction@resource://gre/modules/Task.jsm:254:14\n\tTask_spawn@resource://gre/modules/Task.jsm:168:12\n\tTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:388:16\n\tTaskImpl_run@resource://gre/modules/Task.jsm:327:13\n\tTaskImpl@resource://gre/modules/Task.jsm:280:3\n\tcreateAsyncFunction/asyncFunction@resource://gre/modules/Task.jsm:254:14\n\tTask_spawn@resource://gre/modules/Task.jsm:168:12\n\tDispatcher.prototype.execute@chrome://marionette/content/dispatcher.js:120:13\n\tDispatcher.prototype.onPacket@chrome://marionette/content/dispatcher.js:91:5\n\tDebuggerTransport.prototype._onJSONObjectReady/<@chrome://marionette/content/server.js -> resource://devtools/shared/transport/transport.js:479:9\n\texports.makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/ThreadSafeDevToolsUtils.js:101:14\n\texports.makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/ThreadSafeDevToolsUtils.js:101:14\n\n\n"}
09:18:25    ERROR - Return code: 1
Flags: needinfo?(ted)
I cannot for the life of me figure out where in the Marionette code this gets called. I assume this is just the Marionette test harness trying to use this unconditionally regardless of whether crash reporting is disabled, and other harnesses just don't do that.
Flags: needinfo?(ted)
(In reply to Andreas Tolfsen ‹:ato› from comment #2)
> It looks like the actual script that is evaluated is this:
> https://github.com/mozilla/gecko-dev/blob/master/testing/marionette/harness/
> marionette/runner/base.py#L672

Yeah, I added that a few weeks ago in bug 1253618, but I don't understand how it could lead to this exception on ASAN alone.
Oh! I see what's happening. You're returning `Services.appInfo` which is an XPCOM object, and then the Marionette code is calling wrap_value on it:
https://dxr.mozilla.org/mozilla-central/rev/494289c72ba3997183e7b5beaca3e0447ecaf96d/testing/marionette/element.js#195

That code is enumerating all the properties of the object and copying them to a new object, but that's not actually safe to do in the general case for XPCOM, because properties can throw when accessed. In this specific case, one of the properties of that object is "lastRunCrashID", which will throw if the build was built with --disable-crashreporter:
https://dxr.mozilla.org/mozilla-central/rev/494289c72ba3997183e7b5beaca3e0447ecaf96d/toolkit/xre/nsAppRunner.cpp#1081

We're only seeing this on ASAN builds because those are the only builds we do in CI that --disable-crashreporter and run tests.

The right fix here is probably to fix wrap_value to have a try/catch around the property enumeration bits.
Maja, is comment 4 something you're able to work with?
Flags: needinfo?(mjzffr)
We could probably simulate these builds well enough on Try by just setting --disable-crashreporter in mozconfig.common.override on a regular Linux64 opt build. In fact, just for kicks...
https://treeherder.mozilla.org/#/jobs?repo=try&revision=16f58ac41f67
(In reply to Ryan VanderMeulen [:RyanVM] from comment #5)
> Maja, is comment 4 something you're able to work with?

Yes. I'm not familiar with the Marionette server stuff yet, but this sounds straightforward. Thanks for reminding me; added to my to-do list. :)
Assignee: nobody → mjzffr
Status: NEW → ASSIGNED
Flags: needinfo?(mjzffr)
Ryan, the call to appInfo got removed by ahal recently [1] so I'm assuming you don't see this issue anymore. Could you confirm?

Regardless, I'll follow-up on Ted's suggestion.

[1] https://hg.mozilla.org/mozilla-central/diff/940686f9541f/testing/marionette/harness/marionette/runner/base.py#l1.111
Flags: needinfo?(ryanvm)
No, it's still reproducing on Ash.
https://treeherder.mozilla.org/logviewer.html#?job_id=167918&repo=ash
Flags: needinfo?(ryanvm)
Attachment #8747298 - Flags: review?(dburns)
Comment on attachment 8747298 [details]
MozReview Request: Bug 1257922 - Marionette runs on ASAN fail due to fatal NS_ERROR_NOT_IMPLEMENTED JavascriptException; r?AutomatedTester

https://reviewboard.mozilla.org/r/49813/#review46553

::: testing/marionette/element.js:231
(Diff revision 1)
>          else {
>            result = {};
>            for (let prop in val) {
> +            try {
> -            result[prop] = this.wrapValue(val[prop]);
> +              result[prop] = this.wrapValue(val[prop]);
> +            } catch (e if (e.result == Components.results.NS_ERROR_NOT_IMPLEMENTED)) {

Can you add `results: Cr` to https://dxr.mozilla.org/mozilla-central/source/testing/marionette/element.js#7

then this line can be changed to 

`(e.result == Cr.NS_ERROR_NOT_IMPLEMENTED)`
Comment on attachment 8747298 [details]
MozReview Request: Bug 1257922 - Marionette runs on ASAN fail due to fatal NS_ERROR_NOT_IMPLEMENTED JavascriptException; r?AutomatedTester

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/49813/diff/1-2/
Attachment #8747298 - Flags: review?(dburns)
Comment on attachment 8747298 [details]
MozReview Request: Bug 1257922 - Marionette runs on ASAN fail due to fatal NS_ERROR_NOT_IMPLEMENTED JavascriptException; r?AutomatedTester

https://reviewboard.mozilla.org/r/49813/#review46557
Attachment #8747298 - Flags: review?(dburns) → review+
https://hg.mozilla.org/mozilla-central/rev/c0e34e377be4
Status: ASSIGNED → RESOLVED
Closed: 8 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla49
Whiteboard: [checkin-needed-aurora]
https://hg.mozilla.org/releases/mozilla-aurora/rev/03754c55722d
Whiteboard: [checkin-needed-aurora]
Product: Testing → Remote Protocol
You need to log in before you can comment on or make changes to this bug.