1630192 - Intermittent browser/components/customizableui/test/browser_947914_button_addons.js | Add-ons page was opened -

Status: RESOLVED FIXED

(Firefox :: Toolbars and Customization, defect, P3)

Description

[Treeherder Bug Filer]

Filed by: apavel [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=297693182&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/McpKHhJDQr2ffxkIlKMwyw/runs/0/artifacts/public/logs/live_backing.log

---

[task 2020-04-15T07:46:26.933Z] 07:46:26 INFO - TEST-START | browser/components/customizableui/test/browser_947914_button_addons.js
[task 2020-04-15T07:46:27.596Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 1EE9C000 == 30 [pid = 1272] [id = {793743de-0cc0-45cf-ac8f-85267610b8b8}] [url = about:blank]
[task 2020-04-15T07:46:27.596Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 70 (23D7F400) [pid = 1272] [serial = 85] [outer = 00000000] [url = about:blank]
[task 2020-04-15T07:46:27.597Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 69 (24DEA400) [pid = 1272] [serial = 69] [outer = 00000000] [url = about:blank]
[task 2020-04-15T07:46:27.597Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 68 (28FB5800) [pid = 1272] [serial = 73] [outer = 00000000] [url = about:blank]
[task 2020-04-15T07:46:27.597Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 67 (2D242000) [pid = 1272] [serial = 77] [outer = 00000000] [url = about:blank]
[task 2020-04-15T07:46:27.597Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 66 (23AC5000) [pid = 1272] [serial = 65] [outer = 00000000] [url = about:blank]
[task 2020-04-15T07:46:27.597Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 65 (2D29EC00) [pid = 1272] [serial = 81] [outer = 00000000] [url = about:blank]
[task 2020-04-15T07:46:27.612Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 23602C00 == 29 [pid = 1272] [id = {0ac1be1b-0bf1-4ed6-9016-d7c4eec30069}] [url = about:blank]
[task 2020-04-15T07:46:27.613Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 21F6A800 == 28 [pid = 1272] [id = {d20478f8-128a-4e97-b765-031143422d28}] [url = about:blank]
[task 2020-04-15T07:46:27.613Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 1FCB1400 == 27 [pid = 1272] [id = {2200f38e-a05a-4912-b82c-7d492618532b}] [url = about:blank]
[task 2020-04-15T07:46:27.613Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 255E6400 == 26 [pid = 1272] [id = {73075e36-eadd-4228-8d54-edadf28cbce0}] [url = about:blank]
[task 2020-04-15T07:46:27.614Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 2AD79C00 == 25 [pid = 1272] [id = {05a2dd6a-734a-4032-9e4b-1e8b0013fc7f}] [url = about:blank]
[task 2020-04-15T07:46:27.614Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 23D7E800 == 24 [pid = 1272] [id = {69393a26-c6bb-4858-8ab2-623682068a77}] [url = about:blank]
[task 2020-04-15T07:46:27.614Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 23A39400 == 23 [pid = 1272] [id = {77f78d06-03c3-4f11-9771-b3b0910028a4}] [url = about:blank]
[task 2020-04-15T07:46:27.789Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 64 (2879BF00) [pid = 1272] [serial = 94] [outer = 00000000] [url = about:blank]
[task 2020-04-15T07:46:27.792Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 63 (28F7A300) [pid = 1272] [serial = 96] [outer = 00000000] [url = about:mozilla]
[task 2020-04-15T07:46:27.792Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 62 (2874AC00) [pid = 1272] [serial = 92] [outer = 00000000] [url = about:blank]
[task 2020-04-15T07:46:27.793Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 61 (20C3B200) [pid = 1272] [serial = 90] [outer = 00000000] [url = about:blank]
[task 2020-04-15T07:46:27.793Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 60 (20C3A700) [pid = 1272] [serial = 88] [outer = 00000000] [url = about:blank]
[task 2020-04-15T07:46:27.793Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 59 (231EBC00) [pid = 1272] [serial = 86] [outer = 00000000] [url = about:blank]
[task 2020-04-15T07:46:27.793Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 58 (175B3400) [pid = 1272] [serial = 102] [outer = 00000000] [url = about:mozilla]
[task 2020-04-15T07:46:27.794Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 57 (28F7BA00) [pid = 1272] [serial = 99] [outer = 00000000] [url = about:robots]
[task 2020-04-15T07:46:27.874Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 1EE9D000 == 24 [pid = 1272] [id = {49f8da38-7083-4370-a682-11bb0855ec2c}]
[task 2020-04-15T07:46:27.874Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 58 (0085F000) [pid = 1272] [serial = 121] [outer = 00000000]
[task 2020-04-15T07:46:27.874Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 59 (1EEA3800) [pid = 1272] [serial = 122] [outer = 0085F000]
[task 2020-04-15T07:46:27.914Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 60 (20033000) [pid = 1272] [serial = 123] [outer = 0085F000]
[task 2020-04-15T07:46:27.969Z] 07:46:27 INFO - GECKO(5020) | [Parent 1272: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 61 (20035C00) [pid = 1272] [serial = 124] [outer = 0085F000]
[task 2020-04-15T07:46:28.004Z] 07:46:28 INFO - TEST-INFO | started process screenshot
[task 2020-04-15T07:46:28.069Z] 07:46:28 INFO - TEST-INFO | screenshot: exit 0
[task 2020-04-15T07:46:28.070Z] 07:46:28 INFO - Buffered messages logged at 07:46:26
[task 2020-04-15T07:46:28.070Z] 07:46:28 INFO - Entering test bound
[task 2020-04-15T07:46:28.070Z] 07:46:28 INFO - Check addons button existence and functionality
[task 2020-04-15T07:46:28.071Z] 07:46:28 INFO - Waiting for overflow button to show
[task 2020-04-15T07:46:28.071Z] 07:46:28 INFO - Buffered messages logged at 07:46:27
[task 2020-04-15T07:46:28.071Z] 07:46:28 INFO - Checking if element has non-0 size
[task 2020-04-15T07:46:28.072Z] 07:46:28 INFO - Menu panel was opened
[task 2020-04-15T07:46:28.072Z] 07:46:28 INFO - TEST-PASS | browser/components/customizableui/test/browser_947914_button_addons.js | Add-ons button exists in Panel Menu -
[task 2020-04-15T07:46:28.072Z] 07:46:28 INFO - Buffered messages finished
[task 2020-04-15T07:46:28.073Z] 07:46:28 INFO - TEST-UNEXPECTED-FAIL | browser/components/customizableui/test/browser_947914_button_addons.js | Add-ons page was opened -
[task 2020-04-15T07:46:28.073Z] 07:46:28 INFO - Stack trace:
[task 2020-04-15T07:46:28.073Z] 07:46:28 INFO - chrome://mochikit/content/browser-test.js:test_ok:1269
[task 2020-04-15T07:46:28.073Z] 07:46:28 INFO - chrome://mochitests/content/browser/browser/components/customizableui/test/browser_947914_button_addons.js:null:34
[task 2020-04-15T07:46:28.073Z] 07:46:28 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1039
[task 2020-04-15T07:46:28.074Z] 07:46:28 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1074
[task 2020-04-15T07:46:28.074Z] 07:46:28 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:904
[task 2020-04-15T07:46:28.074Z] 07:46:28 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:918
[task 2020-04-15T07:46:28.074Z] 07:46:28 INFO - Leaving test bound

Comment 1

[Andreea Pavel [:apavel]]

Retriggers: https://treeherder.mozilla.org/#/jobs?repo=autoland&tochange=a3a28be516f9babfe0e22906ed93f858183a8859&test_paths=browser%2Fcomponents%2Fcustomizableui%2Ftest&fromchange=bd5b28e704e6f823caadfe311f6c44d17b1b1618&selectedJob=297693182&group_state=expanded

Comment 2

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 12

Platform breakdown:

• windows7-32: 9
• windows10-64-qr: 1
• windows10-64: 1
• macosx1014-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1630192&startday=2020-04-13&endday=2020-04-19&tree=all

Comment 3

[Jean-Yves Avenard [:jya]]

I'm forwarding to :gijs as he's the most knowledgeable in this area of the code.

In bug 1607984 we modified how parents nsDocShell start loading the content and are now going through a DocumentChannel.

One of the consequence of this change are extra event loop hop between the time the load is initiated, when it starts and when it actually completes.

All this process has always been theoretically async, however the observable outcome between when a load was initiated and when it actually started was in effect synchronous.

So far, in almost all cases of test failures fixed in the process of doing bug 1607984 , were related to tests loading a new tab, a new document or iframe and immediately assuming they could read the DOM without waiting for the appropriate event to determine if things were ready.

It's likely that this test is failing in a similar fashion; unfortunately, I'm not familiar enough with this part of the code.

Is this something you could look into?

Thank you.

Comment 4

[Jean-Yves Avenard [:jya]]

i have a fix

Comment 5

[Jean-Yves Avenard [:jya]]

Attachment: Bug 1630192 - Wait for the page to load before attempting to retrieve element. r?Gijs,kmag

Comment 6

[Intermittent Failures Robot]

76 failures in 1125 pushes (0.068 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 76

Platform breakdown:

• windows10-64-qr: 9
• macosx1014-64: 40
• windows10-64: 23
• windows7-32: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1630192&startday=2020-04-24&endday=2020-04-24&tree=all

Comment 7

[Intermittent Failures Robot]

58 failures in 230 pushes (0.252 failures/push) were associated with this bug yesterday.

Repository breakdown:

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

Platform breakdown:

• macosx1014-64: 25
• windows10-64: 21
• windows10-64-qr: 6
• windows7-32: 5
• windows10-64-ccov: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1630192&startday=2020-04-25&endday=2020-04-25&tree=all

Comment 8

[Intermittent Failures Robot]

134 failures in 5582 pushes (0.024 failures/push) were associated with this bug in the last 7 days.

This is the #9 most frequent failure this week.

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

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

Repository breakdown:

• autoland: 123
• mozilla-central: 6
• try: 5

Platform breakdown:

• windows10-64-qr: 15
• macosx1014-64: 65
• windows10-64: 44
• windows7-32: 9
• windows10-64-ccov: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1630192&startday=2020-04-20&endday=2020-04-26&tree=all

Comment 9

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/b9e3987f0a6a
Wait for the page to load before attempting to retrieve element. r=Gijs

Comment 10

[Stefan Hindli [:stefan_hindli]]

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