1618385 - Intermittent Linux fission devtools/client/netmonitor/test/browser_net_fission_switch_target.js | Test timed out -

Status: RESOLVED FIXED

(DevTools :: Netmonitor, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2020-02-26T22:12:27.052Z] 22:12:27 INFO - TEST-PASS | devtools/client/netmonitor/test/browser_net_fission_switch_target.js | Request to reconfigure the tab was recorded. -
[task 2020-02-26T22:12:27.052Z] 22:12:27 INFO - Clearing requests in the console client.
[task 2020-02-26T22:12:27.053Z] 22:12:27 INFO - Clearing requests in the UI.
[task 2020-02-26T22:12:27.053Z] 22:12:27 INFO - Create a request in the target page for the URL: http://example.com/browser/devtools/client/netmonitor/test/sjs_search-test-server.sjs?value=test
[task 2020-02-26T22:12:27.054Z] 22:12:27 INFO - Wait for the request to be received by the netmonitor UI
[task 2020-02-26T22:12:27.055Z] 22:12:27 INFO - > Network event progress: NetworkEvent: 1/1, PayloadReady: 0/1, got NetMonitor:NetworkEvent for server0.conn57.netEvent23
[task 2020-02-26T22:12:27.055Z] 22:12:27 INFO - > Network event progress: NetworkEvent: 1/1, PayloadReady: 1/1, got NetMonitor:PayloadReady for server0.conn57.netEvent23
[task 2020-02-26T22:12:27.056Z] 22:12:27 INFO - Navigate to a page that runs in another content process (if fission)
[task 2020-02-26T22:12:27.056Z] 22:12:27 INFO - Load document "http://example.net/document-builder.sjs?html=testnet"
[task 2020-02-26T22:12:27.057Z] 22:12:27 INFO - Buffered messages logged at 22:11:01
[task 2020-02-26T22:12:27.059Z] 22:12:27 INFO - Waiting for page to be loaded…
[task 2020-02-26T22:12:27.059Z] 22:12:27 INFO - Buffered messages logged at 22:11:02
[task 2020-02-26T22:12:27.060Z] 22:12:27 INFO - → page loaded
[task 2020-02-26T22:12:27.060Z] 22:12:27 INFO - Waiting for netmonitor to be reloaded…
[task 2020-02-26T22:12:27.061Z] 22:12:27 INFO - Waiting for netmonitor updates after page reload
[task 2020-02-26T22:12:27.061Z] 22:12:27 INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "http://example.net/document-builder.sjs?html=testnet" line: 0}]
[task 2020-02-26T22:12:27.062Z] 22:12:27 INFO - Buffered messages finished
[task 2020-02-26T22:12:27.064Z] 22:12:27 INFO - TEST-UNEXPECTED-FAIL | devtools/client/netmonitor/test/browser_net_fission_switch_target.js | Test timed out -
[task 2020-02-26T22:12:27.952Z] 22:12:27 INFO - Removing tab.
[task 2020-02-26T22:12:27.952Z] 22:12:27 INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2020-02-26T22:12:27.988Z] 22:12:27 INFO - Got event: 'TabClose' on [object XULElement].
[task 2020-02-26T22:12:28.005Z] 22:12:28 INFO - GECKO(1225) | [Parent 1225, Main Thread] WARNING: '!inner', file /builds/worker/workspace/build/src/dom/ipc/JSWindowActorService.cpp, line 182
[task 2020-02-26T22:12:28.013Z] 22:12:28 INFO - Tab removed and finished closing
[task 2020-02-26T22:12:28.076Z] 22:12:28 INFO - GECKO(1225) | [Parent 1225: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f606c3e4800 == 6 [pid = 1225] [id = {c542e42c-83f5-4365-a43b-29a2692dc843}] [url = chrome://devtools/content/netmonitor/index.html]
[task 2020-02-26T22:12:28.083Z] 22:12:28 INFO - TEST-PASS | devtools/client/netmonitor/test/browser_net_fission_switch_target.js | The main process DevToolsServer has no pending connection when the test ends -
[task 2020-02-26T22:12:28.083Z] 22:12:28 INFO - finish() was called, cleaning up...
[task 2020-02-26T22:12:28.139Z] 22:12:28 INFO - GECKO(1225) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-02-26T22:12:28.141Z] 22:12:28 INFO - GECKO(1225) | MEMORY STAT | vsize 3627MB | residentFast 449MB | heapAllocated 140MB
[task 2020-02-26T22:12:28.142Z] 22:12:28 INFO - TEST-OK | devtools/client/netmonitor/test/browser_net_fission_switch_target.js | took 91381ms
[task 2020-02-26T22:12:28.179Z] 22:12:28 INFO - GECKO(1225) | [Child 1439: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f1ca2d1c000 == 1 [pid = 1439] [id = {b1040d5e-0a3d-40d2-9738-014d5ee38c39}]
[task 2020-02-26T22:12:28.180Z] 22:12:28 INFO - GECKO(1225) | [Child 1439: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7f1cbe093350) [pid = 1439] [serial = 67] [outer = (nil)]
[task 2020-02-26T22:12:28.181Z] 22:12:28 INFO - GECKO(1225) | [Child 1439, Main Thread] WARNING: NS_ENSURE_TRUE(mPresShell) failed: file /builds/worker/workspace/build/src/layout/base/nsPresContext.cpp, line 848
[task 2020-02-26T22:12:28.182Z] 22:12:28 INFO - GECKO(1225) | [Child 1439: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7f1ca3020800) [pid = 1439] [serial = 68] [outer = 0x7f1cbe093350]
[task 2020-02-26T22:12:28.302Z] 22:12:28 INFO - checking window state

Comment 1

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Please take a look, it fails frequently on Linux with fission enabled.

Comment 2

[Intermittent Failures Robot]

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

Repository breakdown:

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

Platform breakdown:

• linux1804-64: 8

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

Comment 3

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 21
• try: 3

Platform breakdown:

• linux1804-64: 24

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

Comment 4

[Razvan Maries]

There are 26 total failures in the last 7 days: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2020-03-04&endday=2020-03-11&tree=trunk&bug=1618385

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=292612615&repo=mozilla-central&lineNumber=5816

Comment 5

[Intermittent Failures Robot]

35 failures in 5336 pushes (0.007 failures/push) were associated with this bug in the last 7 days.

** 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: 18
• try: 16
• autoland: 1

Platform breakdown:

• linux1804-64: 32
• macosx1014-64: 1
• linux1804-64-qr: 2

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

Comment 6

[Intermittent Failures Robot]

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

** 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: 12
• try: 19

Platform breakdown:

• linux1804-64: 27
• linux1804-64-asan: 1
• linux1804-64-shippable: 3

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

Comment 7

[Intermittent Failures Robot]

23 failures in 4773 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 16
• try: 7

Platform breakdown:

• linux1804-64: 23

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

Comment 8

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 15
• try: 5

Platform breakdown:

• linux1804-64: 20

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

Comment 9

[Bogdan Tara[:bogdan_tara | bogdant]]

In the last 7 days there have been 20 occurrences on linux1804-64 debug.

Recent failure: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=297257115&repo=mozilla-central&lineNumber=6344

Comment 10

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

Daisuke, could this be related to the recent work on bug 1626494?

Honza

Comment 11

[Daisuke Akatsuka (:daisuke)]

Hi Honza! Thank you for letting me know.

I don't think this is related to bug 1626494.
But as I added this test, let me take a look at this.

Comment 12

[Daisuke Akatsuka (:daisuke)]

I investigated this issue a bit.
And yes, as you said, it seems this is related to bug 1626494. (I'm sorry!)

The reason why this test is failed is because the navigate event on browsing context is fired before onTargetNavitated on firefox-connector is called, we couldn't trigger the navigate event from this listener.

In bug 1625942, as we plan to introduce a new mechanism to trigger document events to fix such the timing issue, let me fix this after bug 1625942.

Comment 13

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

I see, great, thanks for working on this Daisuke!

Honza

Comment 14

[Intermittent Failures Robot]

26 failures in 4823 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 18
• try: 7
• autoland: 1

Platform breakdown:

• linux1804-64: 26

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

Comment 15

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 17
• try: 2

Platform breakdown:

• linux1804-64: 19

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

Comment 16

[Daisuke Akatsuka (:daisuke)]

Attachment: Bug 1618385: Use 'dom-complete' event instead to not miss 'navigate' event.

Comment 17

[Alexandre Poirot [:ochameau] [PTO back August 21]]

I requested a few more runs on your try push and it looks like you fixed it for good :)

Comment 18

[Daisuke Akatsuka (:daisuke)]

Attachment: Bug 1618385: Use document events instead of navigate event.

Depends on D71007

Comment 19

[Intermittent Failures Robot]

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

** 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:

• try: 24
• mozilla-central: 9

Platform breakdown:

• linux1804-64: 31
• macosx1014-64: 1
• windows10-64: 1

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

Comment 20

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/bfb47bf5fcbf
Use 'dom-complete' event instead to not miss 'navigate' event. r=ochameau,Honza

Comment 21

[Cosmin Sabou [:CosminS]]

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

Comment 22

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 5
• try: 2

Platform breakdown:

• linux1804-64: 7

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