1777457 - Intermittent devtools/client/netmonitor/test/browser_net_fonts.js | Test timed out -

Status: RESOLVED FIXED

(DevTools :: Netmonitor, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2022-06-30T09:42:18.747Z] 09:42:18     INFO - TEST-START | devtools/client/netmonitor/test/browser_net_fonts.js
[task 2022-06-30T09:42:18.777Z] 09:42:18     INFO - GECKO(3021) | [Parent 3021: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 22 (7efe286db520) [pid = 3021] [serial = 355] [outer = 0] [url = chrome://devtools/content/inspector/index.xhtml]
[task 2022-06-30T09:42:18.777Z] 09:42:18     INFO - GECKO(3021) | [Parent 3021: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 21 (7efe286db6f0) [pid = 3021] [serial = 357] [outer = 0] [url = chrome://devtools/content/inspector/markup/markup.xhtml]
[task 2022-06-30T09:42:18.780Z] 09:42:18     INFO - GECKO(3021) | [Parent 3021: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7efdfc1ad400 == 9 [pid = 3021] [id = 138] [url = about:devtools-toolbox]
[task 2022-06-30T09:42:18.781Z] 09:42:18     INFO - GECKO(3021) | [Parent 3021: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 20 (7efe17404820) [pid = 3021] [serial = 347] [outer = 0] [url = chrome://devtools/content/netmonitor/index.html]
[task 2022-06-30T09:42:18.782Z] 09:42:18     INFO - GECKO(3021) | [Parent 3021: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 19 (7efe17404480) [pid = 3021] [serial = 344] [outer = 0] [url = about:devtools-toolbox]
[task 2022-06-30T09:42:18.860Z] 09:42:18     INFO - GECKO(3021) | [Child 5617: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (7f20a8f91d90) [pid = 5617] [serial = 1] [outer = 0] [url = https://example.net/document-builder.sjs?html=testnet]
[task 2022-06-30T09:42:18.864Z] 09:42:18     INFO - GECKO(3021) | [Child 5617: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (7f2092f7c800) [pid = 5617] [serial = 2] [outer = 0] [url = about:blank]
[task 2022-06-30T09:42:18.866Z] 09:42:18     INFO - GECKO(3021) | [Child 5617: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (7f2092f80000) [pid = 5617] [serial = 3] [outer = 0] [url = https://example.net/document-builder.sjs?html=testnet]
[task 2022-06-30T09:42:18.868Z] 09:42:18     INFO - GECKO(3021) | [Child 5617, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3359
<...>
[task 2022-06-30T09:43:49.056Z] 09:43:49     INFO - → panel reloaded
[task 2022-06-30T09:43:49.058Z] 09:43:49     INFO - Wait for Responsive UI to reload
[task 2022-06-30T09:43:49.059Z] 09:43:49     INFO - > Network event progress: NetworkEvent: 4/3, PayloadReady: 5/3, EventTimings: 2/4, got NetMonitor:NetworkEventUpdated:EventTimings for server0.conn0.netEvent83
[task 2022-06-30T09:43:49.061Z] 09:43:49     INFO - > Network event progress: NetworkEvent: 4/3, PayloadReady: 5/3, EventTimings: 3/4, got NetMonitor:NetworkEventUpdated:EventTimings for server0.conn0.netEvent94
[task 2022-06-30T09:43:49.062Z] 09:43:49     INFO - Buffered messages finished
[task 2022-06-30T09:43:49.063Z] 09:43:49     INFO - TEST-UNEXPECTED-FAIL | devtools/client/netmonitor/test/browser_net_fonts.js | Test timed out - 
[task 2022-06-30T09:43:49.704Z] 09:43:49     INFO - Removing tab.
[task 2022-06-30T09:43:49.707Z] 09:43:49     INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2022-06-30T09:43:49.749Z] 09:43:49     INFO - Got event: 'TabClose' on [object XULElement].
[task 2022-06-30T09:43:49.774Z] 09:43:49     INFO - GECKO(3021) | [Parent 3021, Main Thread] WARNING: '!inner', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorProtocol.cpp:162
[task 2022-06-30T09:43:49.776Z] 09:43:49     INFO - GECKO(3021) | [Parent 3021, Main Thread] WARNING: '!inner', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorProtocol.cpp:162
[task 2022-06-30T09:43:49.781Z] 09:43:49     INFO - Tab removed and finished closing
[task 2022-06-30T09:43:49.798Z] 09:43:49     INFO - GECKO(3021) | JavaScript error: , line 0: NotFoundError: No such JSWindowActor 'DevToolsFrame'
[task 2022-06-30T09:43:49.820Z] 09:43:49     INFO - Console message: [JavaScript Error: "NotFoundError: No such JSWindowActor 'DevToolsFrame'"]
[task 2022-06-30T09:43:49.821Z] 09:43:49     INFO - TEST-PASS | devtools/client/netmonitor/test/browser_net_fonts.js | The main process DevToolsServer has no pending connection when the test ends - 
[task 2022-06-30T09:43:49.822Z] 09:43:49     INFO - finish() was called, cleaning up...
[task 2022-06-30T09:43:49.857Z] 09:43:49     INFO - GECKO(3021) | [Parent 3021, IPDL Background] WARNING: IPC Connection Error: [Parent][PBackgroundParent] RunMessage(msgname=PRemoteWorkerService::Msg___delete__) Channel closing: too late to send/recv, messages will be lost: file /builds/worker/checkouts/gecko/ipc/glue/MessageChannel.cpp:1876
[task 2022-06-30T09:43:49.862Z] 09:43:49     INFO - GECKO(3021) | [Parent 3021, Compositor] WARNING: IPC Connection Error: [Parent][PImageBridgeParent] RunMessage(msgname=PImageBridge::Msg_WillClose) Channel closing: too late to send/recv, messages will be lost: file /builds/worker/checkouts/gecko/ipc/glue/MessageChannel.cpp:1876
[task 2022-06-30T09:43:49.869Z] 09:43:49     INFO - GECKO(3021) | [Parent 3021: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7efe10d7c800 == 6 [pid = 3021] [id = 147] [url = chrome://devtools/content/netmonitor/index.html]
[task 2022-06-30T09:43:49.876Z] 09:43:49     INFO - GECKO(3021) | MEMORY STAT | vsize 3806MB | residentFast 644MB | heapAllocated 297MB
[task 2022-06-30T09:43:49.879Z] 09:43:49     INFO - TEST-OK | devtools/client/netmonitor/test/browser_net_fonts.js | took 91133ms
[task 2022-06-30T09:43:49.920Z] 09:43:49     INFO - GECKO(3021) | [Child 3124: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7efeae68c400 == 1 [pid = 3124] [id = 33]
[task 2022-06-30T09:43:49.921Z] 09:43:49     INFO - GECKO(3021) | [Child 3124: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (7efec9791820) [pid = 3124] [serial = 69] [outer = 0]
[task 2022-06-30T09:43:49.922Z] 09:43:49     INFO - GECKO(3021) | [Child 3124: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (7efeae68cc00) [pid = 3124] [serial = 70] [outer = 7efec9791820]
[task 2022-06-30T09:43:49.986Z] 09:43:49     INFO - GECKO(3021) | [Child 3190, Main Thread] WARNING: '!CanHandleWith(aPresContext)', file /builds/worker/checkouts/gecko/dom/events/IMEStateManager.cpp:498
[task 2022-06-30T09:43:50.013Z] 09:43:50     INFO - GECKO(3021) | [Child 5675: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7fb57864f000 == 0 [pid = 5675] [id = 0] [url = http://example.com/browser/devtools/client/netmonitor/test/html_fonts-test-page.html?name=fonts]
[task 2022-06-30T09:43:50.039Z] 09:43:50     INFO - checking window state
[task 2022-06-30T09:43:50.134Z] 09:43:50     INFO - GECKO(3021) | [Child 5675: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (7fb58e591d90) [pid = 5675] [serial = 1] [outer = 0] [url = http://example.com/browser/devtools/client/netmonitor/test/html_fonts-test-page.html?name=fonts]
[task 2022-06-30T09:43:50.148Z] 09:43:50     INFO - GECKO(3021) | [Child 5675: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (7fb5786bf800) [pid = 5675] [serial = 5] [outer = 0] [url = http://example.com/browser/devtools/client/netmonitor/test/html_fonts-test-page.html?name=fonts]
[task 2022-06-30T09:43:50.153Z] 09:43:50     INFO - GECKO(3021) | [Child 5675, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3359
[task 2022-06-30T09:43:50.160Z] 09:43:50     INFO - GECKO(3021) | [Child 5675, Main Thread] WARNING: NS_ENSURE_TRUE(InitStaticMembers()) failed: file /builds/worker/workspace/obj-build/dist/include/mozilla/Preferences.h:129
[task 2022-06-30T09:43:50.174Z] 09:43:50     INFO - GECKO(3021) | [Child 5675, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4595
[task 2022-06-30T09:43:50.193Z] 09:43:50     INFO - TEST-START | devtools/client/netmonitor/test/browser_net_footer-summary.js

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux1804-64-qr: 1
  • debug: 1

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

Comment 2

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux1804-64-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1777457&startday=2022-07-04&endday=2022-07-10&tree=all

Comment 3

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 2

Platform and build breakdown:

• linux1804-64-qr: 2
  • debug: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1777457&startday=2022-07-11&endday=2022-07-17&tree=all

Comment 4

[Intermittent Failures Robot]

16 failures in 669 pushes (0.024 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 13
• mozilla-central: 3

Platform and build breakdown:

• linux1804-64-qr: 14
  • opt: 6
  • debug: 8
• linux1804-64-shippable-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1777457&startday=2022-07-19&endday=2022-07-19&tree=all

Comment 5

[Intermittent Failures Robot]

20 failures in 664 pushes (0.03 failures/push) were associated with this bug yesterday.

Repository breakdown:

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

Platform and build breakdown:

• linux1804-64-qr: 16
  • opt: 6
  • debug: 10
• linux1804-64-shippable-qr: 4
  • opt: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1777457&startday=2022-07-21&endday=2022-07-21&tree=all

Comment 6

[Intermittent Failures Robot]

21 failures in 619 pushes (0.034 failures/push) were associated with this bug yesterday.

Repository breakdown:

• mozilla-central: 7
• autoland: 12
• try: 2

Platform and build breakdown:

• linux1804-64-shippable-qr: 6
  • opt: 6
• linux1804-64-qr: 14
  • debug: 9
  • opt: 5
• linux1804-64-asan-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1777457&startday=2022-07-22&endday=2022-07-22&tree=all

Comment 7

[Marian-Vasile Laza]

There have been 76 total failures in the last 7 days, recent failure log.
Affected platforms are:

• linux1804-64-asan-qr
• linux1804-64-qr
• linux1804-64-shippable-qr

Comment 8

[Intermittent Failures Robot]

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

This is the #8 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: 56
• mozilla-central: 21
• try: 7

Platform and build breakdown:

• linux1804-64-qr: 64
  • debug: 40
  • opt: 24
• linux1804-64-shippable-qr: 19
  • opt: 19
• linux1804-64-asan-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1777457&startday=2022-07-18&endday=2022-07-24&tree=all

Comment 9

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

Bomsy, can you please take a look, thank you.

Comment 10

[Julian Descottes [:jdescottes]]

Bomsy on PTO this week, I will take it.

Comment 11

[Julian Descottes [:jdescottes]]

Likely linked to Bug 1764349

Comment 12

[Intermittent Failures Robot]

17 failures in 525 pushes (0.032 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 11
• mozilla-central: 2
• try: 1
• mozilla-beta: 3

Platform and build breakdown:

• linux1804-64-qr: 11
  • debug: 7
  • opt: 4
• linux1804-64-shippable-qr: 4
  • opt: 4
• linux1804-64-devedition-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1777457&startday=2022-07-25&endday=2022-07-25&tree=all

Comment 13

[Julian Descottes [:jdescottes]]

Attachment: Bug 1777457 - [devtools] Update netmonitor test helpers when resources are cleared

There are potentially several sources for the recent netmonitor intermittent failures.
One of them is that we have several helpers to "wait" for requests, and they have a logic so that when they spot a request, they will wait for the request to be
completed.
However if a navigation occurs in the middle, the corresponding resource will be cleared and the updates will not be processed.
So here we emit a test-only event when the netmonitor attempts to clear resources, so that test helpers can update accordingly.

Comment 14

[Julian Descottes [:jdescottes]]

Attachment: Bug 1777457 - [devtools] Ignore actor destroyed errors in Firefox data provider

depends on D152726

This seems necessary to fix the har test intermittents

Comment 15

[Julian Descottes [:jdescottes]]

Netmonitor test suite:

• baseline: https://treeherder.mozilla.org/jobs?repo=try&revision=585ea73bff42df004b02ebbc0927c865e61777f8
• with patches: https://treeherder.mozilla.org/jobs?repo=try&revision=9199a358ed499a6aaa4ae65e72771276f16e6f26

Har test suite:

• baseline: https://treeherder.mozilla.org/jobs?repo=try&revision=1eae48f5f157319df4d2ae65889879b018fd28b2
• with patches: https://treeherder.mozilla.org/jobs?repo=try&revision=ef3768fa5e2bb939ea2c28a4adfc4bd86463cf5b

Results in progress let's see if this helps.

Comment 16

[Julian Descottes [:jdescottes]]

Seems to improve with the two main offenders: browser_net_fonts.js and browser_net_har_copy_all_as_har.js (Bug 1767792) but the suite is still very flaky ...

Comment 17

[Phabricator Automation]

Comment on attachment 9287012 [details]
Bug 1777457 - [devtools] Ignore actor destroyed errors in Firefox data provider

Revision D152727 was moved to bug 1767792. Setting attachment 9287012 [details] to obsolete.

Comment 18

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/08a0a6a25123
[devtools] Update netmonitor test helpers when resources are cleared r=nchevobbe

Comment 19

[Atila Butkovits]

https://hg.mozilla.org/mozilla-central/rev/08a0a6a25123

Comment 20

[Intermittent Failures Robot]

19 failures in 765 pushes (0.025 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 9
• mozilla-central: 5
• try: 4
• mozilla-beta: 1

Platform and build breakdown:

• linux1804-64-qr: 12
  • opt: 8
  • debug: 4
• linux1804-64-shippable-qr: 6
  • opt: 6
• linux1804-64-devedition-qr: 1
  • opt: 1

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

Comment 21

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

https://hg.mozilla.org/releases/mozilla-beta/rev/96885f75657d

Comment 22

[Intermittent Failures Robot]

36 failures in 3245 pushes (0.011 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: 20
• mozilla-central: 7
• try: 5
• mozilla-beta: 4

Platform and build breakdown:

• linux1804-64-qr: 23
  • debug: 11
  • opt: 12
• linux1804-64-shippable-qr: 10
  • opt: 10
• linux1804-64-devedition-qr: 3
  • opt: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1777457&startday=2022-07-25&endday=2022-07-31&tree=all