1584669 - Perma fission [tier2] browser/base/content/test/trackingUI/browser_trackingUI_telemetry.js | Test timed out -

Status: RESOLVED FIXED

(Firefox :: Protections UI, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: dvarga [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=268860338&repo=mozilla-central
Full log: https://queue.taskcluster.net/v1/task/ONFg_av_TCe0VTkUgjSuBg/runs/0/artifacts/public/logs/live_backing.log

---

[task 2019-09-27T22:31:14.844Z] 22:31:14     INFO - Leaving test bound setup
[task 2019-09-27T22:31:14.845Z] 22:31:14     INFO - Entering test bound testShieldHistogram
[task 2019-09-27T22:31:14.846Z] 22:31:14     INFO - Buffered messages logged at 22:29:45
[task 2019-09-27T22:31:14.847Z] 22:31:14     INFO - Wait tab event: load
[task 2019-09-27T22:31:14.848Z] 22:31:14     INFO - Tab event received: load
[task 2019-09-27T22:31:14.850Z] 22:31:14     INFO - TEST-PASS | browser/base/content/test/trackingUI/browser_trackingUI_telemetry.js | Page loads without tracking - 
[task 2019-09-27T22:31:14.851Z] 22:31:14     INFO - Wait tab event: load
[task 2019-09-27T22:31:14.852Z] 22:31:14     INFO - Buffered messages logged at 22:29:46
[task 2019-09-27T22:31:14.853Z] 22:31:14     INFO - Console message: [JavaScript Warning: "The resource at “http://trackertest.org/” was blocked because content blocking is enabled." {file: "about:blank" line: 0}]
[task 2019-09-27T22:31:14.854Z] 22:31:14     INFO - Buffered messages finished
[task 2019-09-27T22:31:14.855Z] 22:31:14     INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/trackingUI/browser_trackingUI_telemetry.js | Test timed out - 
[task 2019-09-27T22:31:14.856Z] 22:31:14     INFO - GECKO(3022) | MEMORY STAT | vsize 2991MB | residentFast 352MB | heapAllocated 101MB
[task 2019-09-27T22:31:14.857Z] 22:31:14     INFO - TEST-OK | browser/base/content/test/trackingUI/browser_trackingUI_telemetry.js | took 90127ms
[task 2019-09-27T22:31:14.858Z] 22:31:14     INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-09-27T22:31:14.859Z] 22:31:14     INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/trackingUI/browser_trackingUI_telemetry.js | Found a tab after previous test timed out: http://tracking.example.org/browser/browser/base/content/test/trackingUI/trackingPage.html - 
[task 2019-09-27T22:31:14.862Z] 22:31:14     INFO - GECKO(3022) | ++DOCSHELL 0x7f75417dd800 == 1 [pid = 3155] [id = {9a5f9ba5-3859-4e07-80c9-cb15a8e463a1}]
[task 2019-09-27T22:31:14.863Z] 22:31:14     INFO - GECKO(3022) | ++DOMWINDOW == 1 (0x7f7540f20f20) [pid = 3155] [serial = 6] [outer = (nil)]
[task 2019-09-27T22:31:14.865Z] 22:31:14     INFO - GECKO(3022) | ++DOMWINDOW == 2 (0x7f7540f2fc00) [pid = 3155] [serial = 7] [outer = 0x7f7540f20f20]
[task 2019-09-27T22:31:14.866Z] 22:31:14     INFO - GECKO(3022) | ++DOMWINDOW == 3 (0x7f75417b6400) [pid = 3155] [serial = 8] [outer = 0x7f7540f20f20]
[task 2019-09-27T22:31:14.867Z] 22:31:14     INFO - checking window state
[task 2019-09-27T22:31:14.868Z] 22:31:14     INFO - GECKO(3022) | [Parent 3022, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005: file /builds/worker/workspace/build/src/dom/base/nsFrameLoader.cpp, line 674
[task 2019-09-27T22:31:14.869Z] 22:31:14     INFO - GECKO(3022) | ++DOMWINDOW == 13 (0x7facd1f37000) [pid = 3022] [serial = 21] [outer = 0x7facdcde6200]
[task 2019-09-27T22:31:14.873Z] 22:31:14     INFO - GECKO(3022) | ++DOMWINDOW == 14 (0x7facd1f34c00) [pid = 3022] [serial = 22] [outer = 0x7facdcde6200]
[task 2019-09-27T22:31:15.218Z] 22:31:15     INFO - GECKO(3022) | --DOCSHELL 0x7fe7b31b8000 == 0 [pid = 3387] [id = {f1eecd82-89f4-4455-a5b9-c83f131753a2}] [url = about:blank]
[task 2019-09-27T22:31:15.339Z] 22:31:15     INFO - GECKO(3022) | --DOMWINDOW == 2 (0x7f7540f2fc00) [pid = 3155] [serial = 7] [outer = (nil)] [url = about:blank]
[task 2019-09-27T22:31:15.500Z] 22:31:15     INFO - GECKO(3022) | --DOCSHELL 0x7f6c7bc22000 == 0 [pid = 3099] [id = {dc40ee5b-69b3-4d95-b389-c5a0c39a8c5e}] [url = about:newtab]
[task 2019-09-27T22:31:15.500Z] 22:31:15     INFO - GECKO(3022) | --DOMWINDOW == 1 (0x7f6c7bcd64c0) [pid = 3099] [serial = 4] [outer = (nil)] [url = about:newtab]
[task 2019-09-27T22:31:15.500Z] 22:31:15     INFO - GECKO(3022) | --DOMWINDOW == 0 (0x7f6c7bc45800) [pid = 3099] [serial = 6] [outer = (nil)] [url = about:newtab]
[task 2019-09-27T22:31:16.651Z] 22:31:16     INFO - GECKO(3022) | --DOCSHELL 0x7f592dab6000 == 0 [pid = 3412] [id = {ccdb6366-3d7b-4717-8b7d-d9942bda5aa7}] [url = http://tracking.example.org/browser/browser/base/content/test/trackingUI/trackingPage.html]
[task 2019-09-27T22:31:16.652Z] 22:31:16     INFO - GECKO(3022) | ###!!! [Child][MessageChannel] Error: (msgtype=0x8C0001,name=PSessionStorageObserver::Msg_DeleteMe) Channel closing: too late to send/recv, messages will be lost
[task 2019-09-27T22:31:16.652Z] 22:31:16     INFO - GECKO(3022) | [Child 3412, Main Thread] WARNING: MsgDropped in ContentChild: file /builds/worker/workspace/build/src/dom/ipc/ContentChild.cpp, line 2436

Comment 1

[Daniel Varga [:dvarga]]

Retrigger link: https://treeherder.mozilla.org/#/jobs?repo=autoland&resultStatus=testfailed%2Cbusted%2Cexception%2Cpending%2Crunning&classifiedState=unclassified&tochange=d23a0a0ffa93fe273c571592bdbff6aa68f6ca2b&fromchange=9f12d9b4c6b5a9b3617b7718c7985aca8d4f0b99&selectedJob=268887663

:annyG, can you please take a look, seems this started to fail after bug 1582531 got landed?

Comment 2

[Intermittent Failures Robot]

23 failures in 850 pushes (0.027 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 16
• mozilla-central: 7

Platform breakdown:

• linux64: 23

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

Comment 3

[Intermittent Failures Robot]

33 failures in 4530 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: 14
• autoland: 18
• try: 1

Platform breakdown:

• linux64: 30
• windows10-64: 1
• windows10-64-qr: 2

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

Comment 4

[Anny Gakhokidze [:annyG]]

This is most likely because of me removing the skip-if annotation. I have a patch I am testing right now to double check this.

Comment 5

[Anny Gakhokidze [:annyG]]

This should be fixed now in bug 1582531, as I changed the annotation for this test.

Comment 6

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 2
• try: 3

Platform breakdown:

• linux64: 4
• linux64-ccov: 1

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

Comment 7

[Neha Kochar [:neha]]

No new failures since Oct 2.

Comment 8

[Chris Peterson [:cpeterson]]

Retroactively moving fixed bugs whose summaries mention "Fission" (or other Fission-related keywords) but are not assigned to a Fission Milestone to an appropriate Fission Milestone.

This will generate a lot of bugmail, so you can filter your bugmail for the following UUID and delete them en masse:

0ee3c76a-bc79-4eb2-8d12-05dc0b68e732