Closed Bug 1312674 Opened 3 years ago Closed 3 years ago

Navigating to `about:blank` for a new docShell causes a "Error loading page, timed out (onDOMContentLoaded)"

Categories

(Testing :: Marionette, defect)

Version 3
defect
Not set

Tracking

(firefox49 unaffected, firefox50 fix-optional, firefox51 fixed, firefox52 fixed, firefox53 fixed)

RESOLVED FIXED
mozilla53
Tracking Status
firefox49 --- unaffected
firefox50 --- fix-optional
firefox51 --- fixed
firefox52 --- fixed
firefox53 --- fixed

People

(Reporter: whimboo, Assigned: whimboo)

References

Details

(Keywords: hang, regression)

Attachments

(2 files)

Kinda easy to reproduce issue which happens all the time on my local machine with the attached minimized testcase.

Given that we use about:blank in many cases in our unit tests we should get this misbehavior fixed or our unit tests updated to not make use of about:blank. 

Andreas, would you have any time to check what's going wrong with this specific call to navigate()? This is actually a regression between 49.0.2 and current Firefox 50beta.
Flags: needinfo?(ato)
I’m guessing it has to do with the remoteness change that occurs when navigating to about: documents and/or the changes made in https://github.com/mozilla/gecko-dev/commit/d9c28dead6e8508684e385b796bdba5ae062bc9e (bug 1261842).
Flags: needinfo?(ato)
(In reply to Andreas Tolfsen ‹:ato› from comment #1)
> I’m guessing it has to do with the remoteness change that occurs when
> navigating to about: documents and/or the changes made in
> https://github.com/mozilla/gecko-dev/commit/
> d9c28dead6e8508684e385b796bdba5ae062bc9e (bug 1261842).

Oh my! I totally forgot about this change which landed for Firefox 50. I tested with two builds (07-25 and 07-26) and bug 1261842 is clearly in that range. So I agree that this should be another fallout from those changes.

Mike, will you have the time to look at this?
Blocks: 1261842
Flags: needinfo?(mconley)
I'm not seeing the minimized test case mentioned in comment 0. Was it forgotten?
Flags: needinfo?(mconley) → needinfo?(hskupin)
Attached file minimized testcase
Strange. I'm sure I put this in. Anyway, I recreated it for you.
Flags: needinfo?(hskupin) → needinfo?(mconley)
See Also: → 1314594
(In reply to Henrik Skupin (:whimboo) from comment #0)
> Given that we use about:blank in many cases in our unit tests

How does this frequency of use manifest itself? In mistaken test failures? In harness failures? (I'm very ignorant of our setup here and just trying to help prioritize (and I'm interested particularly because this is marked as a regression in 50).)
Flags: needinfo?(hskupin)
I'm afraid I don't currently have time to look at this.
Flags: needinfo?(mconley)
Hi David, when 47 went live we had a dot release driver issue with Selenium Webdriver. We are a week away from 50 go-live and I don't consider this a release blocking issue. Do you feel the same way?
Flags: needinfo?(dburns)
I dont consider this a release blocking issue since its mostly around about:* and Selenium webdriver users never test against that.
Flags: needinfo?(dburns)
Flags: needinfo?(hskupin)
(In reply to David Burns :automatedtester from comment #8)
> I dont consider this a release blocking issue since its mostly around
> about:* and Selenium webdriver users never test against that.

This might be true but keep in mind that geckodriver uses about:blank for the what's new page:
https://github.com/mozilla/geckodriver/blob/master/src/marionette.rs#L102

Given that I do not see a pref value for `browser.newtab.url` I assume that it will default to `about:newtab` for opening new tabs. But for opening new windows or links into new tabs we also load `about:blank` as first step (bug 610357). It means `about:blank` is in use even not intentionally.
Summary: Navigating twice to about:blank hangs Marionette → Navigating to `about:blank` when Firefox started up causes "Error loading page, timed out (onDOMContentLoaded)"
Andreas, could it be a problem because the get command is still using the old dispatching technique (bug 1242595)?
Flags: needinfo?(ato)
I think I found the problem which is causing the page load timeout:

https://hg.mozilla.org/mozilla-central/annotate/bad312aefb42982f492ad2cf36f4c6c3d698f4f7/testing/marionette/listener.js#l994

We want to ensure to not return early for the initial load of about:blank for each newly opened tab. But this actually will fail because in this case we want to load about:blank. I think what we have to do here is to simply add an exception if the requestedURL is about:blank.
Flags: needinfo?(ato)
It's actually another regression from the patch on bug 1261842.
Assignee: nobody → hskupin
Status: NEW → ASSIGNED
Summary: Navigating to `about:blank` when Firefox started up causes "Error loading page, timed out (onDOMContentLoaded)" → Navigating to `about:blank` for a new docShell causes a "Error loading page, timed out (onDOMContentLoaded)"
(In reply to Henrik Skupin (:whimboo) from comment #10)
> Andreas, could it be a problem because the get command is still using the
> old dispatching technique (bug 1242595)?

The navigation command in the listener cannot be easily converted to use the new dispatching technique because it requires multiple roundtrips back and forth between driver.js and listener.js.  The `proxy.AsyncMessageChannel` only supports one blocking request at the time.
(In reply to Henrik Skupin (:whimboo) from comment #11)
> I think I found the problem which is causing the page load timeout:
> 
> https://hg.mozilla.org/mozilla-central/annotate/
> bad312aefb42982f492ad2cf36f4c6c3d698f4f7/testing/marionette/listener.js#l994
> 
> We want to ensure to not return early for the initial load of about:blank
> for each newly opened tab. But this actually will fail because in this case
> we want to load about:blank. I think what we have to do here is to simply
> add an exception if the requestedURL is about:blank.

That sounds likely to me.
Attachment #8814451 - Flags: review?(ato)
Comment on attachment 8814451 [details]
Bug 1312674 - Navigating to about:blank for a new docshell should not timeout.

https://reviewboard.mozilla.org/r/95680/#review95744

r+, but there are some test failures on Windows.  Not sure if they are infra related.

::: testing/marionette/harness/marionette/tests/unit/test_navigation.py:134
(Diff revision 1)
>          self.assertEqual("complete", state)
>          self.assertTrue(self.marionette.find_element(By.ID, "mozLink"))
>  
>      def test_error_when_exceeding_page_load_timeout(self):
>          with self.assertRaises(TimeoutException):
> -            self.marionette.timeout.page_load = 0
> +            self.marionette.set_page_load_timeout(0)

I guess you did not mean to make this change?

::: testing/marionette/listener.js:997
(Diff revision 1)
> +    let loadedRequestedURI = (requestedURL == "about:blank") |
> +                             docShell.hasLoadedNonBlankURI;

Do you mean bitwise OR here?

::: testing/marionette/listener.js:998
(Diff revision 1)
>  
> -    // We also need to make sure that the DOMContentLoaded we saw isn't
> -    // for the initial about:blank of a newly created docShell.
> -    let loadedNonAboutBlank = docShell.hasLoadedNonBlankURI;
> +    // We also need to make sure that if the requested URL is not about:blank
> +    // the DOMContentLoaded we saw isn't for the initial about:blank of a newly
> +    // created docShell.
> +    let loadedRequestedURI = (requestedURL == "about:blank") |
> +                             docShell.hasLoadedNonBlankURI;

Second line of a statement should have indentation of four spaces.
Attachment #8814451 - Flags: review?(ato) → review+
Comment on attachment 8814451 [details]
Bug 1312674 - Navigating to about:blank for a new docshell should not timeout.

https://reviewboard.mozilla.org/r/95680/#review95944

::: testing/marionette/harness/marionette/tests/unit/test_navigation.py:134
(Diff revision 1)
>          self.assertEqual("complete", state)
>          self.assertTrue(self.marionette.find_element(By.ID, "mozLink"))
>  
>      def test_error_when_exceeding_page_load_timeout(self):
>          with self.assertRaises(TimeoutException):
> -            self.marionette.timeout.page_load = 0
> +            self.marionette.set_page_load_timeout(0)

Nope. Looks like a bad rebase against central.

::: testing/marionette/listener.js:997
(Diff revision 1)
> +    let loadedRequestedURI = (requestedURL == "about:blank") |
> +                             docShell.hasLoadedNonBlankURI;

Nope. Simply haven't used an `or` in JS for a long time and missed that subtle point.

::: testing/marionette/listener.js:998
(Diff revision 1)
>  
> -    // We also need to make sure that the DOMContentLoaded we saw isn't
> -    // for the initial about:blank of a newly created docShell.
> -    let loadedNonAboutBlank = docShell.hasLoadedNonBlankURI;
> +    // We also need to make sure that if the requested URL is not about:blank
> +    // the DOMContentLoaded we saw isn't for the initial about:blank of a newly
> +    // created docShell.
> +    let loadedRequestedURI = (requestedURL == "about:blank") |
> +                             docShell.hasLoadedNonBlankURI;

Why four spaces? This is Javascript so it should have 2 spaces. Beside that I still find it a strange formatting and it doesn't really apply to our JS coding styles for Firefox. 

We should really have a follow-up bug to make the code more style-guide friendly. 

Anyway, going to update as requested.
Pushed by hskupin@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/7ce5e47c372f
Navigating to about:blank for a new docshell should not timeout. r=ato
https://hg.mozilla.org/mozilla-central/rev/7ce5e47c372f
Status: ASSIGNED → RESOLVED
Closed: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla53
test-only change which we would like to have for aurora and beta. Can you please uplift? Thanks.
Whiteboard: [checkin-needed-aurora][checkin-needed-beta]
https://hg.mozilla.org/releases/mozilla-aurora/rev/939bb4af0df7
Flags: in-testsuite+
Whiteboard: [checkin-needed-aurora][checkin-needed-beta] → [checkin-needed-beta]
You need to log in before you can comment on or make changes to this bug.