1594921 - Intermittent fission browser/components/extensions/test/browser/browser_ext_webNavigation_urlbar_transitions.js | Got the expected url - Expected: http://mochi.test:8888/, Actual: about:blank -

Status: RESOLVED FIXED

(WebExtensions :: General, defect, P3)

Description

[Treeherder Bug Filer]

Filed by: nerli [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=275169197&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/J79IsDMNRWaoSuUefqXsPQ/runs/0/artifacts/public/logs/live_backing.log

---

[task 2019-11-07T22:11:36.826Z] 22:11:36 INFO - TEST-PASS | browser/components/extensions/test/browser/browser_ext_webNavigation_urlbar_transitions.js | webNavigation.from_address_bar.keyword -
[task 2019-11-07T22:11:36.827Z] 22:11:36 INFO - TEST-PASS | browser/components/extensions/test/browser/browser_ext_webNavigation_urlbar_transitions.js | test result correct -
[task 2019-11-07T22:11:36.831Z] 22:11:36 INFO - Leaving test bound test_webnavigation_urlbar_keyword_transition
[task 2019-11-07T22:11:36.832Z] 22:11:36 INFO - Entering test bound test_webnavigation_urlbar_search_transitions
[task 2019-11-07T22:11:36.833Z] 22:11:36 INFO - Extension loaded
[task 2019-11-07T22:11:36.833Z] 22:11:36 INFO - Console message: [JavaScript Error: "getScreenshot(http://example.com/?q=bookmark) failed: TypeError: NetworkError when attempting to fetch resource." {file: "resource://activity-stream/lib/Screenshots.jsm" line: 59}]
[task 2019-11-07T22:11:36.834Z] 22:11:36 INFO - getScreenshotForURL@resource://activity-stream/lib/Screenshots.jsm:59:10
[task 2019-11-07T22:11:36.834Z] 22:11:36 INFO - asyncmaybeCacheScreenshot@resource://activity-stream/lib/Screenshots.jsm:112:37
[task 2019-11-07T22:11:36.835Z] 22:11:36 INFO - fetchImage@resource://activity-stream/lib/HighlightsFeed.jsm:298:24
[task 2019-11-07T22:11:36.835Z] 22:11:36 INFO - fetchHighlights@resource://activity-stream/lib/HighlightsFeed.jsm:242:14
[task 2019-11-07T22:11:36.836Z] 22:11:36 INFO - asynconAction@resource://activity-stream/lib/HighlightsFeed.jsm:334:14
[task 2019-11-07T22:11:36.836Z] 22:11:36 INFO - _middleware/</<@resource://activity-stream/lib/Store.jsm:63:17
[task 2019-11-07T22:11:36.837Z] 22:11:36 INFO - Store/this[method]@resource://activity-stream/lib/Store.jsm:39:54
[task 2019-11-07T22:11:36.837Z] 22:11:36 INFO - customDispatch/this.placesChangedTimer<@resource://activity-stream/lib/PlacesFeed.jsm:233:22
[task 2019-11-07T22:11:36.837Z] 22:11:36 INFO -
[task 2019-11-07T22:11:36.838Z] 22:11:36 INFO - Console message: Warning: attempting to write 38038 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes.
[task 2019-11-07T22:11:36.839Z] 22:11:36 INFO - Waiting for engine to be added: searchSuggestionEngine.xml
[task 2019-11-07T22:11:36.839Z] 22:11:36 INFO - Search engine added: searchSuggestionEngine.xml
[task 2019-11-07T22:11:36.840Z] 22:11:36 INFO - Console message: [JavaScript Error: "Security Error: Content at about:newtab may not load or link to chrome://mozapps/skin/places/defaultFavicon.svg."]
[task 2019-11-07T22:11:36.840Z] 22:11:36 INFO - Console message: [JavaScript Error: "Security Error: Content at about:newtab may not load or link to chrome://mozapps/skin/places/defaultFavicon.svg."]
[task 2019-11-07T22:11:36.842Z] 22:11:36 INFO - Buffered messages finished
[task 2019-11-07T22:11:36.842Z] 22:11:36 INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_webNavigation_urlbar_transitions.js | Got the expected url - Expected: http://mochi.test:8888/, Actual: about:blank -
[task 2019-11-07T22:11:36.842Z] 22:11:36 INFO - Stack trace:
[task 2019-11-07T22:11:36.842Z] 22:11:36 INFO - chrome://mochikit/content/browser-test.js:test_ok:1299
[task 2019-11-07T22:11:36.843Z] 22:11:36 INFO - chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:testHandler:59
[task 2019-11-07T22:11:36.843Z] 22:11:36 INFO - chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:testResult:73
[task 2019-11-07T22:11:36.843Z] 22:11:36 INFO - resource://specialpowers/SpecialPowersChild.jsm:listener:2051
[task 2019-11-07T22:11:36.843Z] 22:11:36 INFO - resource://specialpowers/SpecialPowersChild.jsm:loadExtension/<:1993
[task 2019-11-07T22:11:36.844Z] 22:11:36 INFO - resource://specialpowers/SpecialPowersChild.jsm:receiveMessage:242
[task 2019-11-07T22:11:36.844Z] 22:11:36 INFO - TEST-PASS | browser/components/extensions/test/browser/browser_ext_webNavigation_urlbar_transitions.js | Got the expected from_address_bar transitionQualifier -
[task 2019-11-07T22:11:36.846Z] 22:11:36 INFO - TEST-PASS | browser/components/extensions/test/browser/browser_ext_webNavigation_urlbar_transitions.js | Got the expected 'generated' transitionType - Expected: generated, Actual: generated -
[task 2019-11-07T22:11:36.846Z] 22:11:36 INFO - TEST-PASS | browser/components/extensions/test/browser/browser_ext_webNavigation_urlbar_transitions.js | webNavigation.from_address_bar.generated -
[task 2019-11-07T22:11:36.847Z] 22:11:36 INFO - TEST-PASS | browser/components/extensions/test/browser/browser_ext_webNavigation_urlbar_transitions.js | test result correct -
[task 2019-11-07T22:11:36.847Z] 22:11:36 INFO - Leaving test bound test_webnavigation_urlbar_search_transitions
[task 2019-11-07T22:11:36.847Z] 22:11:36 INFO - GECKO(1177) | ++DOMWINDOW == 4 (0x7f957a304800) [pid = 1529] [serial = 549] [outer = 0x7f957bdfd3e0]
[task 2019-11-07T22:11:37.057Z] 22:11:37 INFO - GECKO(1177) | [Parent 1177, Main Thread] WARNING: Suboptimal indexes for the SQL statement 0x7fb9b7ca2710 (http://mzl.la/1FuID0j).: file /builds/worker/workspace/build/src/storage/mozStoragePrivateHelpers.cpp, line 108
[task 2019-11-07T22:11:37.113Z] 22:11:37 INFO - GECKO(1177) | MEMORY STAT | vsize 4025MB | residentFast 853MB | heapAllocated 424MB
[task 2019-11-07T22:11:37.114Z] 22:11:37 INFO - TEST-OK | browser/components/extensions/test/browser/browser_ext_webNavigation_urlbar_transitions.js | took 9589ms
[task 2019-11-07T22:11:37.117Z] 22:11:37 INFO - GECKO(1177) | ++DOCSHELL 0x7f9fa5ab6800 == 1 [pid = 1256] [id = {a0b4874d-4ff7-43f8-a752-29169867ba4c}]
[task 2019-11-07T22:11:37.118Z] 22:11:37 INFO - GECKO(1177) | ++DOMWINDOW == 1 (0x7f9fab9c1100) [pid = 1256] [serial = 278] [outer = (nil)]
[task 2019-11-07T22:11:37.120Z] 22:11:37 INFO - GECKO(1177) | ++DOMWINDOW == 2 (0x7f9fa5a1d400) [pid = 1256] [serial = 279] [outer = 0x7f9fab9c1100]
[task 2019-11-07T22:11:37.216Z] 22:11:37 INFO - GECKO(1177) | ++DOMWINDOW == 3 (0x7f9fa5a24c00) [pid = 1256] [serial = 280] [outer = 0x7f9fab9c1100]
[task 2019-11-07T22:11:37.252Z] 22:11:37 INFO - checking window state
[task 2019-11-07T22:11:37.253Z] 22:11:37 INFO - GECKO(1177) | --DOMWINDOW == 5 (0x7fcf29acd000) [pid = 1869] [serial = 261] [outer = (nil)] [url = about:blank]
[task 2019-11-07T22:11:37.254Z] 22:11:37 INFO - GECKO(1177) | --DOCSHELL 0x7fcf29add800 == 0 [pid = 1869] [id = {1b4b017f-07d5-4127-8859-38349b277373}] [url = http://example.com/?q=search]

Comment 1

[Intermittent Failures Robot]

9 failures in 4850 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 3
• mozilla-inbound: 1
• mozilla-central: 5

Platform breakdown:

• linux64: 9

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1594921&startday=2019-11-04&endday=2019-11-10&tree=all

Comment 2

[Intermittent Failures Robot]

17 failures in 4207 pushes (0.004 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 8
• mozilla-central: 8
• try: 1

Platform breakdown:

• linux64: 17

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1594921&startday=2019-11-11&endday=2019-11-17&tree=all

Comment 3

[Intermittent Failures Robot]

13 failures in 5444 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 3
• autoland: 7
• mozilla-central: 3

Platform breakdown:

• linux64: 13

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1594921&startday=2019-11-18&endday=2019-11-24&tree=all

Comment 4

[Intermittent Failures Robot]

18 failures in 4331 pushes (0.004 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 12
• mozilla-central: 5
• try: 1

Platform breakdown:

• linux64: 18

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1594921&startday=2019-11-25&endday=2019-12-01&tree=all

Comment 5

[Intermittent Failures Robot]

41 failures in 5144 pushes (0.008 failures/push) were associated with this bug in the last 7 days.

This is the #21 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• mozilla-central: 6
• autoland: 32
• try: 3

Platform breakdown:

• linux64: 41

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1594921&startday=2019-12-02&endday=2019-12-08&tree=all

Comment 6

[Intermittent Failures Robot]

40 failures in 4867 pushes (0.008 failures/push) were associated with this bug in the last 7 days.

This is the #30 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• mozilla-central: 3
• autoland: 33
• try: 4

Platform breakdown:

• linux64: 40

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1594921&startday=2019-12-09&endday=2019-12-15&tree=all

Comment 7

[Intermittent Failures Robot]

24 failures in 933 pushes (0.026 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 20
• try: 3
• mozilla-central: 1

Platform breakdown:

• linux64: 24

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1594921&startday=2019-12-19&endday=2019-12-19&tree=all

Comment 8

[Intermittent Failures Robot]

56 failures in 4582 pushes (0.012 failures/push) were associated with this bug in the last 7 days.

This is the #24 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 47
• try: 6
• mozilla-central: 3

Platform breakdown:

• linux64: 56

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1594921&startday=2019-12-16&endday=2019-12-22&tree=all

Comment 9

[Intermittent Failures Robot]

12 failures in 1365 pushes (0.009 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 5
• try: 4
• mozilla-central: 3

Platform breakdown:

• linux64: 12

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1594921&startday=2019-12-23&endday=2019-12-29&tree=all

Comment 10

[Intermittent Failures Robot]

17 failures in 1862 pushes (0.009 failures/push) were associated with this bug in the last 7 days.

This is the #46 most frequent failure this week.

Repository breakdown:

• autoland: 13
• mozilla-central: 2
• try: 2

Platform breakdown:

• linux64: 17

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1594921&startday=2019-12-30&endday=2020-01-05&tree=all

Comment 11

[Shane Caraveo (:mixedpuppy)]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=c47067a7463f15654ce2788086b44121df077b88

Comment 12

[Shane Caraveo (:mixedpuppy)]

Attachment: Bug 1594921 fix intermittent browser.webNavigation failure

Comment 13

[Shane Caraveo (:mixedpuppy)]

The issue here is that we get two calls to onLocationChange in WebNavigationContent.js,
one for about:blank, the one for the actual document location being loaded. The code
is not expecting two consecutive calls like that. I can find no way to differentiate
the two calls other than by url, and I'm uncertain that we want to skip all
about:blank calls here.

For now we'll just bump this over to a fission bug.

Comment 14

[Luca Greco [:rpl] [:luca] [:lgreco]]

I took another deeper look this morning, to collect some additional logs by triggering the issue locally and to get a better sense of the underlying issue.

After some digging and some thinking, I noticed that the unexpected "about:blank" navigation seems to be triggered by the
test harness, in particular from here in testing/mochitest/browser-test.js. where we are basically doing in rapid sequence:

• closing the tab used by the previous test case
• adding a new blank one
• and finally calling gBrowser.stop()

The unexpected "about:blank" onLocationChange seems to be triggered every time the following conditions are met:

• a navigation is still ongoing (e.g. the one triggered by the test case running right before the one that fails)
• the request triggered by gBrowser.stop() did reach the child process ([1]) after the test extension is already listening for webNavigation API events
  and near before we have just triggered the webNavigation scenario that we are going to test

To avoid to skip all these webNavigation tests on fission (and risk more regressions on fission because of the test coverage lost) we may workaround the issue by making sure that every one of these test case are running in a fresh tab (e.g. using BrowserTestUtils.withNewTab),
and file a separate issue to don't forget that the webNavigation event may misbehaving under these conditions (not sure yet how easy would be for a real user to trigger this exact scenario) and look into an actual fix.

Shane,
how that sounds to you?

---

[1]: received by WebNavigationChild.jsm, which is a JSWindowActor related to RemoteWebNavigation.jsm

Comment 15

[Shane Caraveo (:mixedpuppy)]

Well, I tried that. It reduced the frequency of the problem, but didn't fix it.

Comment 16

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/5be6e4c5ebcc
fix intermittent browser.webNavigation failure r=rpl

Comment 17

[Andreea Pavel [:apavel]]

https://hg.mozilla.org/mozilla-central/rev/5be6e4c5ebcc

Comment 18

[Intermittent Failures Robot]

28 failures in 4472 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

This is the #48 most frequent failure this week.

Repository breakdown:

• autoland: 22
• try: 3
• mozilla-central: 3

Platform breakdown:

• linux64: 28

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1594921&startday=2020-01-06&endday=2020-01-12&tree=all

Comment 19

[Shane Caraveo (:mixedpuppy)]

regarding comment 18, note that there are no further errors once we disabled for fission.

Comment 20

[Shane Caraveo (:mixedpuppy)]

fission? to deal with the intermittent with fission.

Comment 21

[Chris Peterson [:cpeterson]]

Shane, the WebExtension team should fix this test failure. This is probably a race in the test itself. If your investigation points to a bug in core Fission or IPC code, then the Fission team can take over.

Tracking for mochitest failures for Fission mochitest milestone (M4.1)

Comment 22

[Shane Caraveo (:mixedpuppy)]

removing priority so it shows up in our weekly triage

Comment 23

[Chris Peterson [:cpeterson]]

This bug is a blocker for Fission's current milestone (M4.1 aka "fix all the mochitests"), but it's currently unassigned. The Fission team is hoping teams will fix their mochitests for Fission before the end of Q1 (75 or 76 Nightly).

If you don't think this mochitest failure should block shipping Fission, just let me know

If you have questions for Fission engineers, you can reach them in the #fission channel on Slack or Riot.

Comment 24

[Chris Peterson [:cpeterson]]

Shane, you disabled this test (browser_ext_webNavigation_urlbar_transitions.js) for Fission because it was failing intermittently. Does fixing and re-enabling this test need to block enabling Fission in Nightly?

Comment 25

[Chris Peterson [:cpeterson]]

The Fission team hopes to roll out Fission to some Nightly users in Q3, so it would be good if all tests are passing and enabled for Fission by the end of Q2.

Comment 26

[Shane Caraveo (:mixedpuppy)]

It probably doesn't need to block, but it should be on a list to be addressed. Looks like Tom has a ni? for himself.

Comment 27

[Chris Peterson [:cpeterson]]

(In reply to Shane Caraveo (:mixedpuppy) from comment #26)

It probably doesn't need to block, but it should be on a list to be addressed.

Thanks. In that case, I'll defer this bug to our Fission M7 Beta milestone (ride the trains to Beta). That will ensure we revisit this bug again before release.

Comment 28

[Chris Peterson [:cpeterson]]

zombie says this bug likely doesn't need to block Fission M7, but it's simple enough that he'd like to try to fix it in M7.

Comment 29

[Tomislav Jovanovic :zombie]

Moving to M8 to better reflect priories.

Comment 30

[Intermittent Failures Robot]

19 failures in 714 pushes (0.027 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 9
• mozilla-central: 10

Platform and build breakdown:

• linux1804-64: 11
  • debug: 11
• windows10-64-shippable-qr: 3
  • opt: 3
• windows10-64-shippable: 3
  • opt: 3
• linux1804-64-shippable: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1594921&startday=2021-03-26&endday=2021-03-26&tree=all

Comment 31

[Alexandru Michis [:malexandru]]

Kris, retriggers point to Bug 1581859 being the cause of the recent failure spike.
Could you please take a look?

Comment 32

[Intermittent Failures Robot]

20 failures in 164 pushes (0.122 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 9
• mozilla-central: 11

Platform and build breakdown:

• linux1804-64: 11
  • debug: 11
• linux1804-64-shippable: 2
  • opt: 2
• windows10-64-shippable-qr: 4
  • opt: 4
• windows10-64-shippable: 3
  • opt: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1594921&startday=2021-03-27&endday=2021-03-27&tree=all

Comment 33

[Andreea Pavel [:apavel]]

There are 59 total failures in the last 7 days on

• linux1804-64 debug
• linux1804-64-shippable opt
• windows10-64-shippable opt
• windows10-64-shippable-qr opt
  Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=334716051&repo=mozilla-central&lineNumber=28595

[task 2021-03-28T22:28:10.954Z] 22:28:10 INFO - TEST-START | browser/components/extensions/test/browser/browser_ext_webNavigation_urlbar_transitions.js
[task 2021-03-28T22:28:10.971Z] 22:28:10 INFO - GECKO(1530) | [Child 9303: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7f89f2fb2400 == 2 [pid = 9303] [id = 0] [url = http://mochi.test:8888/browser/browser/components/extensions/test/browser/webNav_createdTargetSource.html]
[task 2021-03-28T22:28:10.971Z] 22:28:10 INFO - GECKO(1530) | [Child 9303: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7f89ec506400 == 1 [pid = 9303] [id = 1] [url = http://mochi.test:8888/browser/browser/components/extensions/test/browser/webNav_createdTargetSource_subframe.html]
[task 2021-03-28T22:28:10.971Z] 22:28:10 INFO - GECKO(1530) | [Child 9303: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7f89ec5c5800 == 0 [pid = 9303] [id = 2] [url = http://mochi.test:8888/browser/browser/components/extensions/test/browser/webNav_createdTarget.html#new-tab-from-window-open]
[task 2021-03-28T22:28:11.047Z] 22:28:11 INFO - GECKO(1530) | [Child 9303: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 8 (7f89f2fb5c00) [pid = 9303] [serial = 2] [outer = 0] [url = about:blank]
[task 2021-03-28T22:28:11.047Z] 22:28:11 INFO - GECKO(1530) | [Child 9303: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 7 (7f89ec544740) [pid = 9303] [serial = 6] [outer = 0] [url = http://mochi.test:8888/browser/browser/components/extensions/test/browser/webNav_createdTarget.html#new-tab-from-window-open]
[task 2021-03-28T22:28:11.047Z] 22:28:11 INFO - GECKO(1530) | [Child 9303: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 6 (7f8a09763e40) [pid = 9303] [serial = 1] [outer = 0] [url = http://mochi.test:8888/browser/browser/components/extensions/test/browser/webNav_createdTargetSource.html]
[task 2021-03-28T22:28:11.051Z] 22:28:11 INFO - GECKO(1530) | [Child 9303: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 5 (7f89ec544040) [pid = 9303] [serial = 4] [outer = 0] [url = http://mochi.test:8888/browser/browser/components/extensions/test/browser/webNav_createdTargetSource_subframe.html]
[task 2021-03-28T22:28:11.051Z] 22:28:11 INFO - GECKO(1530) | [Child 9303: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 4 (7f89ec5c6800) [pid = 9303] [serial = 7] [outer = 0] [url = about:blank]
[task 2021-03-28T22:28:11.051Z] 22:28:11 INFO - GECKO(1530) | [Child 9303: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (7f89ec5ca400) [pid = 9303] [serial = 8] [outer = 0] [url = about:blank]
[task 2021-03-28T22:28:11.051Z] 22:28:11 INFO - GECKO(1530) | [Child 9303: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (7f89f2fb8800) [pid = 9303] [serial = 5] [outer = 0] [url = http://mochi.test:8888/browser/browser/components/extensions/test/browser/webNav_createdTargetSource_subframe.html]
[task 2021-03-28T22:28:11.052Z] 22:28:11 INFO - GECKO(1530) | [Child 9303: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (7f89f2fbd000) [pid = 9303] [serial = 3] [outer = 0] [url = http://mochi.test:8888/browser/browser/components/extensions/test/browser/webNav_createdTargetSource.html]
[task 2021-03-28T22:28:11.053Z] 22:28:11 INFO - GECKO(1530) | [Child 9303: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (7f89ec5ccc00) [pid = 9303] [serial = 9] [outer = 0] [url = http://mochi.test:8888/browser/browser/components/extensions/test/browser/webNav_createdTarget.html#new-tab-from-window-open]
[task 2021-03-28T22:28:11.056Z] 22:28:11 INFO - GECKO(1530) | [Child 9303, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3365
[task 2021-03-28T22:28:11.066Z] 22:28:11 INFO - GECKO(1530) | [Child 9303, Main Thread] WARNING: '!obs', file /builds/worker/checkouts/gecko/toolkit/components/sessionstore/RestoreTabContentObserver.cpp:58
[task 2021-03-28T22:28:11.125Z] 22:28:11 INFO - GECKO(1530) | [Child 9303, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4442
[task 2021-03-28T22:28:11.132Z] 22:28:11 INFO - GECKO(1530) | [Child 1616: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7f7809589400 == 8 [pid = 1616] [id = 836]
[task 2021-03-28T22:28:11.132Z] 22:28:11 INFO - GECKO(1530) | [Child 1616: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 21 (7f7808f1d3c0) [pid = 1616] [serial = 2393] [outer = 0]
[task 2021-03-28T22:28:11.133Z] 22:28:11 INFO - GECKO(1530) | [Child 1616: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 22 (7f7814604000) [pid = 1616] [serial = 2394] [outer = 7f7808f1d3c0]
[task 2021-03-28T22:28:11.133Z] 22:28:11 INFO - GECKO(1530) | [Parent 1530, Main Thread] WARNING: Need BrowserChild to get the nativeWindow from!: file /builds/worker/checkouts/gecko/widget/PuppetWidget.cpp:1026
[task 2021-03-28T22:28:11.149Z] 22:28:11 INFO - GECKO(1530) | [Child 1616, Main Thread] WARNING: Fallback to BasicLayerManager: file /builds/worker/checkouts/gecko/dom/ipc/BrowserChild.cpp:2702
[task 2021-03-28T22:28:11.176Z] 22:28:11 INFO - GECKO(1530) | [Child 1616: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 23 (7f7814c56c00) [pid = 1616] [serial = 2395] [outer = 7f7808f1d3c0]
[task 2021-03-28T22:28:12.016Z] 22:28:12 INFO - GECKO(1530) | [Child 1616: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 22 (7f7809590400) [pid = 1616] [serial = 2378] [outer = 0] [url = moz-extension://9b017a59-4d8c-4ec4-ab16-17e04afc424c/_generated_background_page.html]
[task 2021-03-28T22:28:12.016Z] 22:28:12 INFO - GECKO(1530) | [Child 1616: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 21 (7f7808f8cc00) [pid = 1616] [serial = 2383] [outer = 0] [url = about:blank]
[task 2021-03-28T22:28:12.017Z] 22:28:12 INFO - GECKO(1530) | [Child 1616: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7f7808f89c00 == 7 [pid = 1616] [id = 833] [url = moz-extension://ef824e4c-8c05-4d77-8a47-cc566d15840d/_generated_background_page.html]
[task 2021-03-28T22:28:12.017Z] 22:28:12 INFO - GECKO(1530) | [Child 1616: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7f7809581800 == 6 [pid = 1616] [id = 834] [url = moz-extension://ef824e4c-8c05-4d77-8a47-cc566d15840d/popup.html]
[task 2021-03-28T22:28:12.017Z] 22:28:12 INFO - GECKO(1530) | [Child 1616: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7f7809584c00 == 5 [pid = 1616] [id = 835] [url = about:blank]
[task 2021-03-28T22:28:12.172Z] 22:28:12 INFO - GECKO(1530) | [Child 1616: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 20 (7f7808f1d580) [pid = 1616] [serial = 2388] [outer = 0] [url = moz-extension://ef824e4c-8c05-4d77-8a47-cc566d15840d/popup.html]
[task 2021-03-28T22:28:12.173Z] 22:28:12 INFO - GECKO(1530) | [Child 1616: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 19 (7f78146d9200) [pid = 1616] [serial = 2391] [outer = 0] [url = about:blank]
[task 2021-03-28T22:28:12.173Z] 22:28:12 INFO - GECKO(1530) | [Child 1616: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 18 (7f7808f1d040) [pid = 1616] [serial = 2385] [outer = 0] [url = moz-extension://ef824e4c-8c05-4d77-8a47-cc566d15840d/_generated_background_page.html]
[task 2021-03-28T22:28:12.174Z] 22:28:12 INFO - GECKO(1530) | [Child 1616: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 17 (7f7808f1d200) [pid = 1616] [serial = 2382] [outer = 0] [url = moz-extension://5ded5dc5-70a8-4875-8c0d-7abd2cba17ae/_generated_background_page.html]
[task 2021-03-28T22:28:12.403Z] 22:28:12 INFO - GECKO(1530) | [Child 9328: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7f8a6c4b3000 == 1 [pid = 9328] [id = 0]
[task 2021-03-28T22:28:12.404Z] 22:28:12 INFO - GECKO(1530) | [Child 9328: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (7f8a82c63e40) [pid = 9328] [serial = 1] [outer = 0]
[task 2021-03-28T22:28:12.406Z] 22:28:12 INFO - GECKO(1530) | [Child 9328: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (7f8a6c4b6800) [pid = 9328] [serial = 2] [outer = 7f8a82c63e40]
[task 2021-03-28T22:28:12.517Z] 22:28:12 INFO - TEST-INFO | started process screentopng
[task 2021-03-28T22:28:12.970Z] 22:28:12 INFO - TEST-INFO | screentopng: exit 0
[task 2021-03-28T22:28:12.970Z] 22:28:12 INFO - Buffered messages logged at 22:28:10
[task 2021-03-28T22:28:12.970Z] 22:28:12 INFO - Entering test bound test_webnavigation_urlbar_typed_transitions
[task 2021-03-28T22:28:12.970Z] 22:28:12 INFO - Extension loaded
[task 2021-03-28T22:28:12.971Z] 22:28:12 INFO - Buffered messages logged at 22:28:11
[task 2021-03-28T22:28:12.972Z] 22:28:12 INFO - Console message: Warning: attempting to write 39560 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes.
[task 2021-03-28T22:28:12.973Z] 22:28:12 INFO - Buffered messages finished
[task 2021-03-28T22:28:12.975Z] 22:28:12 INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_webNavigation_urlbar_transitions.js | Got the expected url - Expected: http://example.com/?q=typed, Actual: about:blank -
[task 2021-03-28T22:28:12.976Z] 22:28:12 INFO - Stack trace:
[task 2021-03-28T22:28:12.976Z] 22:28:12 INFO - chrome://mochikit/content/browser-test.js:test_ok:1331
[task 2021-03-28T22:28:12.978Z] 22:28:12 INFO - chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:testHandler:68
[task 2021-03-28T22:28:12.983Z] 22:28:12 INFO - chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:testResult:82
[task 2021-03-28T22:28:12.985Z] 22:28:12 INFO - resource://specialpowers/SpecialPowersChild.jsm:listener:1977
[task 2021-03-28T22:28:12.986Z] 22:28:12 INFO - resource://specialpowers/SpecialPowersChild.jsm:loadExtension/<:1915
[task 2021-03-28T22:28:12.987Z] 22:28:12 INFO - resource://specialpowers/SpecialPowersChild.jsm:receiveMessage:267
[task 2021-03-28T22:28:12.988Z] 22:28:12 INFO - TEST-PASS | browser/components/extensions/test/browser/browser_ext_webNavigation_urlbar_transitions.js | Got the expected from_address_bar transitionQualifier -
[task 2021-03-28T22:28:12.989Z] 22:28:12 INFO - TEST-PASS | browser/components/extensions/test/browser/browser_ext_webNavigation_urlbar_transitions.js | Got the expected transitionType - Expected: typed, Actual: typed -
[task 2021-03-28T22:28:12.991Z] 22:28:12 INFO - TEST-PASS | browser/components/extensions/test/browser/browser_ext_webNavigation_urlbar_transitions.js | webNavigation.from_address_bar.typed -
[task 2021-03-28T22:28:12.992Z] 22:28:12 INFO - TEST-PASS | browser/components/extensions/test/browser/browser_ext_webNavigation_urlbar_transitions.js | test result correct -
[task 2021-03-28T22:28:12.994Z] 22:28:12 INFO - GECKO(1530) | [Child 1616, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:40
[task 2021-03-28T22:28:12.995Z] 22:28:12 INFO - Leaving test bound test_webnavigation_urlbar_typed_transitions

Comment 34

[Intermittent Failures Robot]

63 failures in 3967 pushes (0.016 failures/push) were associated with this bug in the last 7 days.

This is the #18 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 31
• mozilla-central: 32

Platform and build breakdown:

• windows10-64: 1
  • debug: 1
• linux1804-64: 36
  • debug: 36
• windows7-32: 1
  • debug: 1
• windows10-64-shippable-qr: 10
  • opt: 10
• windows10-64-shippable: 9
  • opt: 9
• linux1804-64-shippable: 6
  • opt: 6

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1594921&startday=2021-03-22&endday=2021-03-28&tree=all

Comment 35

[Kris Maglione [:kmag]]

Attachment: Bug 1594921: Don't send top-level location change events early in BrowserChild lifetime. r=nika

Doing so results in unexpected load events for the initial about:blank
document, which the frame script implementation did not see.

Comment 36

[Intermittent Failures Robot]

27 failures in 647 pushes (0.042 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 15
• try: 1
• mozilla-central: 11

Platform and build breakdown:

• linux1804-64: 19
  • debug: 19
• windows10-64-shippable: 6
  • opt: 6
• windows10-64-shippable-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1594921&startday=2021-03-29&endday=2021-03-29&tree=all

Comment 37

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/a391978b8666
Don't send top-level location change events early in BrowserChild lifetime. r=nika

Comment 38

[Intermittent Failures Robot]

18 failures in 698 pushes (0.026 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 7
• mozilla-central: 11

Platform and build breakdown:

• linux1804-64: 10
  • debug: 10
• windows10-64-shippable-qr: 3
  • opt: 3
• windows10-64-shippable: 3
  • opt: 3
• linux1804-64-shippable: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1594921&startday=2021-03-30&endday=2021-03-30&tree=all

Comment 39

[Sandor Molnar[:smolnar]]

https://hg.mozilla.org/mozilla-central/rev/a391978b8666

Comment 40

[Intermittent Failures Robot]

45 failures in 3125 pushes (0.014 failures/push) were associated with this bug in the last 7 days.

This is the #33 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 22
• try: 1
• mozilla-central: 22

Platform and build breakdown:

• linux1804-64: 29
  • debug: 29
• windows10-64-shippable: 9
  • opt: 9
• windows10-64-shippable-qr: 5
  • opt: 5
• linux1804-64-shippable: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1594921&startday=2021-03-29&endday=2021-04-04&tree=all

Comment 41

[Neha Kochar [:neha]]

Kris, this still seems to happen - 45 failures in last 7 days. Please look into this.

Comment 42

[Tomislav Jovanovic :zombie]

I checked the treeherder links, and I don't see any failures after March 31.
https://treeherder.mozilla.org/intermittent-failures/bugdetails?startday=2021-03-14&endday=2021-04-13&tree=trunk&bug=1594921

Neha, is there another place to check?

Comment 43

[Neha Kochar [:neha]]

Sorry, I looked at the older reports. This is fixed, I'll close.