1435048 - Intermittent devtools/client/netmonitor/test/browser_net_status-bar.js | There must be [DOMContentLoaded/load] label -

Reporter

Description

•

6 years ago

treeherder

Filed by: ncsoregi [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=159892900&repo=autoland

https://queue.taskcluster.net/v1/task/EoRQkXJQRwqxeIl7jC_ekw/runs/0/artifacts/public/logs/live_backing.log

17:21:47    ERROR -  200 INFO TEST-UNEXPECTED-FAIL | devtools/client/netmonitor/test/browser_net_status-bar.js | There must be DOMContentLoaded label -
2923
17:21:47     INFO -  Stack trace:
2924
17:21:47     INFO -  chrome://mochitests/content/browser/devtools/client/netmonitor/test/browser_net_status-bar.js:null:35
2925
17:21:47     INFO -  Not taking screenshot here: see the one that was previously logged
2926
17:21:47    ERROR -  201 INFO TEST-UNEXPECTED-FAIL | devtools/client/netmonitor/test/browser_net_status-bar.js | There must be load label -
2927
17:21:47     INFO -  Stack trace:
2928
17:21:47     INFO -  chrome://mochitests/content/browser/devtools/client/netmonitor/test/browser_net_status-bar.js:null:36
2929
17:21:47     INFO -  202 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_status-bar.js | There must be request count label text -
2930
17:21:47     INFO -  203 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_status-bar.js | There must be size label text -
2931
17:21:47     INFO -  Not taking screenshot here: see the one that was previously logged
2932
17:21:47    ERROR -  204 INFO TEST-UNEXPECTED-FAIL | devtools/client/netmonitor/test/browser_net_status-bar.js | Uncaught exception - at chrome://mochitests/content/browser/devtools/client/netmonitor/test/browser_net_status-bar.js:41 - TypeError: onContentLoad is null
2933
17:21:47     INFO -  Stack trace:

Natalia Csoregi [:nataliaCs]

Updated

•

6 years ago

Summary: Intermittent devtools/client/netmonitor/test/browser_net_status-bar.js | There must be DOMContentLoaded label - → Intermittent devtools/client/netmonitor/test/browser_net_status-bar.js | There must be [DOMContentLoaded/load] label -

Comment hidden (Intermittent Failures Robot)

19 failures in 735 pushes (0.026 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-central: 7
* autoland: 7
* mozilla-inbound: 4
* try: 1

Platform breakdown:
* windows10-64: 14
* windows7-32: 3
* windows7-32-nightly: 1
* windows10-64-nightly: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1435048&startday=2018-01-29&endday=2018-02-04&tree=all

Cristina Coroiu [:ccoroiu]

Comment 2

•

6 years ago

There have been 32 failures in the last 7 days.
The most failures are occurring on the windows10-64, but there are also some occurrences on Windows 7, one on windows10-64-nightly and one on Linux.
The most affected build type is opt, but here are also failures occurring on pgo.

Recent failure log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=160811803&lineNumber=8507

And the relevant part of the log:
11:56:20     INFO -  581 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_status-bar.js | Request to reconfigure the tab was recorded. -
11:56:20     INFO -  582 INFO Clearing requests in the console client.
11:56:20     INFO -  583 INFO Clearing requests in the UI.
11:56:20     INFO -  584 INFO Starting test...
11:56:20     INFO -  585 INFO Console message: [JavaScript Warning: "Error in parsing value for ‘transform’ after substituting variables. Generated value was ‘ scaleX(Infinity)’.  Falling back to ‘initial’." {file: "chrome://devtools/content/netmonitor/src/assets/styles/RequestList.css" line: 606 column: 12267 source: " scaleX(Infinity)"}]
11:56:20     INFO -  586 INFO > Network event progress: NetworkEvent: 1/1, PayloadReady: 0/1, got NetMonitor:NetworkEvent for server1.conn88.child1/netEvent28
11:56:20     INFO -  587 INFO > Network event progress: NetworkEvent: 1/1, PayloadReady: 1/1, got NetMonitor:PayloadReady for server1.conn88.child1/netEvent28
11:56:20     INFO -  588 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_status-bar.js | There must be request count label -
11:56:20     INFO -  589 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_status-bar.js | There must be size label -
11:56:20     INFO -  590 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_status-bar.js | There must be DOMContentLoaded label -
11:56:20     INFO -  Buffered messages finished
11:56:20    ERROR -  591 INFO TEST-UNEXPECTED-FAIL | devtools/client/netmonitor/test/browser_net_status-bar.js | There must be load label -
11:56:20     INFO -  Stack trace:
11:56:20     INFO -  chrome://mochitests/content/browser/devtools/client/netmonitor/test/browser_net_status-bar.js:null:36
11:56:20     INFO -  592 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_status-bar.js | There must be request count label text -
11:56:20     INFO -  593 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_status-bar.js | There must be size label text -
11:56:20     INFO -  594 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_status-bar.js | There must be DOMContentLoaded label text -
11:56:20     INFO -  Not taking screenshot here: see the one that was previously logged
11:56:20    ERROR -  595 INFO TEST-UNEXPECTED-FAIL | devtools/client/netmonitor/test/browser_net_status-bar.js | Uncaught exception - at chrome://mochitests/content/browser/devtools/client/netmonitor/test/browser_net_status-bar.js:42 - TypeError: onLoad is null
11:56:20     INFO -  Stack trace:
11:56:20     INFO -      @chrome://mochitests/content/browser/devtools/client/netmonitor/test/browser_net_status-bar.js:42:3
11:56:20     INFO -      Async*Tester_execTest/<@chrome://mochikit/content/browser-test.js:1067:21
11:56:20     INFO -      Tester_execTest@chrome://mochikit/content/browser-test.js:1058:9
11:56:20     INFO -      Tester.prototype.nextTest</<@chrome://mochikit/content/browser-test.js:958:9
11:56:20     INFO -      SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:795:59
11:56:20     INFO -  596 INFO Leaving test bound
11:56:20     INFO -  597 INFO Console message: [JavaScript Warning: "Error in parsing value for ‘transform’ after substituting variables. Generated value was ‘ scaleX(Infinity)’.  Falling back to ‘initial’." {file: "chrome://devtools/content/netmonitor/src/assets/styles/RequestList.css" line: 606 column: 12267 source: " scaleX(Infinity)"}]
11:56:20     INFO -  598 INFO Removing tab.
11:56:20     INFO -  599 INFO Waiting for event: 'TabClose' on [object XULElement].
11:56:20     INFO -  600 INFO Got event: 'TabClose' on [object XULElement].
11:56:20     INFO -  601 INFO Tab removed and finished closing
11:56:20     INFO -  602 INFO finish() was called, cleaning up...

:pbro could you please take a look?

Flags: needinfo?(pbrosset)

Whiteboard: [stockwell needswork]

Patrick Brosset <:pbro>

Comment 3

•

6 years ago

Forwarding this to Honza for closer inspection.

Flags: needinfo?(pbrosset) → needinfo?(odvarko)

Jan Honza Odvarko [:Honza] (always need-info? me)

Assignee

Updated

•

6 years ago

Component: Developer Tools → Developer Tools: Netmonitor

Flags: needinfo?(odvarko)

Comment hidden (mozreview-request)

Review commit: https://reviewboard.mozilla.org/r/218690/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/218690/

Alexandre Poirot [:ochameau]

Comment 5

•

6 years ago

mozreview-review

Comment on attachment 8949300 [details]
Bug 1435048 - Wait for async UI update;

https://reviewboard.mozilla.org/r/218690/#review224482

Thanks for looking into this.
Did you pushed to try to confirm this fixes the intermittent?

::: devtools/client/netmonitor/test/browser_net_status-bar.js:22
(Diff revision 1)
> -    return wait;
> -  }
>  
> -  await reloadAndWait();
> +  let requestsDone = waitForAllRequestsFinished(monitor);
> +  let markersDone = waitForTimelineMarkers(monitor);
> +  await Promise.all([requestsDone, markersDone]);

Looks good, but I would suggest calling
  tab.linkedBrowser.reload();
between the two `waitFor*` methods call and the `await Promise.all()`.
By starting the listening of events *after* dispatching the action that is meant to dispatch them, we are introducing possible races where the events is fired immediately during the call to `reload()`.

Attachment #8949300 - Flags: review?(poirot.alex) → review+

Comment hidden (mozreview-request)

Comment on attachment 8949300 [details]
Bug 1435048 - Wait for async UI update;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/218690/diff/1-2/

Jan Honza Odvarko [:Honza] (always need-info? me)

Assignee

Comment 7

•

6 years ago

(In reply to Alexandre Poirot [:ochameau] from comment #5)
> Looks good, but I would suggest calling
>   tab.linkedBrowser.reload();
> between the two `waitFor*` methods call and the `await Promise.all()`.
Good point, done.

Thanks!
Honza

Jan Honza Odvarko [:Honza] (always need-info? me)

Assignee

Updated

•

6 years ago

Assignee: nobody → odvarko

Status: NEW → ASSIGNED

Pulsebot

Comment 8

•

6 years ago

Pushed by jodvarko@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/9d8d4e93d420
Wait for timeline markers; r=ochameau

Cristian Brindusan [:cbrindusan]

Comment 9

•

6 years ago

bugherder

https://hg.mozilla.org/mozilla-central/rev/9d8d4e93d420

Status: ASSIGNED → RESOLVED

Closed: 6 years ago

status-firefox60: --- → fixed

Resolution: --- → FIXED

Target Milestone: --- → Firefox 60

Narcis Beleuzu [:NarcisB]

Comment 10

•

6 years ago

Fail reappeared on inbound:

Push: https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=c82860cdbeafc9b267be7adb206cbaae85647845 
Log: https://treeherder.mozilla.org/logviewer.html#?job_id=161119576&repo=mozilla-inbound&lineNumber=8438

17:09:12    ERROR -  604 INFO TEST-UNEXPECTED-FAIL | devtools/client/netmonitor/test/browser_net_status-bar.js | There must be load label -
17:09:12     INFO -  Stack trace:
17:09:12     INFO -  chrome://mochitests/content/browser/devtools/client/netmonitor/test/browser_net_status-bar.js:null:36
17:09:12     INFO -  605 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_status-bar.js | There must be request count label text -
17:09:12     INFO -  606 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_status-bar.js | There must be size label text -
17:09:12     INFO -  607 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_status-bar.js | There must be DOMContentLoaded label text -
17:09:12     INFO -  Not taking screenshot here: see the one that was previously logged
17:09:12    ERROR -  608 INFO TEST-UNEXPECTED-FAIL | devtools/client/netmonitor/test/browser_net_status-bar.js | Uncaught exception - at chrome://mochitests/content/browser/devtools/client/netmonitor/test/browser_net_status-bar.js:42 - TypeError: onLoad is null
17:09:12     INFO -  Stack trace:
17:09:12     INFO -      @chrome://mochitests/content/browser/devtools/client/netmonitor/test/browser_net_status-bar.js:42:3
17:09:12     INFO -      Async*Tester_execTest/<@chrome://mochikit/content/browser-test.js:1067:21
17:09:12     INFO -      Tester_execTest@chrome://mochikit/content/browser-test.js:1058:9
17:09:12     INFO -      Tester.prototype.nextTest</<@chrome://mochikit/content/browser-test.js:958:9
17:09:12     INFO -      SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:795:59

Status: RESOLVED → REOPENED

status-firefox60: fixed → ---

Flags: needinfo?(odvarko)

Resolution: FIXED → ---

Target Milestone: Firefox 60 → ---

Comment hidden (mozreview-request)

Comment on attachment 8949300 [details]
Bug 1435048 - Wait for async UI update;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/218690/diff/2-3/

Jan Honza Odvarko [:Honza] (always need-info? me)

Assignee

Updated

•

6 years ago

Flags: needinfo?(odvarko)

Attachment #8949300 - Flags: review+ → review?(poirot.alex)

Jan Honza Odvarko [:Honza] (always need-info? me)

Assignee

Comment 12

•

6 years ago

Patch updated, yet  waiting for async UI update.

Try push:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=f9aa0defe886aeeb9811343f5abf12492a60555a

Honza

Comment hidden (Intermittent Failures Robot)

24 failures in 702 pushes (0.034 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 9
* mozilla-inbound: 7
* mozilla-central: 5
* try: 3

Platform breakdown:
* windows10-64: 19
* windows7-32: 1
* windows10-64-nightly: 1
* linux64-stylo-disabled: 1
* linux64: 1
* linux32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1435048&startday=2018-02-05&endday=2018-02-11&tree=all

Alexandre Poirot [:ochameau]

Comment 14

•

6 years ago

mozreview-review

Comment on attachment 8949300 [details]
Bug 1435048 - Wait for async UI update;

https://reviewboard.mozilla.org/r/218690/#review225224

Could it be because the timeline event are sent before redux action?
https://searchfox.org/mozilla-central/source/devtools/client/netmonitor/src/connector/firefox-connector.js#203,215

I requested more runs on your try:
  https://treeherder.mozilla.org/#/jobs?repo=try&revision=f9aa0defe886aeeb9811343f5abf12492a60555a
Please wait for the results, to ensure you really fixed this intermittent.
(To spawn more you, you can select on job, like "dt3" and hit "r" key. It will request one more run each time you press the key.)

::: devtools/client/netmonitor/test/browser_net_status-bar.js:47
(Diff revision 3)
> +
> +  await waitUntil(() => onContentLoad.textContent);
> +  ok(true, "There must be DOMContentLoaded label text");
> +
> +  await waitUntil(() => onLoad.textContent);
> +  ok(true, "There must be load label text");

We could use waitUntil() for the last field to be updated first: onLoad, and use regular asserts for all the others, which should already be displayed.

Attachment #8949300 - Flags: review?(poirot.alex) → review+

Jan Honza Odvarko [:Honza] (always need-info? me)

Assignee

Comment 15

•

6 years ago

Try looks good, landing. Let's see if this helps.
Thanks.

Honza

Pulsebot

Comment 16

•

6 years ago

Pushed by jodvarko@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/96c6eef5f48b
Wait for async UI update; r=ochameau

Andreea Pavel [:apavel]

Comment 17

•

6 years ago

bugherder

https://hg.mozilla.org/mozilla-central/rev/96c6eef5f48b

Status: REOPENED → RESOLVED

Closed: 6 years ago → 6 years ago

status-firefox60: --- → fixed

Resolution: --- → FIXED

Target Milestone: --- → Firefox 60

Joel Maher ( :jmaher ) (UTC -8)

Updated

•

6 years ago

Whiteboard: [stockwell needswork] → [stockwell fixed:timing]

Comment hidden (Intermittent Failures Robot)

1 failures in 792 pushes (0.001 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 1

Platform breakdown:
* osx-10-10: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1435048&startday=2018-04-09&endday=2018-04-15&tree=trunk

BMO Automation

Updated

•

6 years ago

Product: Firefox → DevTools