Closed Bug 1322862 Opened 6 years ago Closed 6 years ago

Callbacks and event listeners attached to content sandbox cause permission denied errors when inspected

Categories

(Remote Protocol :: Marionette, defect)

Product:
Remote Protocol
Component:
Marionette
Version:
Version 3
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(firefox52 fixed, firefox53 fixed, firefox54 fixed)

Status:
RESOLVED FIXED
Milestone:
mozilla54
Tracking Flags:
Tracking Status
firefox52 --- fixed
firefox53 --- fixed
firefox54 --- fixed

People

(Reporter: ato, Assigned: ato)

Details

Attachments

(3 files)

Bug 1322862 - Make __webDriverArguments et al. content safe;
58 bytes, text/x-review-board-request
automatedtester
: review+
Details
Bug 1322862 - Compare unicode strings in Python test;
59 bytes, text/x-review-board-request
whimboo
: review+
Details
Bug 1322862 - Wait for forward- and back commands to complete;
59 bytes, text/x-review-board-request
impossibus
: review+
Details 
Marionette attaches callbacks and adds event listeners to the (mutable) content sandbox when executing scripts.  When any of these are inspected they cause the error “Permission denied to access property "toString"” to throw.

Originally reported in https://github.com/mozilla/geckodriver/issues/389.
Assignee: nobody → ato
Status: NEW → ASSIGNED
Comment on attachment 8817843 [details]
Bug 1322862 - Make __webDriverArguments et al. content safe;

https://reviewboard.mozilla.org/r/98064/#review99416
Attachment #8817843 - Flags: review?(dburns) → review+
Pushed by atolfsen@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/9bc09c4c42c8
Make __webDriverCallback et al. content safe; r=automatedtester
Backed out in https://hg.mozilla.org/integration/autoland/rev/447c6f269bdf for frequent (like, 9/25 frequent) Win8 debug https://treeherder.mozilla.org/logviewer.html#?job_id=8297265&repo=autoland

Dunno if anything other than Win8 debug is willing to fail that way, and just hasn't gotten around to doing so yet.
It looks like Python is failing on comparing "about:blank" to u"about:blank".  In other words, this is a test issue to do with unicode encoding in Python.
However, I can’t see what in the patch changed anything to do with navigation.  I’m going to trigger some try runs.
Added a patch which uses unicode strings for comparison in test_navigation.py.  This should hopefully make the intermittent comparisons on Windows 8 go away.  I have no idea why this only happens occasionally, though.
Comment on attachment 8817843 [details]
Bug 1322862 - Make __webDriverArguments et al. content safe;

https://reviewboard.mozilla.org/r/98064/#review102482

::: testing/marionette/evaluate.js:143
(Diff revision 6)
>      // see bug 1128760 for more details
>      if (opts.debug) {
> -      sb.window.onerror = (msg, url, line) => {
> -        let err = new JavaScriptError(`${msg} at: ${url} line: ${line}`);
> +      sb.window.addEventListener("error", (msg, url, line) => {
> +        let err = new JavaScriptError(`${msg} at ${url}:${line}`);
>          reject(err);
> -      };
> +      });

What about removing the listeners? Aren't we leaking the instances now? Can we use the `once` option here?

Also make sure to update the comment above which doesn't seem to apply fully anymore.
Comment on attachment 8823365 [details]
Bug 1322862 - Compare unicode strings in Python test;

https://reviewboard.mozilla.org/r/101906/#review102484

Do you have references to those failures? I would like to inspect them first before reviewing those changes. Thanks.
Comment on attachment 8823365 [details]
Bug 1322862 - Compare unicode strings in Python test;

https://reviewboard.mozilla.org/r/101906/#review102484

This is available in the bug: https://bugzilla.mozilla.org/show_bug.cgi?id=1322862#c8

I have a sense that the Windows 8 intermittents do not stem from the changes in the first patch, so the second patch to address the intermittents is in some sense unrelated.

try run without second patch: https://treeherder.mozilla.org/#/jobs?repo=try&revision=0a6b7d8cda796cab7b96a25dc4970f91f0fa2471
try run with second patch: https://treeherder.mozilla.org/#/jobs?repo=try&revision=0e6b91afafaa

There is still one instance where it fails on `u"about:blank" == u"about:blank"`, but there are certainly fewer of them.
Comment on attachment 8817843 [details]
Bug 1322862 - Make __webDriverArguments et al. content safe;

https://reviewboard.mozilla.org/r/98064/#review102482

> What about removing the listeners? Aren't we leaking the instances now? Can we use the `once` option here?
> 
> Also make sure to update the comment above which doesn't seem to apply fully anymore.

We don’t normally reuse sandboxes, but there is indeed a chance we’re not cleaning up properly by using `addEventListener`.  `{once: true}` wont’t work if an error doesn’t throw, so I guess using the `onerror` setter is a better solution since it gets replaced every time we were to reuse the sandbox.

I’ll revert to using `sb.window.onerror`/`sb.window.onunload`.
Comment on attachment 8823365 [details]
Bug 1322862 - Compare unicode strings in Python test;

https://reviewboard.mozilla.org/r/101906/#review102484

The failures I see here are coming only from the helper property location_href in that test. I wonder if that is an issue with execute_script(). I don't see why we have to fix comparisons for other checks. Did we had those too?
Comment on attachment 8823365 [details]
Bug 1322862 - Compare unicode strings in Python test;

https://reviewboard.mozilla.org/r/101906/#review102484

Possibly, I don’t quite know what is the root cause.  A theory I had was that we are running different Python interpreters on some Windows 8 slaves.
Comment on attachment 8823365 [details]
Bug 1322862 - Compare unicode strings in Python test;

https://reviewboard.mozilla.org/r/101906/#review102484

I would suggest that you update location_href() to return the string as str and let it do a necessary conversion before returning the value. So in case of a unicode string do href.encode('utf-8'). With that we wouldn't have to mess around with all the checks in that test file.
Comment on attachment 8823365 [details]
Bug 1322862 - Compare unicode strings in Python test;

https://reviewboard.mozilla.org/r/101906/#review102484

Good idea.
Comment on attachment 8823365 [details]
Bug 1322862 - Compare unicode strings in Python test;

https://reviewboard.mozilla.org/r/101906/#review103872

::: testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py:38
(Diff revision 4)
>  
>          super(TestNavigate, self).tearDown()
>  
>      @property
>      def location_href(self):
> -        return self.marionette.execute_script("return window.location.href")
> +        return self.marionette.execute_script("return window.location.href").encode("utf-8")

Please add at least a comment why we have to encode the returned value here. You may want to refer to the specific comments in this bug.

But I would be more happy if you can file a new bug, so we can investigate this issue if it becomes more wide-spread.
Attachment #8823365 - Flags: review?(hskupin) → review+
Pushed by atolfsen@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/f7fbaa09b025
Make __webDriverArguments et al. content safe; r=automatedtester
https://hg.mozilla.org/integration/autoland/rev/fa592f5df0fe
Compare unicode strings in Python test; r=whimboo
(In reply to Phil Ringnalda (:philor) from comment #32)
> Backed out in
> https://hg.mozilla.org/integration/autoland/rev/
> 5bf281bce89679ddd6d01091a6606028672a3d3a for fairly frequent
> https://treeherder.mozilla.org/logviewer.html#?job_id=67416401&repo=autoland

What is fairly frequent? I can see two failures for Mn jobs, both for debug builds. A lot of other Mn jobs have been retriggered for this changeset and they all are passing. So I don't actually see why it was backed out. Did other (following) changesets also had this problem? 

Thanks.
Flags: needinfo?(philringnalda)
Thanks Phil. Checking this range it's indeed clear that the patch on this bug caused this.

So go_back() similar to go_forward() and refresh() do not wait for the page load being finished. The easiest fix should be to add a Wait().until() to the test, and wait for the appropriate page being loaded.
(In reply to Henrik Skupin (:whimboo) from comment #35)
> Thanks Phil. Checking this range it's indeed clear that the patch on this
> bug caused this.
> 
> So go_back() similar to go_forward() and refresh() do not wait for the page
> load being finished. The easiest fix should be to add a Wait().until() to
> the test, and wait for the appropriate page being loaded.

I filed https://bugzilla.mozilla.org/show_bug.cgi?id=1330348 about making the forward- and back commands in Marionette synchronous.  We can work around the intermittent issues right now by using Wait.until as whimboo says, but they highlight that the server commands are inadequately implemented in that they do not wait for the document state to update before returning.

By contrast, the Refresh command always expects the document load event to fire, and there is a separate existing bug for fixing this: https://bugzilla.mozilla.org/show_bug.cgi?id=1291320
Because this patch does not qualitatively make the situation on m-c any worse, I’m going to resubmit it to Autoland to see if it sticks this time.  I’m leaning towards filing a separate bug to use the Wait.until workaround until we fix https://bugzilla.mozilla.org/show_bug.cgi?id=1330348, which I suspect is more work.
I wouldn't try to push the patch as it is right now again, given that it will certainly break tests again. With all the green Mn test jobs it will be highly visible, and a backout can be foreseen.
OK, so it appears that we use execute script, which this patch touches, to return the URL after we call Back/Forward in the intermittent tests.  It is possible that this is causing a race condition to occur; possibly because the the getting the arguments is faster now that they are being cloned into the sandbox.
Curious if there is an update on this, I'm not going to pretend I understand much of this thread though :)
Sorry, I haven’t had time to follow-up on this recently due to some holidaying.  The situation right now is that the patch is done, but that it is causing flakiness in our CI.  This means we cannot land it in mozilla-central until we figure out what is causing the flakiness.

See comment #39 for various ideas what might be the reason.
Pushed by atolfsen@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/0d31bc70ba46
Make __webDriverArguments et al. content safe; r=automatedtester
https://hg.mozilla.org/integration/autoland/rev/38d9a0fa515a
Compare unicode strings in Python test; r=whimboo
Backed out for frequent failures in test_navigation.py:

https://hg.mozilla.org/integration/autoland/rev/41fe7b64a199c7c329fcc5978ab18c1f284c1312
https://hg.mozilla.org/integration/autoland/rev/1e8ed0e59c57de5dd137a07fce3cf489e6a8892e

Push with failures: https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=38d9a0fa515abfc32aced8d09704d40c47c6ef23
Failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=73686463&repo=autoland

[task 2017-02-01T21:33:55.986878Z] 21:33:55     INFO - TEST-START | test_navigation.py TestNavigate.test_go_back
[task 2017-02-01T21:33:56.751481Z] 21:33:56     INFO - TEST-PASS | test_navigation.py TestNavigate.test_go_back | took 766ms
[task 2017-02-01T21:33:56.752399Z] 21:33:56     INFO - TEST-START | test_navigation.py TestNavigate.test_go_forward
[task 2017-02-01T21:33:57.606429Z] 21:33:57     INFO - TEST-UNEXPECTED-FAIL | test_navigation.py TestNavigate.test_go_forward | AssertionError: 'http://127.0.0.1:47475/test.html' != 'about:blank'
[task 2017-02-01T21:33:57.606647Z] 21:33:57     INFO - Traceback (most recent call last):
[task 2017-02-01T21:33:57.606793Z] 21:33:57     INFO -   File "/home/worker/workspace/build/venv/local/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 166, in run
[task 2017-02-01T21:33:57.606893Z] 21:33:57     INFO -     testMethod()
[task 2017-02-01T21:33:57.607006Z] 21:33:57     INFO -   File "/home/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py", line 98, in test_go_forward
[task 2017-02-01T21:33:57.607339Z] 21:33:57     INFO -     self.assertEqual(self.test_doc, self.location_href)
Flags: needinfo?(ato)
Andreas, maybe we should wait for bug 1330348 being implemented before trying to push it again?
(In reply to Henrik Skupin (:whimboo) from comment #46)
> Andreas, maybe we should wait for bug 1330348 being implemented before
> trying to push it again?

I think I will try again with explicit waits for the forward/backward tests.
I’ve tried working around the raciness of back/forward by using a couple of wait conditions.  This is suboptimal, but will allow us to land this without waiting for bug 1330348.

I should add that it is curious this patch makes script execution faster, but perhaps not having to cross content/chrome boundaries by copying the functions into the sandbox makes a difference…
Flags: needinfo?(ato)
Comment on attachment 8832861 [details]
Bug 1322862 - Wait for forward- and back commands to complete;

https://reviewboard.mozilla.org/r/109120/#review110782
Attachment #8832861 - Flags: review?(mjzffr) → review+
Pushed by atolfsen@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/ce216a8c272f
Make __webDriverArguments et al. content safe; r=automatedtester
https://hg.mozilla.org/integration/autoland/rev/18fcec744245
Compare unicode strings in Python test; r=whimboo
https://hg.mozilla.org/integration/autoland/rev/93b5ddfa8698
Wait for forward- and back commands to complete; r=maja_zf
Sheriffs: Please uplift to Aurora and Beta as testonly.
Whiteboard: [checkin-needed-aurora][checkin-needed-beta]
Product: Testing → Remote Protocol
You need to log in before you can comment on or make changes to this bug.