1526153 - Intermittent browser_aboutdebugging_serviceworker_not_compatible.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort. -

Status: RESOLVED FIXED

(DevTools :: about:debugging, defect, P5)

Description

[Treeherder Bug Filer]

#[markdown(off)]
Filed by: ncsoregi [at] mozilla.com

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

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

[task 2019-02-08T03:56:14.274Z] 03:56:14 INFO - Tab added and finished loading
[task 2019-02-08T03:56:14.277Z] 03:56:14 INFO - wait for the initial about:debugging requests to be successful
[task 2019-02-08T03:56:14.280Z] 03:56:14 INFO - Buffered messages logged at 03:56:09
[task 2019-02-08T03:56:14.291Z] 03:56:14 INFO - Checking a USB runtime
[task 2019-02-08T03:56:14.305Z] 03:56:14 INFO - Wait until the sidebar item for Fancy Phone appears
[task 2019-02-08T03:56:14.309Z] 03:56:14 INFO - TEST-PASS | devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_not_compatible.js | Connect button is displayed for the runtime Fancy Phone -
[task 2019-02-08T03:56:14.323Z] 03:56:14 INFO - Click on the connect button and wait until it disappears
[task 2019-02-08T03:56:14.327Z] 03:56:14 INFO - Buffered messages logged at 03:56:10
[task 2019-02-08T03:56:14.330Z] 03:56:14 INFO - TEST-PASS | devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_not_compatible.js | Warning message is displayed -
[task 2019-02-08T03:56:14.339Z] 03:56:14 INFO - Remove all remote clients
[task 2019-02-08T03:56:14.358Z] 03:56:14 INFO - Removing tab.
[task 2019-02-08T03:56:14.370Z] 03:56:14 INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2019-02-08T03:56:14.373Z] 03:56:14 INFO - Got event: 'TabClose' on [object XULElement].
[task 2019-02-08T03:56:14.379Z] 03:56:14 INFO - Tab removed and finished closing
[task 2019-02-08T03:56:14.394Z] 03:56:14 INFO - Leaving test bound testRemoteRuntime
[task 2019-02-08T03:56:14.395Z] 03:56:14 INFO - Buffered messages finished
[task 2019-02-08T03:56:14.409Z] 03:56:14 INFO - TEST-UNEXPECTED-FAIL | devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_not_compatible.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort. -
[task 2019-02-08T03:56:14.411Z] 03:56:14 INFO - GECKO(1079) | MEMORY STAT | vsize 2263MB | residentFast 519MB | heapAllocated 179MB
[task 2019-02-08T03:56:14.422Z] 03:56:14 INFO - TEST-OK | devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_not_compatible.js | took 102977ms

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform breakdown:

• linux64: 1

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

Comment 2

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1

Platform breakdown:

• linux64: 1

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

Comment 3

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1
• try: 1

Platform breakdown:

• linux64: 2

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

Comment 4

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform breakdown:

• linux64: 1

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

Comment 5

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Comment 6

[Cristina Coroiu [:ccoroiu]]

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=264381997&repo=autoland&lineNumber=3839

[task 2019-08-31T04:46:42.651Z] 04:46:42 INFO - TEST-PASS | devtools/client/aboutdebugging/test/browser/browser_aboutdebugging_serviceworker_not_compatible.js | Connect button is displayed for the runtime Fancy Phone -
[task 2019-08-31T04:46:42.652Z] 04:46:42 INFO - Click on the connect button and wait until it disappears
[task 2019-08-31T04:46:42.652Z] 04:46:42 INFO - Buffered messages logged at 04:46:42
[task 2019-08-31T04:46:42.652Z] 04:46:42 INFO - TEST-PASS | devtools/client/aboutdebugging/test/browser/browser_aboutdebugging_serviceworker_not_compatible.js | Warning message is displayed -
[task 2019-08-31T04:46:42.653Z] 04:46:42 INFO - Remove all remote clients
[task 2019-08-31T04:46:42.653Z] 04:46:42 INFO - Removing tab.
[task 2019-08-31T04:46:42.653Z] 04:46:42 INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2019-08-31T04:46:42.654Z] 04:46:42 INFO - Got event: 'TabClose' on [object XULElement].
[task 2019-08-31T04:46:42.657Z] 04:46:42 INFO - Tab removed and finished closing
[task 2019-08-31T04:46:42.657Z] 04:46:42 INFO - Leaving test bound testRemoteRuntime
[task 2019-08-31T04:46:42.657Z] 04:46:42 INFO - Console message: [JavaScript Error: "uncaught exception: Object" {file: "resource://testing-common/PromiseTestUtils.jsm" line: 112}]
[task 2019-08-31T04:46:42.657Z] 04:46:42 INFO - Buffered messages finished
[task 2019-08-31T04:46:42.658Z] 04:46:42 INFO - TEST-UNEXPECTED-FAIL | devtools/client/aboutdebugging/test/browser/browser_aboutdebugging_serviceworker_not_compatible.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort. -
[task 2019-08-31T04:46:42.663Z] 04:46:42 INFO - GECKO(1692) | MEMORY STAT | vsize 8777MB | residentFast 1026MB | heapAllocated 315MB
[task 2019-08-31T04:46:42.663Z] 04:46:42 INFO - TEST-OK | devtools/client/aboutdebugging/test/browser/browser_aboutdebugging_serviceworker_not_compatible.js | took 97373ms
[task 2019-08-31T04:46:42.664Z] 04:46:42 INFO - GECKO(1692) | ++DOCSHELL 0x10e040000 == 1 [pid = 1713] [id = {f5d3f9f0-7122-ba4b-b6ed-fcf9a82df9b5}]
[task 2019-08-31T04:46:42.664Z] 04:46:42 INFO - GECKO(1692) | ++DOMWINDOW == 1 (0x10b604020) [pid = 1713] [serial = 1] [outer = 0x0]
[task 2019-08-31T04:46:42.667Z] 04:46:42 INFO - GECKO(1692) | ++DOMWINDOW == 2 (0x10b6e2400) [pid = 1713] [serial = 2] [outer = 0x10b604020]
[task 2019-08-31T04:46:42.759Z] 04:46:42 INFO - checking window state
[task 2019-08-31T04:46:47.893Z] 04:46:47 INFO - GECKO(1692) | --DOMWINDOW == 48 (0x179f96c00) [pid = 1692] [serial = 356] [outer = 0x0] [url = about:debugging]
[task 2019-08-31T04:46:47.907Z] 04:46:47 INFO - GECKO(1692) | --DOCSHELL 0x1080ab000 == 12 [pid = 1692] [id = {04c0516e-bb85-ae42-91a1-153ce1c5853f}] [url = about:debugging#/runtime/this-firefox]
[task 2019-08-31T04:46:47.971Z] 04:46:47 INFO - TEST-START | devtools/client/aboutdebugging/test/browser/browser_aboutdebugging_serviceworker_push.js
[task 2019-08-31T04:46:48.128Z] 04:46:48 INFO - GECKO(1692) | [Child 1697, Main Thread] WARNING: nsAppShell::Exit() called redundantly: file /builds/worker/workspace/build/src/widget/cocoa/nsAppShell.mm, line 725
[task 2019-08-31T04:46:48.128Z] 04:46:48 INFO - GECKO(1692) | [Child 1698, Main Thread] WARNING: nsAppShell::Exit() called redundantly: file /builds/worker/workspace/build/src/widget/cocoa/nsAppShell.mm, line 725
[task 2019-08-31T04:46:48.153Z] 04:46:48 INFO - GECKO(1692) | [Child 1712, Main Thread] WARNING: nsAppShell::Exit() called redundantly: file /builds/worker/workspace/build/src/widget/cocoa/nsAppShell.mm, line 725
[task 2019-08-31T04:46:48.256Z] 04:46:48 INFO - GECKO(1692) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-08-31T04:46:50.059Z] 04:46:50 INFO - GECKO(1692) | --DOCSHELL 0x10c84d000 == 0 [pid = 1712] [id = {4c0c04b2-f8ab-3e48-8fd6-03076b1c6aa6}] [url = about:blank]
[task 2019-08-31T04:46:51.343Z] 04:46:51 INFO - GECKO(1692) | --DOMWINDOW == 1 (0x1043b2020) [pid = 1712] [serial = 1] [outer = 0x0] [url = about:blank]
[task 2019-08-31T04:46:51.344Z] 04:46:51 INFO - GECKO(1692) | --DOMWINDOW == 0 (0x10c82c800) [pid = 1712] [serial = 2] [outer = 0x0] [url = about:blank]
[task 2019-08-31T04:46:51.494Z] 04:46:51 INFO - GECKO(1692) | nsStringStats
[task 2019-08-31T04:46:51.494Z] 04:46:51 INFO - GECKO(1692) | => mAllocCount: 17152
[task 2019-08-31T04:46:51.494Z] 04:46:51 INFO - GECKO(1692) | => mReallocCount: 0
[task 2019-08-31T04:46:51.494Z] 04:46:51 INFO - GECKO(1692) | => mFreeCount: 17152
[task 2019-08-31T04:46:51.494Z] 04:46:51 INFO - GECKO(1692) | => mShareCount: 18062
[task 2019-08-31T04:46:51.494Z] 04:46:51 INFO - GECKO(1692) | => mAdoptCount: 999
[task 2019-08-31T04:46:51.494Z] 04:46:51 INFO - GECKO(1692) | => mAdoptFreeCount: 999
[task 2019-08-31T04:46:51.494Z] 04:46:51 INFO - GECKO(1692) | => Process ID: 1712, Thread ID: 4508091840
[task 2019-08-31T04:46:56.443Z] 04:46:56 INFO - GECKO(1692) | ++DOCSHELL 0x100a51800 == 13 [pid = 1692] [id = {18c8d614-c5d4-504d-be3d-5e84a47bba89}]
[task 2019-08-31T04:46:56.443Z] 04:46:56 INFO - GECKO(1692) | ++DOMWINDOW == 49 (0x17a641200) [pid = 1692] [serial = 399] [outer = 0x0]
[task 2019-08-31T04:46:56.507Z] 04:46:56 INFO - GECKO(1692) | ++DOMWINDOW == 50 (0x13d14cc00) [pid = 1692] [serial = 400] [outer = 0x17a641200]
[task 2019-08-31T04:46:57.219Z] 04:46:57 INFO - GECKO(1692) | ++DOMWINDOW == 51 (0x10aaa7000) [pid = 1692] [serial = 401] [outer = 0x17a641200]
[task 2019-08-31T04:47:01.021Z] 04:47:01 INFO - GECKO(1692) | [Child 1697, Main Thread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 198
[task 2019-08-31T04:47:01.021Z] 04:47:01 INFO - GECKO(1692) | [Child 1697, Main Thread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 198
[task 2019-08-31T04:47:01.022Z] 04:47:01 INFO - GECKO(1692) | nsStringStats

Comment 7

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 2

Platform breakdown:

• macosx1014-64-ccov: 2

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

Comment 8

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1

Platform breakdown:

• windows10-64-ccov: 1

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

Comment 9

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform breakdown:

• macosx1014-64-ccov: 1

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

Comment 10

[BugBot [:suhaib / :marco/ :calixte]]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Comment 11

[Andreea Pavel [:apavel]]

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

Comment 12

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 11

Platform breakdown:

• linux64-ccov: 6
• windows10-64-ccov: 5

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

Comment 13

[Alexandru Michis [:malexandru]]

Hi Julian,
This is failing quite frequently on linux ccov, this is the range I could find for the failure:
https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&resultStatus=testfailed%2Cbusted%2Cexception%2Csuccess%2Cusercancel%2Crunning%2Cpending%2Crunnable&searchStr=linux%2Cx64%2Cccov%2Cdebug%2Cmochitests%2Ctest-linux64-ccov%2Fdebug-mochitest-devtools-chrome-e10s&tochange=9277be3613ca5109ae4007a512ee75856f8f1120&fromchange=dd7a79a0e83d6d24f672ce3f619f613ca7ab5f1d&selectedJob=273217663

Can you please take a look at it?

Comment 14

[Julian Descottes [:jdescottes]]

Thanks I'll take a look. Please note that before the changeset that you highlighted, the test was running in another chunk (dt5) so if the investigation is mainly based on dt6 retriggers, it might need some more retriggers.

Comment 15

[Alexandru Michis [:malexandru]]

I launched a couple retriggers on the dt5 chunk:
https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&resultStatus=testfailed%2Cbusted%2Cexception%2Csuccess%2Cusercancel%2Crunning%2Cpending%2Crunnable&searchStr=linux%2Cx64%2Cccov%2Cdebug%2Cmochitests%2Ctest-linux64-ccov%2Fdebug-mochitest-devtools-chrome-e10s&tochange=9277be3613ca5109ae4007a512ee75856f8f1120&fromchange=dd7a79a0e83d6d24f672ce3f619f613ca7ab5f1d&selectedJob=275289835

Looking in the log tells us that the test passes, that means that the regression landed in the push above:
https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&selectedJob=273217663&resultStatus=testfailed%2Cbusted%2Cexception%2Csuccess%2Cusercancel%2Crunning%2Cpending%2Crunnable&searchStr=linux%2Cx64%2Cccov%2Cdebug%2Cmochitests%2Ctest-linux64-ccov%2Fdebug-mochitest-devtools-chrome-e10s&revision=9277be3613ca5109ae4007a512ee75856f8f1120

Comment 16

[Intermittent Failures Robot]

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

This is the #49 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: 36
• try: 3

Platform breakdown:

• linux64-ccov: 17
• windows10-64-ccov: 22

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

Comment 17

[Julian Descottes [:jdescottes]]

Attachment: Failed test log

This is a real timeout, where the test succeeds but takes too much time.

This is an extract of a failed log. The test is successful on the platform, but it seems it jumped from taking 60 seconds to 90+ seconds: 
Test starts at 11:06:46, then we have 73 `--DOMWINDOW`, 11 `--DOCSHELL` against 26 `++DOMWINDOW` and 9 `++DOCSHELL`. Then the test actually starts at 11:08:23 and finishes in the same second.

It seems that the test just started running during a GC which makes it time out. I think splitting the test would probably just move the GC somewhere else, so let's request longer timeout here.

Comment 18

[Julian Descottes [:jdescottes]]

Attachment: Failed test log

```

Comment 19

[Julian Descottes [:jdescottes]]

Attachment: Bug 1526153 - Request longer timeout for browser_aboutdebugging_serviceworker_not_compatible

Also removed the outdated comment referring to the tests of the old aboutdebugging which are no longer in the source ocntrol.
Seems like this was the only leftover comment of the sort.

Comment 20

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/43033bd0f88d
Request longer timeout for browser_aboutdebugging_serviceworker_not_compatible r=ladybenko

Comment 21

[Andrei Ciure[:aciure]]

https://hg.mozilla.org/mozilla-central/rev/43033bd0f88d

Comment 22

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 4
• try: 1

Platform breakdown:

• windows10-64-ccov: 3
• linux64-ccov: 2

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