1652828 - High frequency devtools/client/application/test/browser/browser_application_panel_telemetry-workers.js | Test timed out -

Status: RESOLVED FIXED

(DevTools :: General, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2020-07-14T17:32:53.700Z] 17:32:53     INFO - TEST-START | devtools/client/application/test/browser/browser_application_panel_telemetry-workers.js
[task 2020-07-14T17:32:53.801Z] 17:32:53     INFO - GECKO(1274) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-07-14T17:32:54.237Z] 17:32:54     INFO - GECKO(1274) | Empty service worker registered
[task 2020-07-14T17:32:54.359Z] 17:32:54     INFO - GECKO(1274) | [CodeCoverage] Setting handlers for process 1872.
[task 2020-07-14T17:32:58.022Z] 17:32:58     INFO - GECKO(1274) | Empty service worker registered
[task 2020-07-14T17:33:38.722Z] 17:33:38     INFO - TEST-INFO | started process screentopng
[task 2020-07-14T17:33:38.940Z] 17:33:38     INFO - TEST-INFO | screentopng: exit 0
[task 2020-07-14T17:33:38.940Z] 17:33:38     INFO - Buffered messages logged at 17:32:53
[task 2020-07-14T17:33:38.941Z] 17:33:38     INFO - Entering test bound 
[task 2020-07-14T17:33:38.941Z] 17:33:38     INFO - Adding a new tab with URL: http://example.com/browser/devtools/client/application/test/browser/resources/service-workers/simple.html
[task 2020-07-14T17:33:38.941Z] 17:33:38     INFO - Buffered messages logged at 17:32:54
[task 2020-07-14T17:33:38.942Z] 17:33:38     INFO - Tab added and finished loading
[task 2020-07-14T17:33:38.942Z] 17:33:38     INFO - Buffered messages logged at 17:32:55
[task 2020-07-14T17:33:38.942Z] 17:33:38     INFO - Selecting application page: service-workers
[task 2020-07-14T17:33:38.942Z] 17:33:38     INFO - TEST-PASS | devtools/client/application/test/browser/browser_application_panel_telemetry-workers.js | No events have been logged for the main process - 
[task 2020-07-14T17:33:38.942Z] 17:33:38     INFO - Wait until the service worker appears in the application panel
[task 2020-07-14T17:33:38.943Z] 17:33:38     INFO - Wait until the unregister button is displayed for the service worker
[task 2020-07-14T17:33:38.943Z] 17:33:38     INFO - Click the unregister button
[task 2020-07-14T17:33:38.943Z] 17:33:38     INFO - Check telemetry event
[task 2020-07-14T17:33:38.943Z] 17:33:38     INFO - TEST-PASS | devtools/client/application/test/browser/browser_application_panel_telemetry-workers.js | There was only 1 event logged - 
[task 2020-07-14T17:33:38.943Z] 17:33:38     INFO - TEST-PASS | devtools/client/application/test/browser/browser_application_panel_telemetry-workers.js | There is a valid session_id in the event - 
[task 2020-07-14T17:33:38.943Z] 17:33:38     INFO - TEST-PASS | devtools/client/application/test/browser/browser_application_panel_telemetry-workers.js | {"method":"unregister_worker","session_id":"105642"} deepEqual {"method":"unregister_worker","session_id":"105642"} - 
[task 2020-07-14T17:33:38.944Z] 17:33:38     INFO - Closing the tab.
[task 2020-07-14T17:33:38.944Z] 17:33:38     INFO - Leaving test bound 
[task 2020-07-14T17:33:38.944Z] 17:33:38     INFO - Entering test bound 
[task 2020-07-14T17:33:38.944Z] 17:33:38     INFO - Set a low service worker idle timeout
[task 2020-07-14T17:33:38.944Z] 17:33:38     INFO - Buffered messages logged at 17:32:57
[task 2020-07-14T17:33:38.945Z] 17:33:38     INFO - Adding a new tab with URL: http://example.com/browser/devtools/client/application/test/browser/resources/service-workers/simple.html
[task 2020-07-14T17:33:38.946Z] 17:33:38     INFO - Tab added and finished loading
[task 2020-07-14T17:33:38.947Z] 17:33:38     INFO - Buffered messages logged at 17:32:59
[task 2020-07-14T17:33:38.947Z] 17:33:38     INFO - Selecting application page: service-workers
[task 2020-07-14T17:33:38.948Z] 17:33:38     INFO - Wait until the registration appears on the window
[task 2020-07-14T17:33:38.948Z] 17:33:38     INFO - TEST-PASS | devtools/client/application/test/browser/browser_application_panel_telemetry-workers.js | No events have been logged for the main process - 
[task 2020-07-14T17:33:38.949Z] 17:33:38     INFO - Wait until the service worker appears in the application panel
[task 2020-07-14T17:33:38.949Z] 17:33:38     INFO - Wait until the start button is displayed and enabled
[task 2020-07-14T17:33:38.950Z] 17:33:38     INFO - Buffered messages finished
[task 2020-07-14T17:33:38.950Z] 17:33:38     INFO - TEST-UNEXPECTED-FAIL | devtools/client/application/test/browser/browser_application_panel_telemetry-workers.js | Test timed out - 
[task 2020-07-14T17:33:39.167Z] 17:33:39     INFO - Removing tab.
[task 2020-07-14T17:33:39.168Z] 17:33:39     INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2020-07-14T17:33:39.183Z] 17:33:39     INFO - Got event: 'TabClose' on [object XULElement].
[task 2020-07-14T17:33:39.199Z] 17:33:39     INFO - Tab removed and finished closing
[task 2020-07-14T17:33:39.247Z] 17:33:39     INFO - TEST-PASS | devtools/client/application/test/browser/browser_application_panel_telemetry-workers.js | The main process DevToolsServer has no pending connection when the test ends - 
[task 2020-07-14T17:33:39.270Z] 17:33:39     INFO - GECKO(1274) | MEMORY STAT | vsize 3625MB | residentFast 624MB | heapAllocated 129MB
[task 2020-07-14T17:33:39.271Z] 17:33:39     INFO - TEST-OK | devtools/client/application/test/browser/browser_application_panel_telemetry-workers.js | took 45572ms
[task 2020-07-14T17:33:39.634Z] 17:33:39     INFO - checking window state
[task 2020-07-14T17:33:39.675Z] 17:33:39     INFO - TEST-START | devtools/client/application/test/browser/browser_application_panel_unregister-worker.js
[task 2020-07-14T17:33:39.771Z] 17:33:39     INFO - GECKO(1274) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-07-14T17:33:40.052Z] 17:33:40     INFO - GECKO(1274) | Empty service worker registered
[task 2020-07-14T17:33:40.304Z] 17:33:40     INFO - GECKO(1274) | [CodeCoverage] Setting handlers for process 1902.
[task 2020-07-14T17:33:42.576Z] 17:33:42     INFO - GECKO(1274) | MEMORY STAT | vsize 3619MB | residentFast 635MB | heapAllocated 145MB
[task 2020-07-14T17:33:42.576Z] 17:33:42     INFO - TEST-OK | devtools/client/application/test/browser/browser_application_panel_unregister-worker.js | took 2909ms
[task 2020-07-14T17:33:42.934Z] 17:33:42     INFO - checking window state
[task 2020-07-14T17:33:42.956Z] 17:33:42     INFO - TEST-START | devtools/client/application/test/browser/browser_application_panel_worker-states.js
[task 2020-07-14T17:33:43.071Z] 17:33:43     INFO - GECKO(1274) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-07-14T17:33:43.637Z] 17:33:43     INFO - GECKO(1274) | [CodeCoverage] Setting handlers for process 1929.
[task 2020-07-14T17:33:46.051Z] 17:33:46     INFO - GECKO(1274) | MEMORY STAT | vsize 3619MB | residentFast 644MB | heapAllocated 157MB
[task 2020-07-14T17:33:46.051Z] 17:33:46     INFO - TEST-OK | devtools/client/application/test/browser/browser_application_panel_worker-states.js | took 3090ms
[task 2020-07-14T17:33:46.409Z] 17:33:46     INFO - checking window state
[task 2020-07-14T17:33:47.138Z] 17:33:47     INFO - GECKO(1274) | [CodeCoverage] Setting handlers for process 1955.
[task 2020-07-14T17:33:50.384Z] 17:33:50     INFO - GECKO(1274) | Completed ShutdownLeaks collections in process 1955
[task 2020-07-14T17:33:50.581Z] 17:33:50     INFO - GECKO(1274) | Completed ShutdownLeaks collections in process 1382
[task 2020-07-14T17:33:50.604Z] 17:33:50     INFO - GECKO(1274) | Completed ShutdownLeaks collections in process 1363
[task 2020-07-14T17:33:50.632Z] 17:33:50     INFO - GECKO(1274) | Completed ShutdownLeaks collections in process 1929
[task 2020-07-14T17:33:54.514Z] 17:33:54     INFO - GECKO(1274) | Completed ShutdownLeaks collections in process 1274
[task 2020-07-14T17:33:54.515Z] 17:33:54     INFO - TEST-START | Shutdown

Comment 1

[Alexandru Michis [:malexandru]]

Belen,
I see that this test was introduced in Bug 1643253, could you please take a look?

Currently permafailing on ccov jobs:
https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&group_state=expanded&searchStr=linux%2C18.04%2Cx64%2Cccov%2Copt%2Cmochitests%2Ctest-linux1804-64-ccov%2Fopt-mochitest-devtools-chrome-e10s%2Cdt9&fromchange=f13654aaef855ac8ca3502e557d99d01415a1a71&tochange=bca48c382991c7fd778f835f2a780e3c35185fc4

Comment 2

[Natalia Csoregi [:nataliaCs]]

Started failing on tier 1 as well, but it is intermittent

Comment 3

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

Set release status flags based on info from the regressing bug 1643253

Comment 4

[Belén [:ladybenko]]

Hi, I'm investigating this.

Comment 5

[Belén [:ladybenko]]

Attachment: Bug 1652828 - Skip browser_application_panel_telemetry-workers.js test in ccov platform

I'm unsure why this is permafailing in ccov. I'm trying with longer timeouts, but in the meantime maybe it's best to disable the test and keep this bug open while we find what's the root cause. (Try push here https://treeherder.mozilla.org/#/jobs?repo=try&revision=be4007c9a758b76a0c4346a1931c1c61af7cb418 )

Comment 6

[Intermittent Failures Robot]

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

This is the #42 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: 24
• autoland: 10

Platform breakdown:

• linux1804-64-ccov: 11
• linux1804-64-shippable: 3
• windows10-64-shippable: 7
• windows10-64-ccov: 9
• windows10-64: 1
• linux1804-64: 3

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

Comment 7

[Pulsebot]

Backout by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/c69a7f114fbf
Backed out changeset aa5b7db30aed as req by aa5b7db30aed. DONTBUILD CLOSED TREE

Comment 8

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/f8c223b7ff37
Skip browser_application_panel_telemetry-workers.js test in ccov platform r=jdescottes

Comment 9

[Andreea Pavel [:apavel]]

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

Comment 10

[Belén [:ladybenko]]

Attachment: Bug 1652828 - Fix intermittent failure in app panel telemetry tests

Comment 11

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/6fa683e60d96
Fix intermittent failure in app panel telemetry tests r=jdescottes

Comment 12

[Cosmin Sabou [:CosminS]]

https://hg.mozilla.org/mozilla-central/rev/6fa683e60d96

Comment 13

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 7
• try: 2

Platform breakdown:

• linux1804-64-ccov: 3
• windows10-64-ccov: 3
• windows10-64: 1
• linux1804-64: 1
• linux1804-64-asan: 1

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