Closed Bug 1336214 Opened 3 years ago Closed 3 years ago

JS Error stack is mangled since bug 1326534 landed

Categories

(Testing :: Marionette, defect)

Version 3
defect
Not set

Tracking

(firefox52 fixed, firefox-esr52 fixed, firefox53 fixed, firefox54 fixed)

RESOLVED FIXED
mozilla54
Tracking Status
firefox52 --- fixed
firefox-esr52 --- fixed
firefox53 --- fixed
firefox54 --- fixed

People

(Reporter: whimboo, Assigned: ato)

References

Details

Attachments

(3 files)

While working on bug 1326534 today I noticed that a thrown exception in eg. browser.js is not correctly listed anymore. You can reproduce it by just adding the following code at a prominent place:

> browser.getBrowserForTab(null);

Before:

> Marionette threw an error: TypeError: invalid 'in' operand tab
> browser.getBrowserForTab@chrome://marionette/content/browser.js:30:1
> GeckoDriver.prototype.getCurrentWindow@chrome://marionette/content/driver.js:332:9
> GeckoDriver.prototype.getPageSource@chrome://marionette/content/driver.js:1038:30
> TaskImpl_run@resource://gre/modules/Task.jsm:319:42
[..]

Now:

	this.WebDriverError@chrome://marionette/content/error.js:214:17
	sendError@chrome://marionette/content/message.js:258:25
	process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:925:21
	walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7


Also we do not really return the stack to the client as I just noticed, but this is not relevant to the change in the other bug.
ato - can you look at this?  also, does this affect 52, since bug 1326534 is marked fixed on 52.
Flags: needinfo?(ato)
From what I can tell the error is still marshalled and returned to the client, albeit with a misleading stacktrace in some circumstances.  The correct stacktrace is still printed in the error console, as it also was before:

> 1486668095425	Marionette	TRACE	conn8 -> [0,5,"setTestName",{"value":"test_marionette.py TestMarionette.test_wait_for_port_non_existing_process"}]
> 1486668095426	Marionette	TRACE	conn8 <- [1,5,{"error":"webdriver error","message":"invalid 'in' operand tab","stacktrace":"this.WebDriverError@chrome://marionette/content/error.js:214:17\nsendError@chrome://marionette/content/message.js:258:25\nprocess@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:925:21\nwalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7\nPromise*scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:739:11\nschedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:770:7\nPromise.prototype.then@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:455:5\nTaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7\nTaskImpl_run@resource://gre/modules/Task.jsm:327:15\nTaskImpl@resource://gre/modules/Task.jsm:277:3\nasyncFunction@resource://gre/modules/Task.jsm:252:14\nTask_spawn@resource://gre/modules/Task.jsm:166:12\nDispatcher.prototype.execute@chrome://marionette/content/dispatcher.js:118:13\nDispatcher.prototype.onPacket@chrome://marionette/content/dispatcher.js:89:5\n_onJSONObjectReady/<@chrome://marionette/content/server.js -> resource://devtools/shared/transport/transport.js:483:11\nexports.makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/ThreadSafeDevToolsUtils.js:101:14\nexports.makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/ThreadSafeDevToolsUtils.js:101:14\n"},null]
> 
> *************************
> Marionette threw an error: TypeError: invalid 'in' operand tab
> browser.getBrowserForTab@chrome://marionette/content/browser.js:30:1
> GeckoDriver.prototype.setTestName@chrome://marionette/content/driver.js:1973:3
> TaskImpl_run@resource://gre/modules/Task.jsm:319:42
> TaskImpl@resource://gre/modules/Task.jsm:277:3
> asyncFunction@resource://gre/modules/Task.jsm:252:14
> Task_spawn@resource://gre/modules/Task.jsm:166:12
> TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:389:16
> TaskImpl_run@resource://gre/modules/Task.jsm:327:15
> TaskImpl@resource://gre/modules/Task.jsm:277:3
> asyncFunction@resource://gre/modules/Task.jsm:252:14
> Task_spawn@resource://gre/modules/Task.jsm:166:12
> Dispatcher.prototype.execute@chrome://marionette/content/dispatcher.js:118:13
> Dispatcher.prototype.onPacket@chrome://marionette/content/dispatcher.js:89:5
> _onJSONObjectReady/<@chrome://marionette/content/server.js -> resource://devtools/shared/transport/transport.js:483:11
> exports.makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/ThreadSafeDevToolsUtils.js:101:14
> exports.makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/ThreadSafeDevToolsUtils.js:101:14
> 
> 1486668095427	Marionette	TRACE	conn8 -> [0,6,"getContext",null]
> 1486668095427	Marionette	TRACE	conn8 <- [1,6,null,{"value":"content"}]
> 1486668095427	Marionette	TRACE	conn8 -> [0,7,"setContext",{"value":"chrome"}]
> 1486668095427	Marionette	TRACE	conn8 <- [1,7,null,{}]
> 
>  0:02.31 TEST_END: MainThread ERROR, expected PASS
> Traceback (most recent call last):
>   File "/home/ato/src/gecko/testing/marionette/harness/marionette_harness/marionette_test/testcases.py", line 147, in run
>     self.setUp()
>   File "/home/ato/src/gecko/testing/marionette/harness/marionette_harness/marionette_test/testcases.py", line 469, in setUp
>     self.marionette.test_name = self.test_name
>   File "/home/ato/src/gecko/testing/marionette/client/marionette_driver/marionette.py", line 1303, in test_name
>     self._send_message("setTestName", {"value": test_name})
>   File "/home/ato/src/gecko/testing/marionette/client/marionette_driver/decorators.py", line 23, in _
>     return func(*args, **kwargs)
>   File "/home/ato/src/gecko/testing/marionette/client/marionette_driver/marionette.py", line 729, in _send_message
>     self._handle_error(err)
>   File "/home/ato/src/gecko/testing/marionette/client/marionette_driver/marionette.py", line 762, in _handle_error
>     raise errors.lookup(error)(message, stacktrace=stacktrace)
> MarionetteException: invalid 'in' operand tab
> stacktrace:
> 	this.WebDriverError@chrome://marionette/content/error.js:214:17
> 	sendError@chrome://marionette/content/message.js:258:25
> 	process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:925:21
> 	walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:806:7
> 	Promise*scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:739:11
> 	schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:770:7
> 	Promise.prototype.then@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:455:5
> 	TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
> 	TaskImpl_run@resource://gre/modules/Task.jsm:327:15
> 	TaskImpl@resource://gre/modules/Task.jsm:277:3
> 	asyncFunction@resource://gre/modules/Task.jsm:252:14
> 	Task_spawn@resource://gre/modules/Task.jsm:166:12
> 	Dispatcher.prototype.execute@chrome://marionette/content/dispatcher.js:118:13
> 	Dispatcher.prototype.onPacket@chrome://marionette/content/dispatcher.js:89:5
> 	_onJSONObjectReady/<@chrome://marionette/content/server.js -> resource://devtools/shared/transport/transport.js:483:11
> 	exports.makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/ThreadSafeDevToolsUtils.js:101:14
> 	exports.makeInfallible/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/ThreadSafeDevToolsUtils.js:101:14

And let’s be clear: Before the patch referenced above, we did not include the stacktrace at all in the response returned to the client.

I will take closer look at what we can do about this.  Investigating this, I also found some other inconsistencies with our error handling.  It would be good to rectify this.
Flags: needinfo?(ato)
Assignee: nobody → ato
Status: NEW → ASSIGNED
(In reply to Andreas Tolfsen ‹:ato› from comment #2)
> From what I can tell the error is still marshalled and returned to the
> client, albeit with a misleading stacktrace in some circumstances.  The
> correct stacktrace is still printed in the error console, as it also was
> before:

> And let’s be clear: Before the patch referenced above, we did not include
> the stacktrace at all in the response returned to the client.
> 
> I will take closer look at what we can do about this.  Investigating this, I
> also found some other inconsistencies with our error handling.  It would be
> good to rectify this.

Ok.  In that case, this appears to not be a regression, but simply a bug.  Thanks
Keywords: regression
Comment on attachment 8836168 [details]
Bug 1336214 - Remove duplicate error.wrap;

https://reviewboard.mozilla.org/r/111602/#review113016
Attachment #8836168 - Flags: review?(mjzffr) → review+
Comment on attachment 8836170 [details]
Bug 1336214 - Preserve stacktraces in Marionette errors;

https://reviewboard.mozilla.org/r/111606/#review113024

::: testing/marionette/proxy.js:191
(Diff revision 3)
> +      payload = data.toJSON();
> +    } else {
> +      payload = data;
> +    }
> +
> +    const msg = {type: type, data: data};

`data: payload`
Attachment #8836170 - Flags: review?(mjzffr) → review-
Comment on attachment 8836169 [details]
Bug 1336214 - Use static lookup of errors;

https://reviewboard.mozilla.org/r/111604/#review113020

::: testing/marionette/error.js:402
(Diff revision 3)
>    this.name = "UnsupportedOperationError";
>    this.status = "unsupported operation";
>  };
>  UnsupportedOperationError.prototype = Object.create(WebDriverError.prototype);
>  
> -const nameLookup = new Map();
> +const STATUSES = new Map([

Could you please document the motivation for this in your commit message? I'm all for verbose commit messages.
Attachment #8836169 - Flags: review?(mjzffr) → review+
Comment on attachment 8836170 [details]
Bug 1336214 - Preserve stacktraces in Marionette errors;

https://reviewboard.mozilla.org/r/111606/#review113024

> `data: payload`

Good catch.  It is a bit surprising to me that this would still work, however.
Comment on attachment 8836170 [details]
Bug 1336214 - Preserve stacktraces in Marionette errors;

https://reviewboard.mozilla.org/r/111606/#review113686
Attachment #8836170 - Flags: review?(mjzffr) → review+
Pushed by atolfsen@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/af9a91862c82
Remove duplicate error.wrap; r=maja_zf
https://hg.mozilla.org/integration/autoland/rev/eba41ae5c5bf
Use static lookup of errors; r=maja_zf
https://hg.mozilla.org/integration/autoland/rev/f4c341352fad
Preserve stacktraces in Marionette errors; r=maja_zf
Blocks: 1333014
You need to log in before you can comment on or make changes to this bug.