1584391 - Intermittent toolkit/components/extensions/test/browser/browser_ext_themes_ntp_colors_perwindow.js | leaked 1 window(s) until shutdown [url = chrome://browser/content/browser.xhtml]

Status: RESOLVED FIXED

(WebExtensions :: General, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: shindli [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=268670609&repo=mozilla-inbound
Full log: https://queue.taskcluster.net/v1/task/cX5kXhZyTZiMFcHKTbvJMg/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://queue.taskcluster.net/v1/task/cX5kXhZyTZiMFcHKTbvJMg/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

---

[task 2019-09-26T23:17:11.384Z] 23:17:11 INFO - GECKO(27640) | => mAllocCount: 50127
[task 2019-09-26T23:17:11.385Z] 23:17:11 INFO - GECKO(27640) | => mReallocCount: 0
[task 2019-09-26T23:17:11.386Z] 23:17:11 INFO - GECKO(27640) | => mFreeCount: 50127
[task 2019-09-26T23:17:11.387Z] 23:17:11 INFO - GECKO(27640) | => mShareCount: 159165
[task 2019-09-26T23:17:11.387Z] 23:17:11 INFO - GECKO(27640) | => mAdoptCount: 2769
[task 2019-09-26T23:17:11.388Z] 23:17:11 INFO - GECKO(27640) | => mAdoptFreeCount: 2821
[task 2019-09-26T23:17:11.389Z] 23:17:11 INFO - GECKO(27640) | => Process ID: 27765, Thread ID: 140550449268544
[task 2019-09-26T23:17:11.411Z] 23:17:11 INFO - GECKO(27640) | nsStringStats
[task 2019-09-26T23:17:11.412Z] 23:17:11 INFO - GECKO(27640) | => mAllocCount: 50963
[task 2019-09-26T23:17:11.412Z] 23:17:11 INFO - GECKO(27640) | => mReallocCount: 0
[task 2019-09-26T23:17:11.412Z] 23:17:11 INFO - GECKO(27640) | => mFreeCount: 50963
[task 2019-09-26T23:17:11.413Z] 23:17:11 INFO - GECKO(27640) | => mShareCount: 170519
[task 2019-09-26T23:17:11.413Z] 23:17:11 INFO - GECKO(27640) | => mAdoptCount: 2594
[task 2019-09-26T23:17:11.413Z] 23:17:11 INFO - GECKO(27640) | => mAdoptFreeCount: 2650
[task 2019-09-26T23:17:11.413Z] 23:17:11 INFO - GECKO(27640) | => Process ID: 27793, Thread ID: 139936686417728
[task 2019-09-26T23:17:11.438Z] 23:17:11 INFO - GECKO(27640) | nsStringStats
[task 2019-09-26T23:17:11.440Z] 23:17:11 INFO - GECKO(27640) | => mAllocCount: 12862
[task 2019-09-26T23:17:11.441Z] 23:17:11 INFO - GECKO(27640) | => mReallocCount: 0
[task 2019-09-26T23:17:11.442Z] 23:17:11 INFO - GECKO(27640) | => mFreeCount: 12862
[task 2019-09-26T23:17:11.443Z] 23:17:11 INFO - GECKO(27640) | => mShareCount: 16724
[task 2019-09-26T23:17:11.443Z] 23:17:11 INFO - GECKO(27640) | => mAdoptCount: 398
[task 2019-09-26T23:17:11.444Z] 23:17:11 INFO - GECKO(27640) | => mAdoptFreeCount: 402
[task 2019-09-26T23:17:11.445Z] 23:17:11 INFO - GECKO(27640) | => Process ID: 27909, Thread ID: 140664718829376
[task 2019-09-26T23:17:11.635Z] 23:17:11 INFO - GECKO(27640) | 1569539831633 Marionette TRACE Received observer notification xpcom-will-shutdown
[task 2019-09-26T23:17:11.636Z] 23:17:11 INFO - GECKO(27640) | 1569539831633 Marionette INFO Stopped listening on port 2828
[task 2019-09-26T23:17:11.637Z] 23:17:11 INFO - GECKO(27640) | 1569539831634 Marionette DEBUG Remote service is inactive
[task 2019-09-26T23:17:11.645Z] 23:17:11 INFO - GECKO(27640) | [Parent 27640, Main Thread] WARNING: NS_ENSURE_TRUE(mDB) failed: file /builds/worker/workspace/build/src/netwerk/cache/nsDiskCacheDeviceSQL.cpp, line 1285
[task 2019-09-26T23:17:12.618Z] 23:17:12 INFO - GECKO(27640) | --DOMWINDOW == 13 (0x7f670d7f4800) [pid = 27640] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-09-26T23:17:12.620Z] 23:17:12 INFO - GECKO(27640) | --DOMWINDOW == 12 (0x7f67000cdc00) [pid = 27640] [serial = 58] [outer = (nil)] [url = about:blank]
[task 2019-09-26T23:17:12.626Z] 23:17:12 INFO - GECKO(27640) | --DOMWINDOW == 11 (0x7f66ffcbb7a0) [pid = 27640] [serial = 57] [outer = (nil)] [url = chrome://browser/content/browser.xhtml]
[task 2019-09-26T23:17:12.628Z] 23:17:12 INFO - GECKO(27640) | --DOMWINDOW == 10 (0x7f6711d97880) [pid = 27640] [serial = 1] [outer = (nil)] [url = chrome://browser/content/browser.xhtml]
[task 2019-09-26T23:17:12.629Z] 23:17:12 INFO - GECKO(27640) | --DOMWINDOW == 9 (0x7f67070fb6a0) [pid = 27640] [serial = 13] [outer = (nil)] [url = chrome://mochikit/content/browser-harness.xul]
[task 2019-09-26T23:17:12.630Z] 23:17:12 INFO - GECKO(27640) | --DOMWINDOW == 8 (0x7f6704642000) [pid = 27640] [serial = 14] [outer = (nil)] [url = about:blank]
[task 2019-09-26T23:17:12.631Z] 23:17:12 INFO - GECKO(27640) | --DOMWINDOW == 7 (0x7f670a5687a0) [pid = 27640] [serial = 5] [outer = (nil)] [url = chrome://extensions/content/dummy.xul]
[task 2019-09-26T23:17:12.632Z] 23:17:12 INFO - GECKO(27640) | --DOMWINDOW == 6 (0x7f6709ecdc00) [pid = 27640] [serial = 7] [outer = (nil)] [url = chrome://extensions/content/dummy.xul]
[task 2019-09-26T23:17:12.633Z] 23:17:12 INFO - GECKO(27640) | --DOMWINDOW == 5 (0x7f67070fb100) [pid = 27640] [serial = 10] [outer = (nil)] [url = resource://gre-resources/hiddenWindow.html]

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-inbound: 2
• autoland: 6
• mozilla-central: 3

Platform breakdown:

• linux64: 1
• windows10-64: 5
• windows10-64-ccov: 1
• windows10-64-qr: 2
• linux64-ccov: 1
• macosx1014-64: 1

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

Comment 2

[Intermittent Failures Robot]

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

This is the #45 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: 26
• mozilla-central: 6
• mozilla-beta: 1
• try: 2

Platform breakdown:

• windows10-64: 16
• linux64-ccov: 5
• linux64: 6
• macosx1014-64: 2
• windows10-64-qr: 5
• windows7-32: 1

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

Comment 3

[Andreea Pavel [:apavel]]

Hi Rob, can you take a look at this?

Comment 4

[Rob Wu [:robwu]]

This looks identical to bug 1474041.
Why did the intermittent failure viewer graph flatline despite the bug nog being fixed? ( https://bugzilla.mozilla.org/show_bug.cgi?id=1474041#c72 )

I checked the test again, and there is no obvious way that this bug could have been caused by the test or extension API implementation.

Comment 5

[Intermittent Failures Robot]

54 failures in 3801 pushes (0.014 failures/push) were associated with this bug in the last 7 days.

This is the #32 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: 35
• mozilla-central: 10
• mozilla-inbound: 1
• mozilla-beta: 2
• try: 6

Platform breakdown:

• windows10-64: 25
• windows10-64-ccov: 2
• windows10-64-qr: 10
• linux64: 16
• linux64-ccov: 1

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

Comment 6

[Andreea Pavel [:apavel]]

(In reply to Rob Wu [:robwu] from comment #4)

This looks identical to bug 1474041.
Why did the intermittent failure viewer graph flatline despite the bug nog being fixed? ( https://bugzilla.mozilla.org/show_bug.cgi?id=1474041#c72 )

I checked the test again, and there is no obvious way that this bug could have been caused by the test or extension API implementation.

Since the bug was closed as fixed I assume it didn't show up as a suggestion in TH so this one got filed.

Comment 7

[Intermittent Failures Robot]

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

Repository breakdown:

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

Platform breakdown:

• windows10-64-qr: 11
• windows10-64: 7
• linux64: 8
• linux64-ccov: 2

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

Comment 8

[Intermittent Failures Robot]

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

This is the #46 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:

• try: 5
• mozilla-central: 7
• autoland: 26
• mozilla-esr68: 1

Platform breakdown:

• linux64: 20
• windows10-64-qr: 13
• windows10-64: 3
• macosx1014-64: 1
• linux64-ccov: 1
• windows10-64-ccov: 1

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

Comment 9

[Andreea Pavel [:apavel]]

Rob are you working on this?

Even if this is a duplicate of bug 1474041, the issue is still happening, having 33 total failures in the last 7 days on windows10-64-qr and linux64 both debug builds. Should we disable the test until there is a fix?

Comment 10

[Rob Wu [:robwu]]

I'm not actively working on this, as I haven't found any pointers towards a potential cause. Still keeping this in my needinfo queue just in case.

I'd rather not disable this test, because there are no obvious signs of the test being bad.
If anything, I would disable parts of the test, land then with keyword leave-open and then see if the issue goes away.

About my question in comment 4, I am still genuinely wondering why the graph stopped showing failures. I thought that failures are still automatically attributed to a bug (especially if the error is the same), even if the bug is closed.

Comment 11

[Andreea Pavel [:apavel]]

@Rob: Failures are manually classified against bugs. We, sheriffs, classify them.

Jim, since Rob inclined for this test not to be disabled, can you assign someone to work on it?

There are 37 total failures in the last 7 days on linux64,linux64-ccov, macosx, windows10-64-qr all debug builds

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

[task 2019-10-30T16:44:21.578Z] 16:44:21 INFO - TEST-START | toolkit/components/extensions/test/browser/browser_ext_windows_popup_title.js
[task 2019-10-30T16:44:21.654Z] 16:44:21 INFO - GECKO(6343) | --DOMWINDOW == 6 (0x7f41b049dc00) [pid = 6472] [serial = 69] [outer = (nil)] [url = about:blank]
[task 2019-10-30T16:44:21.736Z] 16:44:21 INFO - GECKO(6343) | --DOMWINDOW == 5 (0x7f41b09ee2e0) [pid = 6472] [serial = 70] [outer = (nil)] [url = about:blank]
[task 2019-10-30T16:44:21.736Z] 16:44:21 INFO - GECKO(6343) | --DOMWINDOW == 4 (0x7f41b09ee4c0) [pid = 6472] [serial = 72] [outer = (nil)] [url = about:blank]
[task 2019-10-30T16:44:21.755Z] 16:44:21 INFO - GECKO(6343) | [Parent 6343, Main Thread] WARNING: Need BrowserChild to get the nativeWindow from!: file /builds/worker/workspace/build/src/widget/PuppetWidget.cpp, line 1090
[task 2019-10-30T16:44:21.755Z] 16:44:21 INFO - GECKO(6343) | ++DOCSHELL 0x7fd3ada4a800 == 5 [pid = 6395] [id = {4813ea99-27fd-4310-95a0-c8bf75ddc42e}]
[task 2019-10-30T16:44:21.755Z] 16:44:21 INFO - GECKO(6343) | ++DOMWINDOW == 10 (0x7fd3adadc880) [pid = 6395] [serial = 52] [outer = (nil)]
[task 2019-10-30T16:44:21.757Z] 16:44:21 INFO - GECKO(6343) | ++DOMWINDOW == 11 (0x7fd3aa91bc00) [pid = 6395] [serial = 53] [outer = 0x7fd3adadc880]
[task 2019-10-30T16:44:21.780Z] 16:44:21 INFO - GECKO(6343) | [Child 6395, Main Thread] WARNING: Fallback to BasicLayerManager: file /builds/worker/workspace/build/src/dom/ipc/BrowserChild.cpp, line 2700
[task 2019-10-30T16:44:21.841Z] 16:44:21 INFO - GECKO(6343) | ++DOMWINDOW == 12 (0x7fd3ac45cc00) [pid = 6395] [serial = 54] [outer = 0x7fd3adadc880]
[task 2019-10-30T16:44:22.067Z] 16:44:22 INFO - GECKO(6343) | ++DOCSHELL 0x7fc0bcc67800 == 7 [pid = 6343] [id = {452eb341-5fe1-47d9-bb6b-dcbfdff313df}]
[task 2019-10-30T16:44:22.067Z] 16:44:22 INFO - GECKO(6343) | ++DOMWINDOW == 32 (0x7fc0d89585c0) [pid = 6343] [serial = 54] [outer = (nil)]
[task 2019-10-30T16:44:22.068Z] 16:44:22 INFO - GECKO(6343) | ++DOMWINDOW == 33 (0x7fc0e4fd8400) [pid = 6343] [serial = 55] [outer = 0x7fc0d89585c0]
[task 2019-10-30T16:44:22.774Z] 16:44:22 INFO - GECKO(6343) | ++DOCSHELL 0x7fc0be428000 == 8 [pid = 6343] [id = {2de49268-17df-4ab4-96bf-7f424c475300}]
[task 2019-10-30T16:44:22.774Z] 16:44:22 INFO - GECKO(6343) | ++DOMWINDOW == 34 (0x7fc0d89587a0) [pid = 6343] [serial = 56] [outer = (nil)]
[task 2019-10-30T16:44:23.114Z] 16:44:23 INFO - GECKO(6343) | ++DOCSHELL 0x7fd3ada4e000 == 6 [pid = 6395] [id = {8437e165-a9d2-42ae-9f80-d24f020de547}]
[task 2019-10-30T16:44:23.114Z] 16:44:23 INFO - GECKO(6343) | ++DOMWINDOW == 13 (0x7fd3adadca60) [pid = 6395] [serial = 55] [outer = (nil)]
[task 2019-10-30T16:44:23.114Z] 16:44:23 INFO - GECKO(6343) | ++DOMWINDOW == 14 (0x7fd3aa922800) [pid = 6395] [serial = 56] [outer = 0x7fd3adadca60]
[task 2019-10-30T16:44:24.566Z] 16:44:24 INFO - GECKO(6343) | ++DOMWINDOW == 35 (0x7fc0bef93400) [pid = 6343] [serial = 57] [outer = 0x7fc0d89587a0]
[task 2019-10-30T16:44:24.703Z] 16:44:24 INFO - GECKO(6343) | --DOMWINDOW == 34 (0x7fc0c8182c00) [pid = 6343] [serial = 51] [outer = (nil)] [url = about:blank]
[task 2019-10-30T16:44:24.961Z] 16:44:24 INFO - GECKO(6343) | ++DOMWINDOW == 15 (0x7fd3aa924400) [pid = 6395] [serial = 57] [outer = 0x7fd3adadca60]
[task 2019-10-30T16:44:25.057Z] 16:44:25 INFO - GECKO(6343) | [Parent 6343, Main Thread] WARNING: Ignoring duplicate observer.: file /builds/worker/workspace/build/src/modules/libpref/Preferences.cpp, line 2696
[task 2019-10-30T16:44:25.502Z] 16:44:25 INFO - GECKO(6343) | --DOCSHELL 0x7fd3ac362800 == 5 [pid = 6395] [id = {61a99dbd-535a-4da3-ac50-81b6f268b853}] [url = moz-extension://ae819b89-8312-4f58-9223-dfe94ef6ba46/_generated_background_page.html]
[task 2019-10-30T16:44:25.570Z] 16:44:25 INFO - GECKO(6343) | MEMORY STAT | vsize 3539MB | residentFast 720MB | heapAllocated 205MB
[task 2019-10-30T16:44:25.570Z] 16:44:25 INFO - TEST-OK | toolkit/components/extensions/test/browser/browser_ext_windows_popup_title.js | took 3988ms
[task 2019-10-30T16:44:25.586Z] 16:44:25 INFO - GECKO(6343) | ++DOCSHELL 0x7f41b0409000 == 2 [pid = 6472] [id = {6973dd61-3adb-489b-9916-8788660e7963}]
[task 2019-10-30T16:44:25.587Z] 16:44:25 INFO - GECKO(6343) | ++DOMWINDOW == 5 (0x7f41b09ed200) [pid = 6472] [serial = 76] [outer = (nil)]
[task 2019-10-30T16:44:25.588Z] 16:44:25 INFO - GECKO(6343) | ++DOMWINDOW == 6 (0x7f41b04a0400) [pid = 6472] [serial = 77] [outer = 0x7f41b09ed200]
[task 2019-10-30T16:44:25.649Z] 16:44:25 INFO - checking window state
[task 2019-10-30T16:44:25.650Z] 16:44:25 INFO - GECKO(6343) | must wait for focus

[task 2019-10-30T16:44:55.321Z] 16:44:55 INFO - GECKO(6343) | => Process ID: 6472, Thread ID: 139920919299904
[task 2019-10-30T16:44:56.990Z] 16:44:56 INFO - GECKO(6343) | 1572453896978 Marionette TRACE Received observer notification xpcom-will-shutdown
[task 2019-10-30T16:44:56.992Z] 16:44:56 INFO - GECKO(6343) | 1572453896980 Marionette INFO Stopped listening on port 2828
[task 2019-10-30T16:44:56.993Z] 16:44:56 INFO - GECKO(6343) | 1572453896982 Marionette DEBUG Remote service is inactive
[task 2019-10-30T16:45:00.550Z] 16:45:00 INFO - GECKO(6343) | --DOMWINDOW == 11 (0x7fc0d8958f20) [pid = 6343] [serial = 44] [outer = (nil)] [url = chrome://browser/content/browser.xhtml]
[task 2019-10-30T16:45:00.566Z] 16:45:00 INFO - GECKO(6343) | --DOMWINDOW == 10 (0x7fc0bec49800) [pid = 6343] [serial = 45] [outer = (nil)] [url = about:blank]
[task 2019-10-30T16:45:00.568Z] 16:45:00 INFO - GECKO(6343) | --DOMWINDOW == 9 (0x7fc0de6f4400) [pid = 6343] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-10-30T16:45:00.569Z] 16:45:00 INFO - GECKO(6343) | --DOMWINDOW == 8 (0x7fc0e4aa36a0) [pid = 6343] [serial = 1] [outer = (nil)] [url = chrome://browser/content/browser.xhtml]
[task 2019-10-30T16:45:00.570Z] 16:45:00 INFO - GECKO(6343) | --DOMWINDOW == 7 (0x7fc0da4f97a0) [pid = 6343] [serial = 11] [outer = (nil)] [url = chrome://mochikit/content/browser-harness.xul]
[task 2019-10-30T16:45:00.571Z] 16:45:00 INFO - GECKO(6343) | --DOMWINDOW == 6 (0x7fc0da504400) [pid = 6343] [serial = 12] [outer = (nil)] [url = about:blank]
[task 2019-10-30T16:45:00.571Z] 16:45:00 INFO - GECKO(6343) | --DOMWINDOW == 5 (0x7fc0dd0db200) [pid = 6343] [serial = 4] [outer = (nil)] [url = chrome://extensions/content/dummy.xul]
[task 2019-10-30T16:45:00.571Z] 16:45:00 INFO - GECKO(6343) | --DOMWINDOW == 4 (0x7fc0dcc8d800) [pid = 6343] [serial = 6] [outer = (nil)] [url = chrome://extensions/content/dummy.xul]
[task 2019-10-30T16:45:00.572Z] 16:45:00 INFO - GECKO(6343) | --DOMWINDOW == 3 (0x7fc0da4f9020) [pid = 6343] [serial = 8] [outer = (nil)] [url = resource://gre-resources/hiddenWindow.html]
[task 2019-10-30T16:45:00.572Z] 16:45:00 INFO - GECKO(6343) | --DOMWINDOW == 2 (0x7fc0be9c9c00) [pid = 6343] [serial = 59] [outer = (nil)] [url = about:blank]
[task 2019-10-30T16:45:00.572Z] 16:45:00 INFO - GECKO(6343) | --DOMWINDOW == 1 (0x7fc0e4aa3e20) [pid = 6343] [serial = 3] [outer = (nil)] [url = about:blank]
[task 2019-10-30T16:45:00.593Z] 16:45:00 INFO - GECKO(6343) | --DOMWINDOW == 0 (0x7fc0d777b000) [pid = 6343] [serial = 10] [outer = (nil)] [url = resource://gre-resources/hiddenWindow.html]
[task 2019-10-30T16:45:00.810Z] 16:45:00 INFO - GECKO(6343) | nsStringStats
[task 2019-10-30T16:45:00.811Z] 16:45:00 INFO - GECKO(6343) | => mAllocCount: 336143
[task 2019-10-30T16:45:00.811Z] 16:45:00 INFO - GECKO(6343) | => mReallocCount: 2
[task 2019-10-30T16:45:00.811Z] 16:45:00 INFO - GECKO(6343) | => mFreeCount: 336143
[task 2019-10-30T16:45:00.812Z] 16:45:00 INFO - GECKO(6343) | => mShareCount: 390436
[task 2019-10-30T16:45:00.812Z] 16:45:00 INFO - GECKO(6343) | => mAdoptCount: 6579
[task 2019-10-30T16:45:00.812Z] 16:45:00 INFO - GECKO(6343) | => mAdoptFreeCount: 7063
[task 2019-10-30T16:45:00.813Z] 16:45:00 INFO - GECKO(6343) | => Process ID: 6343, Thread ID: 140467174934336
[task 2019-10-30T16:45:01.534Z] 16:45:01 INFO - TEST-INFO | Main app process: exit 0
[task 2019-10-30T16:45:01.536Z] 16:45:01 ERROR - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/browser/browser_ext_themes_ntp_colors_perwindow.js | leaked 1 window(s) until shutdown [url = chrome://browser/content/browser.xhtml]
[task 2019-10-30T16:45:01.536Z] 16:45:01 ERROR - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/browser/browser_ext_themes_ntp_colors_perwindow.js | leaked 1 window(s) until shutdown [url = about:blank]
[task 2019-10-30T16:45:01.536Z] 16:45:01 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_ntp_colors_perwindow.js | windows(s) leaked: [pid = 6343] [serial = 44], [pid = 6343] [serial = 45]
[task 2019-10-30T16:45:01.537Z] 16:45:01 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_ntp_colors_perwindow.js | This test created 1 hidden window(s)
[task 2019-10-30T16:45:01.537Z] 16:45:01 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_ntp_colors_perwindow.js | This test created 1 hidden docshell(s)
[task 2019-10-30T16:45:01.537Z] 16:45:01 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_downloads_referrer.js | This test created 1 hidden window(s)
[task 2019-10-30T16:45:01.538Z] 16:45:01 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_downloads_referrer.js | This test created 1 hidden docshell(s)
[task 2019-10-30T16:45:01.538Z] 16:45:01 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_management_themes.js | This test created 1 hidden window(s)
[task 2019-10-30T16:45:01.539Z] 16:45:01 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_management_themes.js | This test created 1 hidden docshell(s)
[task 2019-10-30T16:45:01.539Z] 16:45:01 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_additional_backgrounds_alignment.js | This test created 1 hidden window(s)
[task 2019-10-30T16:45:01.539Z] 16:45:01 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_additional_backgrounds_alignment.js | This test created 1 hidden docshell(s)

Comment 12

[Rob Wu [:robwu]]

(In reply to Andreea Pavel [:apavel] from comment #11)

@Rob: Failures are manually classified against bugs. We, sheriffs, classify them.

Interesting. Is there a query that I can run to find potentially related test failures, even before they are classified by sheriffs?

Since I'm unable to reproduce locally, I will debug by landing patches in the tree (once I'm back next week).

First thing that I'm going to try is to stop the test from opening extra tabs (to rule it out as being a cause), by skipping most of the logic at https://searchfox.org/mozilla-central/rev/1fe0cf575841dbf3b7e159e88ba03260cd1354c0/toolkit/components/extensions/test/browser/browser_ext_themes_ntp_colors_perwindow.js#170-172

(and also prepend await before https://searchfox.org/mozilla-central/rev/1fe0cf575841dbf3b7e159e88ba03260cd1354c0/toolkit/components/extensions/test/browser/browser_ext_themes_ntp_colors_perwindow.js#194 , just in case)

If that doesn't erase the failures, then I'll disable the theme.update and theme.reset call at https://searchfox.org/mozilla-central/rev/1fe0cf575841dbf3b7e159e88ba03260cd1354c0/toolkit/components/extensions/test/browser/browser_ext_themes_ntp_colors_perwindow.js#149-164

ni? myself to put it back on my list

Comment 13

[Andreea Pavel [:apavel]]

(In reply to Rob Wu [:robwu] from comment #12)

(In reply to Andreea Pavel [:apavel] from comment #11)

@Rob: Failures are manually classified against bugs. We, sheriffs, classify them.

Interesting. Is there a query that I can run to find potentially related test failures, even before they are classified by sheriffs?
No, i don't think there is. You can see the failures just after they are classified as they show up in orange factor here: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-10-24&endday=2019-10-31&tree=trunk&bug=1584391

Since I'm unable to reproduce locally, I will debug by landing patches in the tree (once I'm back next week).
You could try to make the changes you need and push to try but select just the jobs this fails on, such as linux64 debug mochitest-browser-chrome-fis-e10s-4 and retrigger it to see if it shows up.

First thing that I'm going to try is to stop the test from opening extra tabs (to rule it out as being a cause), by skipping most of the logic at https://searchfox.org/mozilla-central/rev/1fe0cf575841dbf3b7e159e88ba03260cd1354c0/toolkit/components/extensions/test/browser/browser_ext_themes_ntp_colors_perwindow.js#170-172

(and also prepend await before https://searchfox.org/mozilla-central/rev/1fe0cf575841dbf3b7e159e88ba03260cd1354c0/toolkit/components/extensions/test/browser/browser_ext_themes_ntp_colors_perwindow.js#194 , just in case)

If that doesn't erase the failures, then I'll disable the theme.update and theme.reset call at https://searchfox.org/mozilla-central/rev/1fe0cf575841dbf3b7e159e88ba03260cd1354c0/toolkit/components/extensions/test/browser/browser_ext_themes_ntp_colors_perwindow.js#149-164

ni? myself to put it back on my list

Answers are inline. Ni Aryx as he might have more to add to help you out.

Comment 14

[Intermittent Failures Robot]

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

This is the #47 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: 27
• try: 5
• mozilla-central: 5
• mozilla-beta: 2

Platform breakdown:

• macosx1014-64: 2
• windows10-64-qr: 9
• linux64: 23
• windows10-64: 4
• linux64-ccov: 1

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

Comment 15

[Andreea Pavel [:apavel]]

There are 39 total failures in the last 7 days on mostly on linux64 debug, and several on windows10-64 and windows10-64-qr debug,

Recent failure log:

[task 2019-11-03T23:05:11.611Z] 23:05:11 INFO - checking window state
[task 2019-11-03T23:05:11.629Z] 23:05:11 INFO - TEST-START | toolkit/components/extensions/test/browser/browser_ext_windows_popup_title.js
[task 2019-11-03T23:05:11.688Z] 23:05:11 INFO - GECKO(10260) | [Parent 9692, Main Thread] WARNING: Need BrowserChild to get the nativeWindow ++DOCSHELL 0000016AAB787800 == 5 [pid = 1132] [id = {a9e8916c-2d64-4131-8dc0-ef2891a9a041}]
[task 2019-11-03T23:05:11.688Z] 23:05:11 INFO - GECKO(10260) | from!: file z:/build/build/src/widget/Pup++DOMWINDOW == 13 (0000016AAA93FB60) [pid = 1132] [serial = 52] [outer = 0000000000000000]
[task 2019-11-03T23:05:11.688Z] 23:05:11 INFO - GECKO(10260) | petWidget.cpp, line 1090
[task 2019-11-03T23:05:11.688Z] 23:05:11 INFO - GECKO(10260) | ++DOMWINDOW == 14 (0000016AAA9A5800) [pid = 1132] [serial = 53] [outer = 0000016AAA93FB60]
[task 2019-11-03T23:05:11.693Z] 23:05:11 INFO - GECKO(10260) | [Child 1132, Main Thread] WARNING: Fallback to BasicLayerManager: file z:/build/build/src/dom/ipc/BrowserChild.cpp, line 2700

[task 2019-11-03T23:05:26.020Z] 23:05:26 INFO - GECKO(10260) | --DOMWINDOW == 3 (000002574FC52020) [pid = 9692] [serial = 10] [outer = 0000000000000000] [url = resource://gre-resources/hiddenWindow.html]
[task 2019-11-03T23:05:26.020Z] 23:05:26 INFO - GECKO(10260) | --DOMWINDOW == 2 (0000025759A7C000) [pid = 9692] [serial = 61] [outer = 0000000000000000] [url = about:blank]
[task 2019-11-03T23:05:26.020Z] 23:05:26 INFO - GECKO(10260) | --DOMWINDOW == 1 (00000257482A14C0) [pid = 9692] [serial = 5] [outer = 0000000000000000] [url = about:blank]
[task 2019-11-03T23:05:26.038Z] 23:05:26 INFO - GECKO(10260) | --DOMWINDOW == 0 (0000025751AA4000) [pid = 9692] [serial = 12] [outer = 0000000000000000] [url = resource://gre-resources/hiddenWindow.html]
[task 2019-11-03T23:05:26.118Z] 23:05:26 INFO - GECKO(10260) | nsStringStats
[task 2019-11-03T23:05:26.118Z] 23:05:26 INFO - GECKO(10260) | => mAllocCount: 316890
[task 2019-11-03T23:05:26.118Z] 23:05:26 INFO - GECKO(10260) | => mReallocCount: 2
[task 2019-11-03T23:05:26.118Z] 23:05:26 INFO - GECKO(10260) | => mFreeCount: 316890
[task 2019-11-03T23:05:26.118Z] 23:05:26 INFO - GECKO(10260) | => mShareCount: 439218
[task 2019-11-03T23:05:26.118Z] 23:05:26 INFO - GECKO(10260) | => mAdoptCount: 6086
[task 2019-11-03T23:05:26.118Z] 23:05:26 INFO - GECKO(10260) | => mAdoptFreeCount: 6566
[task 2019-11-03T23:05:26.119Z] 23:05:26 INFO - GECKO(10260) | => Process ID: 9692, Thread ID: 2376
[task 2019-11-03T23:05:26.198Z] 23:05:26 INFO - TEST-INFO | Main app process: exit 0
[task 2019-11-03T23:05:26.199Z] 23:05:26 ERROR - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/browser/browser_ext_themes_ntp_colors_perwindow.js | leaked 1 window(s) until shutdown [url = chrome://browser/content/browser.xhtml]
[task 2019-11-03T23:05:26.199Z] 23:05:26 ERROR - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/browser/browser_ext_themes_ntp_colors_perwindow.js | leaked 1 window(s) until shutdown [url = about:blank]
[task 2019-11-03T23:05:26.199Z] 23:05:26 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_ntp_colors_perwindow.js | windows(s) leaked: [pid = 9692] [serial = 46], [pid = 9692] [serial = 47]
[task 2019-11-03T23:05:26.200Z] 23:05:26 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_ntp_colors_perwindow.js | This test created 1 hidden window(s)
[task 2019-11-03T23:05:26.200Z] 23:05:26 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_ntp_colors_perwindow.js | This test created 1 hidden docshell(s)
[task 2019-11-03T23:05:26.201Z] 23:05:26 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_downloads_referrer.js | This test created 1 hidden window(s)
[task 2019-11-03T23:05:26.201Z] 23:05:26 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_downloads_referrer.js | This test created 1 hidden docshell(s)
[task 2019-11-03T23:05:26.201Z] 23:05:26 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_management_themes.js | This test created 1 hidden window(s)
[task 2019-11-03T23:05:26.201Z] 23:05:26 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_management_themes.js | This test created 1 hidden docshell(s)
[task 2019-11-03T23:05:26.201Z] 23:05:26 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_additional_backgrounds_alignment.js | This test created 1 hidden window(s)
[task 2019-11-03T23:05:26.201Z] 23:05:26 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_additional_backgrounds_alignment.js | This test created 1 hidden docshell(s)

@Rob any updates?

Comment 16

[Rob Wu [:robwu]]

I'll attach a patch that attempts to tackle the failure from a few angles.
If the leak goes away, I'll revert the chunks one by one until the leak returns.

Comment 17

[Rob Wu [:robwu]]

Attachment: Bug 1584391 - Attempt to debug leak in browser_ext_themes_ntp_colors_perwindow.js

Comment 18

[Intermittent Failures Robot]

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

This is the #44 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:

• try: 4
• autoland: 25
• mozilla-esr68: 1
• mozilla-central: 11

Platform breakdown:

• windows10-64: 4
• windows10-64-qr: 4
• linux64: 18
• macosx1014-64: 3
• linux32: 1
• windows10-64-ccov: 5
• linux64-ccov: 5
• windows7-32: 1

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

Comment 19

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 20
• mozilla-esr68: 1
• try: 3
• mozilla-beta: 1
• mozilla-central: 4

Platform breakdown:

• linux64: 22
• linux64-ccov: 4
• windows10-64-qr: 1
• windows10-64: 2

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

Comment 20

[Oana Pop-Rus]

Over the past week there are 34 failures on this bug. Most of the occurrences can be seen on Linux x64, several on linux64-ccov and windows10-64. All on debug platform.

Recent failure log:
[task 2019-11-20T12:48:06.838Z] 12:48:06 INFO - TEST-START | Shutdown
[task 2019-11-20T12:48:06.838Z] 12:48:06 INFO - Browser Chrome Test Summary
[task 2019-11-20T12:48:06.838Z] 12:48:06 INFO - Passed: 749
[task 2019-11-20T12:48:06.838Z] 12:48:06 INFO - Failed: 0
[task 2019-11-20T12:48:06.841Z] 12:48:06 INFO - Todo: 0
[task 2019-11-20T12:48:06.842Z] 12:48:06 INFO - Mode: e10s
[task 2019-11-20T12:48:06.842Z] 12:48:06 INFO - *** End BrowserChrome Test Results ***
[task 2019-11-20T12:48:07.031Z] 12:48:07 INFO - GECKO(6873) | [Parent 6873, Main Thread] WARNING: '!mIMContext', file /builds/worker/workspace/build/src/widget/gtk/nsWindow.cpp, line 6383
[task 2019-11-20T12:48:07.032Z] 12:48:07 INFO - GECKO(6873) | [Parent 6873, Main Thread] WARNING: '!mIMContext', file /builds/worker/workspace/build/src/widget/gtk/nsWindow.cpp, line 6383
[task 2019-11-20T12:48:07.190Z] 12:48:07 INFO - GECKO(6873) | [Parent 6873, Main Thread] WARNING: NS_ENSURE_TRUE(GetWrapper()) failed: file /builds/worker/workspace/build/src/dom/ipc/JSWindowActor.cpp, line 55
[task 2019-11-20T12:48:07.191Z] 12:48:07 INFO - GECKO(6873) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-11-20T12:48:07.200Z] 12:48:07 INFO - GECKO(6873) | --DOCSHELL 0x7f10e85b9000 == 2 [pid = 6927] [id = {43b3a49d-c1d5-4405-9b22-1833a26fc591}] [url = moz-extension://e8d80ea9-25a4-4380-80c3-c8a233c82cfc/_generated_background_page.html]
[task 2019-11-20T12:48:07.200Z] 12:48:07 INFO - GECKO(6873) | --DOCSHELL 0x7f10e8c92800 == 1 [pid = 6927] [id = {32f5eb20-c267-41eb-b301-b7164aacd9e2}] [url = moz-extension://a3e2c921-3fab-4cdb-ba36-21688ce2f1ed/_generated_background_page.html]
[task 2019-11-20T12:48:07.202Z] 12:48:07 INFO - GECKO(6873) | --DOCSHELL 0x7f10e85b6800 == 0 [pid = 6927] [id = {a4a3de93-7c3b-49e1-be61-c82b0884dfe9}] [url = moz-extension://127fb245-74c7-4981-8184-e105c1bc7061/_generated_background_page.html]
[task 2019-11-20T12:48:07.202Z] 12:48:07 INFO - GECKO(6873) | [Parent 6873, Main Thread] WARNING: A runnable was posted to a worker that is already shutting down!: file /builds/worker/workspace/build/src/dom/workers/WorkerPrivate.cpp, line 1418
[task 2019-11-20T12:48:07.202Z] 12:48:07 INFO - GECKO(6873) | [Parent 6873, Main Thread] WARNING: Failed to dispatch offline status change event!: file /builds/worker/workspace/build/src/dom/workers/WorkerPrivate.cpp, line 1901
[task 2019-11-20T12:48:07.243Z] 12:48:07 INFO - GECKO(6873) | [Parent 6873, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file /builds/worker/workspace/build/src/netwerk/cache/nsCacheService.cpp, line 859
[task 2019-11-20T12:48:07.243Z] 12:48:07 INFO - GECKO(6873) | [Parent 6873, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file /builds/worker/workspace/build/src/netwerk/cache/nsCacheService.cpp, line 822
[task 2019-11-20T12:48:07.243Z] 12:48:07 INFO - GECKO(6873) | [Parent 6873, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file /builds/worker/workspace/build/src/netwerk/cache/nsApplicationCacheService.cpp, line 159
[task 2019-11-20T12:48:07.339Z] 12:48:07 INFO - GECKO(6873) | [2019-11-20T12:48:07Z WARN xulstore::persist] tried to remove key that isn't in the store
[task 2019-11-20T12:48:07.445Z] 12:48:07 INFO - GECKO(6873) | --DOMWINDOW == 5 (0x7f10e8c863e0) [pid = 6927] [serial = 5] [outer = (nil)] [url = moz-extension://e8d80ea9-25a4-4380-80c3-c8a233c82cfc/_generated_background_page.html]
[task 2019-11-20T12:48:07.445Z] 12:48:07 INFO - GECKO(6873) | --DOMWINDOW == 4 (0x7f10e8c876a0) [pid = 6927] [serial = 3] [outer = (nil)] [url = moz-extension://127fb245-74c7-4981-8184-e105c1bc7061/_generated_background_page.html]
[task 2019-11-20T12:48:07.445Z] 12:48:07 INFO - GECKO(6873) | --DOMWINDOW == 3 (0x7f10e8c874c0) [pid = 6927] [serial = 1] [outer = (nil)] [url = moz-extension://a3e2c921-3fab-4cdb-ba36-21688ce2f1ed/_generated_background_page.html]
[task 2019-11-20T12:48:07.445Z] 12:48:07 INFO - GECKO(6873) | --DOMWINDOW == 2 (0x7f10e7b99c00) [pid = 6927] [serial = 9] [outer = (nil)] [url = moz-extension://a3e2c921-3fab-4cdb-ba36-21688ce2f1ed/_generated_background_page.html]
[task 2019-11-20T12:48:07.445Z] 12:48:07 INFO - GECKO(6873) | --DOMWINDOW == 1 (0x7f10e8c67000) [pid = 6927] [serial = 10] [outer = (nil)] [url = moz-extension://127fb245-74c7-4981-8184-e105c1bc7061/generated_background_page.html]
[task 2019-11-20T12:48:07.445Z] 12:48:07 INFO - GECKO(6873) | --DOMWINDOW == 0 (0x7f10e8cbac00) [pid = 6927] [serial = 11] [outer = (nil)] [url = moz-extension://e8d80ea9-25a4-4380-80c3-c8a233c82cfc/generated_background_page.html]
[task 2019-11-20T12:48:07.480Z] 12:48:07 INFO - GECKO(6873) | nsStringStats
[task 2019-11-20T12:48:07.481Z] 12:48:07 INFO - GECKO(6873) | => mAllocCount: 52346
[task 2019-11-20T12:48:07.482Z] 12:48:07 INFO - GECKO(6873) | => mReallocCount: 0
[task 2019-11-20T12:48:07.482Z] 12:48:07 INFO - GECKO(6873) | => mFreeCount: 52346
[task 2019-11-20T12:48:07.482Z] 12:48:07 INFO - GECKO(6873) | => mShareCount: 37619
[task 2019-11-20T12:48:07.483Z] 12:48:07 INFO - GECKO(6873) | => mAdoptCount: 1885
[task 2019-11-20T12:48:07.483Z] 12:48:07 INFO - GECKO(6873) | => mAdoptFreeCount: 1997
[task 2019-11-20T12:48:07.484Z] 12:48:07 INFO - GECKO(6873) | => Process ID: 6927, Thread ID: 139711042635584
[task 2019-11-20T12:48:07.745Z] 12:48:07 INFO - GECKO(6873) | --DOCSHELL 0x7f53c8cc1800 == 4 [pid = 6873] [id = {ac353b2a-d714-4053-8f58-befd738bf79a}] [url = chrome://mochikit/content/browser-harness.xul]
[task 2019-11-20T12:48:07.745Z] 12:48:07 INFO - GECKO(6873) | --DOCSHELL 0x7f53cc9d8000 == 3 [pid = 6873] [id = {b136d909-5662-4fef-9e51-e96a86039569}] [url = chrome://browser/content/browser.xhtml]
[task 2019-11-20T12:48:07.745Z] 12:48:07 INFO - GECKO(6873) | --DOCSHELL 0x7f53cc3ec800 == 2 [pid = 6873] [id = {3b8d0407-fac2-490a-8008-5b076ff2ffd7}] [url = about:blank]
[task 2019-11-20T12:48:07.745Z] 12:48:07 INFO - GECKO(6873) | --DOCSHELL 0x7f53cb081800 == 1 [pid = 6873] [id = {1ce2513b-2a81-4384-bf5f-9a038ccec65d}] [url = chrome://extensions/content/dummy.xul]
[task 2019-11-20T12:48:07.773Z] 12:48:07 INFO - GECKO(6873) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-11-20T12:48:07.808Z] 12:48:07 INFO - GECKO(6873) | --DOCSHELL 0x7f53c8cc8000 == 0 [pid = 6873] [id = {9213063a-1e59-4b8c-861b-1011f3214a94}] [url = resource://gre-resources/hiddenWindow.html]
[task 2019-11-20T12:48:08.140Z] 12:48:08 INFO - GECKO(6873) | nsStringStats
[task 2019-11-20T12:48:08.140Z] 12:48:08 INFO - GECKO(6873) | => mAllocCount: 25091
[task 2019-11-20T12:48:08.140Z] 12:48:08 INFO - GECKO(6873) | => mReallocCount: 0
[task 2019-11-20T12:48:08.140Z] 12:48:08 INFO - GECKO(6873) | => mFreeCount: 25091
[task 2019-11-20T12:48:08.141Z] 12:48:08 INFO - GECKO(6873) | => mShareCount: 18595
[task 2019-11-20T12:48:08.142Z] 12:48:08 INFO - GECKO(6873) | => mAdoptCount: 373
[task 2019-11-20T12:48:08.142Z] 12:48:08 INFO - GECKO(6873) | => mAdoptFreeCount: 373
[task 2019-11-20T12:48:08.143Z] 12:48:08 INFO - GECKO(6873) | => Process ID: 7130, Thread ID: 140164854228800
[task 2019-11-20T12:48:08.144Z] 12:48:08 INFO - GECKO(6873) | nsStringStats
[task 2019-11-20T12:48:08.144Z] 12:48:08 INFO - GECKO(6873) | => mAllocCount: 24876
[task 2019-11-20T12:48:08.145Z] 12:48:08 INFO - GECKO(6873) | => mReallocCount: 0
[task 2019-11-20T12:48:08.146Z] 12:48:08 INFO - GECKO(6873) | => mFreeCount: 24876
[task 2019-11-20T12:48:08.147Z] 12:48:08 INFO - GECKO(6873) | => mShareCount: 18669
[task 2019-11-20T12:48:08.147Z] 12:48:08 INFO - GECKO(6873) | => mAdoptCount: 372
[task 2019-11-20T12:48:08.148Z] 12:48:08 INFO - GECKO(6873) | => mAdoptFreeCount: 372
[task 2019-11-20T12:48:08.148Z] 12:48:08 INFO - GECKO(6873) | => Process ID: 7191, Thread ID: 140416329574208
[task 2019-11-20T12:48:08.151Z] 12:48:08 INFO - GECKO(6873) | --DOCSHELL 0x7f4b3652d800 == 0 [pid = 7036] [id = {6dbf30ca-640e-4dd8-9a36-c6858a53b42b}] [url = about:blank]
[task 2019-11-20T12:48:08.228Z] 12:48:08 INFO - GECKO(6873) | nsStringStats
[task 2019-11-20T12:48:08.229Z] 12:48:08 INFO - GECKO(6873) | => mAllocCount: 24844
[task 2019-11-20T12:48:08.229Z] 12:48:08 INFO - GECKO(6873) | => mReallocCount: 0
[task 2019-11-20T12:48:08.230Z] 12:48:08 INFO - GECKO(6873) | => mFreeCount: 24844
[task 2019-11-20T12:48:08.230Z] 12:48:08 INFO - GECKO(6873) | => mShareCount: 18645
[task 2019-11-20T12:48:08.231Z] 12:48:08 INFO - GECKO(6873) | => mAdoptCount: 372
[task 2019-11-20T12:48:08.232Z] 12:48:08 INFO - GECKO(6873) | => mAdoptFreeCount: 372
[task 2019-11-20T12:48:08.232Z] 12:48:08 INFO - GECKO(6873) | => Process ID: 7150, Thread ID: 140396921304896
[task 2019-11-20T12:48:08.297Z] 12:48:08 INFO - GECKO(6873) | nsStringStats
[task 2019-11-20T12:48:08.298Z] 12:48:08 INFO - GECKO(6873) | => mAllocCount: 46520
[task 2019-11-20T12:48:08.299Z] 12:48:08 INFO - GECKO(6873) | => mReallocCount: 0
[task 2019-11-20T12:48:08.299Z] 12:48:08 INFO - GECKO(6873) | => mFreeCount: 46520
[task 2019-11-20T12:48:08.300Z] 12:48:08 INFO - GECKO(6873) | => mShareCount: 77884
[task 2019-11-20T12:48:08.300Z] 12:48:08 INFO - GECKO(6873) | => mAdoptCount: 1119
[task 2019-11-20T12:48:08.300Z] 12:48:08 INFO - GECKO(6873) | => mAdoptFreeCount: 1131
[task 2019-11-20T12:48:08.301Z] 12:48:08 INFO - GECKO(6873) | => Process ID: 7007, Thread ID: 140608898950976
[task 2019-11-20T12:48:08.307Z] 12:48:08 INFO - GECKO(6873) | nsStringStats
[task 2019-11-20T12:48:08.308Z] 12:48:08 INFO - GECKO(6873) | => mAllocCount: 41150
[task 2019-11-20T12:48:08.308Z] 12:48:08 INFO - GECKO(6873) | => mReallocCount: 0
[task 2019-11-20T12:48:08.309Z] 12:48:08 INFO - GECKO(6873) | => mFreeCount: 41150
[task 2019-11-20T12:48:08.309Z] 12:48:08 INFO - GECKO(6873) | => mShareCount: 80803
[task 2019-11-20T12:48:08.309Z] 12:48:08 INFO - GECKO(6873) | => mAdoptCount: 1129
[task 2019-11-20T12:48:08.310Z] 12:48:08 INFO - GECKO(6873) | => mAdoptFreeCount: 1157
[task 2019-11-20T12:48:08.310Z] 12:48:08 INFO - GECKO(6873) | => Process ID: 7110, Thread ID: 140385874585408
[task 2019-11-20T12:48:08.336Z] 12:48:08 INFO - GECKO(6873) | nsStringStats
[task 2019-11-20T12:48:08.337Z] 12:48:08 INFO - GECKO(6873) | => mAllocCount: 44209
[task 2019-11-20T12:48:08.337Z] 12:48:08 INFO - GECKO(6873) | => mReallocCount: 0
[task 2019-11-20T12:48:08.338Z] 12:48:08 INFO - GECKO(6873) | => mFreeCount: 44209
[task 2019-11-20T12:48:08.339Z] 12:48:08 INFO - GECKO(6873) | => mShareCount: 60929
[task 2019-11-20T12:48:08.339Z] 12:48:08 INFO - GECKO(6873) | => mAdoptCount: 1053
[task 2019-11-20T12:48:08.339Z] 12:48:08 INFO - GECKO(6873) | => mAdoptFreeCount: 1061
[task 2019-11-20T12:48:08.340Z] 12:48:08 INFO - GECKO(6873) | => Process ID: 6948, Thread ID: 140437006538560
[task 2019-11-20T12:48:08.345Z] 12:48:08 INFO - GECKO(6873) | nsStringStats
[task 2019-11-20T12:48:08.346Z] 12:48:08 INFO - GECKO(6873) | => mAllocCount: 63803
[task 2019-11-20T12:48:08.346Z] 12:48:08 INFO - GECKO(6873) | => mReallocCount: 0
[task 2019-11-20T12:48:08.347Z] 12:48:08 INFO - GECKO(6873) | => mFreeCount: 63803
[task 2019-11-20T12:48:08.348Z] 12:48:08 INFO - GECKO(6873) | => mShareCount: 173783
[task 2019-11-20T12:48:08.348Z] 12:48:08 INFO - GECKO(6873) | => mAdoptCount: 1770
[task 2019-11-20T12:48:08.348Z] 12:48:08 INFO - GECKO(6873) | => mAdoptFreeCount: 1830
[task 2019-11-20T12:48:08.348Z] 12:48:08 INFO - GECKO(6873) | => Process ID: 7090, Thread ID: 140478892689216
[task 2019-11-20T12:48:08.349Z] 12:48:08 INFO - GECKO(6873) | --DOMWINDOW == 1 (0x7f4b3490c6a0) [pid = 7036] [serial = 70] [outer = (nil)] [url = about:blank]
[task 2019-11-20T12:48:08.351Z] 12:48:08 INFO - GECKO(6873) | --DOMWINDOW == 0 (0x7f4b36339000) [pid = 7036] [serial = 71] [outer = (nil)] [url = about:blank]
[task 2019-11-20T12:48:08.399Z] 12:48:08 INFO - GECKO(6873) | nsStringStats
[task 2019-11-20T12:48:08.399Z] 12:48:08 INFO - GECKO(6873) | => mAllocCount: 49115
[task 2019-11-20T12:48:08.400Z] 12:48:08 INFO - GECKO(6873) | => mReallocCount: 0
[task 2019-11-20T12:48:08.400Z] 12:48:08 INFO - GECKO(6873) | => mFreeCount: 49115
[task 2019-11-20T12:48:08.401Z] 12:48:08 INFO - GECKO(6873) | => mShareCount: 83992
[task 2019-11-20T12:48:08.401Z] 12:48:08 INFO - GECKO(6873) | => mAdoptCount: 1720
[task 2019-11-20T12:48:08.402Z] 12:48:08 INFO - GECKO(6873) | => mAdoptFreeCount: 1740
[task 2019-11-20T12:48:08.402Z] 12:48:08 INFO - GECKO(6873) | => Process ID: 7036, Thread ID: 139961513998144
[task 2019-11-20T12:48:08.602Z] 12:48:08 INFO - GECKO(6873) | 1574254088600 Marionette TRACE Received observer notification xpcom-will-shutdown
[task 2019-11-20T12:48:08.602Z] 12:48:08 INFO - GECKO(6873) | 1574254088600 Marionette INFO Stopped listening on port 2828
[task 2019-11-20T12:48:08.603Z] 12:48:08 INFO - GECKO(6873) | 1574254088600 Marionette DEBUG Remote service is inactive
[task 2019-11-20T12:48:10.145Z] 12:48:10 INFO - GECKO(6873) | --DOMWINDOW == 11 (0x7f53cc9adc00) [pid = 6873] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-11-20T12:48:10.147Z] 12:48:10 INFO - GECKO(6873) | --DOMWINDOW == 10 (0x7f53d329e100) [pid = 6873] [serial = 1] [outer = (nil)] [url = chrome://browser/content/browser.xhtml]
[task 2019-11-20T12:48:10.148Z] 12:48:10 INFO - GECKO(6873) | --DOMWINDOW == 9 (0x7f53cadace20) [pid = 6873] [serial = 11] [outer = (nil)] [url = chrome://mochikit/content/browser-harness.xul]
[task 2019-11-20T12:48:10.148Z] 12:48:10 INFO - GECKO(6873) | --DOMWINDOW == 8 (0x7f53c3bcec00) [pid = 6873] [serial = 12] [outer = (nil)] [url = about:blank]
[task 2019-11-20T12:48:10.150Z] 12:48:10 INFO - GECKO(6873) | --DOMWINDOW == 7 (0x7f53d329ea60) [pid = 6873] [serial = 4] [outer = (nil)] [url = chrome://extensions/content/dummy.xul]
[task 2019-11-20T12:48:10.151Z] 12:48:10 INFO - GECKO(6873) | --DOMWINDOW == 6 (0x7f53cad11000) [pid = 6873] [serial = 6] [outer = (nil)] [url = chrome://extensions/content/dummy.xul]
[task 2019-11-20T12:48:10.151Z] 12:48:10 INFO - GECKO(6873) | --DOMWINDOW == 5 (0x7f53c08ec5c0) [pid = 6873] [serial = 44] [outer = (nil)] [url = chrome://browser/content/browser.xhtml]
[task 2019-11-20T12:48:10.152Z] 12:48:10 INFO - GECKO(6873) | --DOMWINDOW == 4 (0x7f53c8b42880) [pid = 6873] [serial = 8] [outer = (nil)] [url = resource://gre-resources/hiddenWindow.html]
[task 2019-11-20T12:48:10.153Z] 12:48:10 INFO - GECKO(6873) | --DOMWINDOW == 3 (0x7f53d329e880) [pid = 6873] [serial = 3] [outer = (nil)] [url = about:blank]
[task 2019-11-20T12:48:10.153Z] 12:48:10 INFO - GECKO(6873) | --DOMWINDOW == 2 (0x7f53bfef6800) [pid = 6873] [serial = 45] [outer = (nil)] [url = about:blank]
[task 2019-11-20T12:48:10.153Z] 12:48:10 INFO - GECKO(6873) | --DOMWINDOW == 1 (0x7f53a6c9cc00) [pid = 6873] [serial = 59] [outer = (nil)] [url = about:blank]
[task 2019-11-20T12:48:10.169Z] 12:48:10 INFO - GECKO(6873) | --DOMWINDOW == 0 (0x7f53c837d400) [pid = 6873] [serial = 10] [outer = (nil)] [url = resource://gre-resources/hiddenWindow.html]
[task 2019-11-20T12:48:10.230Z] 12:48:10 INFO - GECKO(6873) | nsStringStats
[task 2019-11-20T12:48:10.231Z] 12:48:10 INFO - GECKO(6873) | => mAllocCount: 360876
[task 2019-11-20T12:48:10.232Z] 12:48:10 INFO - GECKO(6873) | => mReallocCount: 2
[task 2019-11-20T12:48:10.232Z] 12:48:10 INFO - GECKO(6873) | => mFreeCount: 360876
[task 2019-11-20T12:48:10.232Z] 12:48:10 INFO - GECKO(6873) | => mShareCount: 424023
[task 2019-11-20T12:48:10.232Z] 12:48:10 INFO - GECKO(6873) | => mAdoptCount: 6441
[task 2019-11-20T12:48:10.233Z] 12:48:10 INFO - GECKO(6873) | => mAdoptFreeCount: 6933
[task 2019-11-20T12:48:10.233Z] 12:48:10 INFO - GECKO(6873) | => Process ID: 6873, Thread ID: 139998461937472
[task 2019-11-20T12:48:10.279Z] 12:48:10 INFO - TEST-INFO | Main app process: exit 0
[task 2019-11-20T12:48:10.280Z] 12:48:10 ERROR - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/browser/browser_ext_themes_ntp_colors_perwindow.js | leaked 1 window(s) until shutdown [url = chrome://browser/content/browser.xhtml]
[task 2019-11-20T12:48:10.280Z] 12:48:10 ERROR - TEST-UNEXPECTED-FAIL | toolkit/components/extensions/test/browser/browser_ext_themes_ntp_colors_perwindow.js | leaked 1 window(s) until shutdown [url = about:blank]
[task 2019-11-20T12:48:10.280Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_ntp_colors_perwindow.js | windows(s) leaked: [pid = 6873] [serial = 44], [pid = 6873] [serial = 45]
[task 2019-11-20T12:48:10.280Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_ntp_colors_perwindow.js | This test created 1 hidden window(s)
[task 2019-11-20T12:48:10.281Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_ntp_colors_perwindow.js | This test created 1 hidden docshell(s)
[task 2019-11-20T12:48:10.281Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_downloads_referrer.js | This test created 1 hidden window(s)
[task 2019-11-20T12:48:10.281Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_downloads_referrer.js | This test created 1 hidden docshell(s)
[task 2019-11-20T12:48:10.282Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_management_themes.js | This test created 1 hidden window(s)
[task 2019-11-20T12:48:10.283Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_management_themes.js | This test created 1 hidden docshell(s)
[task 2019-11-20T12:48:10.284Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_additional_backgrounds_alignment.js | This test created 1 hidden window(s)
[task 2019-11-20T12:48:10.284Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_additional_backgrounds_alignment.js | This test created 1 hidden docshell(s)
[task 2019-11-20T12:48:10.285Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_alpha_accentcolor.js | This test created 1 hidden window(s)
[task 2019-11-20T12:48:10.285Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_alpha_accentcolor.js | This test created 1 hidden docshell(s)
[task 2019-11-20T12:48:10.287Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_arrowpanels.js | This test created 1 hidden window(s)
[task 2019-11-20T12:48:10.293Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_arrowpanels.js | This test created 1 hidden docshell(s)
[task 2019-11-20T12:48:10.295Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_autocomplete_popup.js | This test created 1 hidden window(s)
[task 2019-11-20T12:48:10.295Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_autocomplete_popup.js | This test created 1 hidden docshell(s)
[task 2019-11-20T12:48:10.295Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_chromeparity.js | This test created 1 hidden window(s)
[task 2019-11-20T12:48:10.295Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_chromeparity.js | This test created 1 hidden docshell(s)
[task 2019-11-20T12:48:10.295Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_dynamic_getCurrent.js | This test created 1 hidden window(s)
[task 2019-11-20T12:48:10.299Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_dynamic_getCurrent.js | This test created 1 hidden docshell(s)
[task 2019-11-20T12:48:10.299Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_dynamic_onUpdated.js | This test created 1 hidden window(s)
[task 2019-11-20T12:48:10.300Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_dynamic_onUpdated.js | This test created 1 hidden docshell(s)
[task 2019-11-20T12:48:10.300Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_dynamic_updates.js | This test created 1 hidden window(s)
[task 2019-11-20T12:48:10.302Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_dynamic_updates.js | This test created 1 hidden docshell(s)
[task 2019-11-20T12:48:10.302Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_experiment.js | This test created 1 hidden window(s)
[task 2019-11-20T12:48:10.303Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_experiment.js | This test created 1 hidden docshell(s)
[task 2019-11-20T12:48:10.303Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_getCurrent_differentExt.js | This test created 1 hidden window(s)
[task 2019-11-20T12:48:10.303Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_getCurrent_differentExt.js | This test created 1 hidden docshell(s)
[task 2019-11-20T12:48:10.304Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_incognito.js | This test created 1 hidden window(s)
[task 2019-11-20T12:48:10.305Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_incognito.js | This test created 1 hidden docshell(s)
[task 2019-11-20T12:48:10.305Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_ntp_colors.js | This test created 1 hidden window(s)
[task 2019-11-20T12:48:10.305Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_ntp_colors.js | This test created 1 hidden docshell(s)
[task 2019-11-20T12:48:10.306Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_persistence.js | This test created 1 hidden window(s)
[task 2019-11-20T12:48:10.306Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_persistence.js | This test created 1 hidden docshell(s)
[task 2019-11-20T12:48:10.307Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_sidebars.js | This test created 1 hidden window(s)
[task 2019-11-20T12:48:10.307Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_sidebars.js | This test created 1 hidden docshell(s)
[task 2019-11-20T12:48:10.307Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_static_onUpdated.js | This test created 1 hidden window(s)
[task 2019-11-20T12:48:10.308Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_static_onUpdated.js | This test created 1 hidden docshell(s)
[task 2019-11-20T12:48:10.309Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_tab_selected.js | This test created 1 hidden window(s)
[task 2019-11-20T12:48:10.310Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_tab_selected.js | This test created 1 hidden docshell(s)
[task 2019-11-20T12:48:10.310Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_tab_separators.js | This test created 1 hidden window(s)
[task 2019-11-20T12:48:10.311Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_tab_separators.js | This test created 1 hidden docshell(s)
[task 2019-11-20T12:48:10.312Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_warnings.js | This test created 1 hidden window(s)
[task 2019-11-20T12:48:10.313Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_themes_warnings.js | This test created 1 hidden docshell(s)
[task 2019-11-20T12:48:10.313Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_windows_popup_title.js | This test created 1 hidden window(s)
[task 2019-11-20T12:48:10.314Z] 12:48:10 INFO - TEST-INFO | toolkit/components/extensions/test/browser/browser_ext_windows_popup_title.js | This test created 1 hidden docshell(s)
[task 2019-11-20T12:48:10.314Z] 12:48:10 INFO - runtests.py | Application ran for: 0:01:36.179728
[task 2019-11-20T12:48:10.314Z] 12:48:10 INFO - zombiecheck | Reading PID log: /tmp/tmpD9U7vApidlog
[task 2019-11-20T12:48:10.314Z] 12:48:10 INFO - ==> process 6873 launched child process 6891
[task 2019-11-20T12:48:10.314Z] 12:48:10 INFO - ==> process 6873 launched child process 6927
[task 2019-11-20T12:48:10.314Z] 12:48:10 INFO - ==> process 6873 launched child process 6948
[task 2019-11-20T12:48:10.314Z] 12:48:10 INFO - ==> process 6873 launched child process 7007
[task 2019-11-20T12:48:10.314Z] 12:48:10 INFO - ==> process 6873 launched child process 7036
[task 2019-11-20T12:48:10.315Z] 12:48:10 INFO - ==> process 6873 launched child process 7051
[task 2019-11-20T12:48:10.315Z] 12:48:10 INFO - ==> process 6873 launched child process 7090
[task 2019-11-20T12:48:10.315Z] 12:48:10 INFO - ==> process 6873 launched child process 7110
[task 2019-11-20T12:48:10.315Z] 12:48:10 INFO - ==> process 6873 launched child process 7130
[task 2019-11-20T12:48:10.315Z] 12:48:10 INFO - ==> process 6873 launched child process 7150
[task 2019-11-20T12:48:10.315Z] 12:48:10 INFO - ==> process 6873 launched child process 7164
[task 2019-11-20T12:48:10.315Z] 12:48:10 INFO - ==> process 6873 launched child process 7191
[task 2019-11-20T12:48:10.315Z] 12:48:10 INFO - zombiecheck | Checking for orphan process with PID: 6891
[task 2019-11-20T12:48:10.315Z] 12:48:10 INFO - zombiecheck | Checking for orphan process with PID: 6948
[task 2019-11-20T12:48:10.315Z] 12:48:10 INFO - zombiecheck | Checking for orphan process with PID: 7110
[task 2019-11-20T12:48:10.315Z] 12:48:10 INFO - zombiecheck | Checking for orphan process with PID: 7164
[task 2019-11-20T12:48:10.315Z] 12:48:10 INFO - zombiecheck | Checking for orphan process with PID: 7051
[task 2019-11-20T12:48:10.315Z] 12:48:10 INFO - zombiecheck | Checking for orphan process with PID: 7150
[task 2019-11-20T12:48:10.315Z] 12:48:10 INFO - zombiecheck | Checking for orphan process with PID: 6927
[task 2019-11-20T12:48:10.317Z] 12:48:10 INFO - zombiecheck | Checking for orphan process with PID: 7090
[task 2019-11-20T12:48:10.317Z] 12:48:10 INFO - zombiecheck | Checking for orphan process with PID: 7191
[task 2019-11-20T12:48:10.318Z] 12:48:10 INFO - zombiecheck | Checking for orphan process with PID: 7130
[task 2019-11-20T12:48:10.319Z] 12:48:10 INFO - zombiecheck | Checking for orphan process with PID: 7036
[task 2019-11-20T12:48:10.320Z] 12:48:10 INFO - zombiecheck | Checking for orphan process with PID: 7007
[task 2019-11-20T12:48:10.320Z] 12:48:10 INFO - Stopping web server
[task 2019-11-20T12:48:10.320Z] 12:48:10 INFO - Stopping web socket server
[task 2019-11-20T12:48:10.320Z] 12:48:10 INFO - Stopping ssltunnel
[task 2019-11-20T12:48:10.340Z] 12:48:10 INFO - leakcheck | Processing log file /tmp/tmpfm6TZ.mozrunner/runtests_leaks.log
[task 2019-11-20T12:48:10.341Z] 12:48:10 INFO - TEST-INFO | leakcheck | default process: leak threshold set at 0 bytes
[task 2019-11-20T12:48:10.341Z] 12:48:10 INFO - TEST-INFO | leakcheck | plugin process: leak threshold set at 0 bytes
[task 2019-11-20T12:48:10.342Z] 12:48:10 INFO - TEST-INFO | leakcheck | tab process: leak threshold set at 0 bytes
[task 2019-11-20T12:48:10.342Z] 12:48:10 INFO - TEST-INFO | leakcheck | gmplugin process: leak threshold set at 20000 bytes
[task 2019-11-20T12:48:10.343Z] 12:48:10 INFO - TEST-INFO | leakcheck | gpu process: leak threshold set at 0 bytes
[task 2019-11-20T12:48:10.343Z] 12:48:10 INFO - TEST-INFO | leakcheck | rdd process: leak threshold set at 400 bytes
[task 2019-11-20T12:48:10.344Z] 12:48:10 INFO - TEST-INFO | leakcheck | vr process: leak threshold set at 0 bytes
[task 2019-11-20T12:48:10.344Z] 12:48:10 INFO - TEST-INFO | leakcheck | socket process: leak threshold set at 0 bytes
[task 2019-11-20T12:48:10.345Z] 12:48:10 INFO - leakcheck | Processing leak log file /tmp/tmpfm6TZ.mozrunner/runtests_leaks_tab_pid6948.log
[task 2019-11-20T12:48:10.345Z] 12:48:10 INFO -
[task 2019-11-20T12:48:10.345Z] 12:48:10 INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 6948
[task 2019-11-20T12:48:10.346Z] 12:48:10 INFO -
[task 2019-11-20T12:48:10.346Z] 12:48:10 INFO - |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2019-11-20T12:48:10.347Z] 12:48:10 INFO - | | Per-Inst Leaked| Total Rem|
[task 2019-11-20T12:48:10.347Z] 12:48:10 INFO - 0 |TOTAL | 30 0| 959243 0|
[task 2019-11-20T12:48:10.347Z] 12:48:10 INFO -
[task 2019-11-20T12:48:10.348Z] 12:48:10 INFO - nsTraceRefcnt::DumpStatistics: 1050 entries

Comment 21

[Rob Wu [:robwu]]

(going to land patch to see if the leak goes away)

Comment 22

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/b9cf0123bc9b
Attempt to debug leak in browser_ext_themes_ntp_colors_perwindow.js r=rpl

Comment 23

[Andreea Pavel [:apavel]]

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

Comment 24

[Andreea Pavel [:apavel]]

Rob do we still leave this open or close it as fixed?

Comment 25

[Intermittent Failures Robot]

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

This is the #45 most frequent failure this week.

Repository breakdown:

• try: 2
• mozilla-esr68: 1
• autoland: 22
• mozilla-central: 3
• mozilla-inbound: 1

Platform breakdown:

• linux64: 22
• linux32: 1
• linux64-ccov: 1
• windows10-64-qr: 3
• windows10-64: 1
• windows10-64-ccov: 1

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

Comment 26

[Rob Wu [:robwu]]

Let's keep this bug open.

The patch has three parts that may potentially have contributed to the fix. I'm going to partially revert the patch (clean up), and by doing so the bug may regress again (and I would know that by the intermittent failure reports in this bug).

Comment 27

[Rob Wu [:robwu]]

Attachment: Bug 1584391 - Re-enable test logic and remove debugging code

Comment 28

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/3cd2d971dee5
Re-enable test logic and remove debugging code r=rpl

Comment 29

[Stefan Hindli [:stefan_hindli]]

https://hg.mozilla.org/mozilla-central/rev/3cd2d971dee5

Comment 30

[Rob Wu [:robwu]]

Sadly, the test failures returned: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-11-19&endday=2019-11-26&tree=all&bug=1584391

So merely opening tabs in new windows sometimes causes that new window to leak at the end of the test.

When I landed the patch, the try push had a TV failure on Linux debug. That looks promising, it means that I can debug by pushing to try instead of to m-c.

Comment 31

[Dimi Lee [:dimi]]

Attachment: Bug 1584931 - P1. Fix flashblock testcase failures when fission is enabled.

Although we decided to disable flashblock when fission is enabled, we
still need to update testcases so they can run normally in fission mode.

Comment 32

[Dimi Lee [:dimi]]

Attachment: Bug 1584391 - P2. Disable flashblock when fission is enabled.

This patch does the following:

1. Disable flashblock when fission is enabled.
2. Update flashblock tests to expect "unknown" classification when fission is
   enabled.
3. Remove skip-if=fission in flashblock mochitests.

Depends on D51098

Comment 33

[Dimi Lee [:dimi]]

Attachment: Bug 1584391 - P3. Hide the flashblock checkbox when fission is enabled.

Depends on D55091

Comment 34

[Rob Wu [:robwu]]

Dimi, I think that you made a typo in your bug number.
You probably meant bug 1584931 (3 and 9 exchanged).

Comment 35

[Phabricator Automation]

Comment on attachment 9112251 [details]
Bug 1584931 - P1. Fix flashblock testcase failures when fission is enabled.

Revision D51098 was moved to bug 1584931. Setting attachment 9112251 [details] to obsolete.

Comment 36

[Phabricator Automation]

Comment on attachment 9112252 [details]
Bug 1584391 - P2. Disable flashblock when fission is enabled.

Revision D55091 was moved to bug 1584931. Setting attachment 9112252 [details] to obsolete.

Comment 37

[Phabricator Automation]

Comment on attachment 9112253 [details]
Bug 1584391 - P3. Hide the flashblock checkbox when fission is enabled.

Revision D55092 was moved to bug 1584931. Setting attachment 9112253 [details] to obsolete.

Comment 38

[Dimi Lee [:dimi]]

(In reply to Rob Wu [:robwu] from comment #34)

Dimi, I think that you made a typo in your bug number.
You probably meant bug 1584931 (3 and 9 exchanged).

right, super sorry!

Comment 39

[Rob Wu [:robwu]]

Attachment: Bug 1584391 - Fix intermittent leak in browser_ext_themes_ntp_colors_perwindow.js

From extensive testing, it appears that the test fails (also on TV)
when one of the home pages is opened. This did not happen with
"about:robots". Apparently, a browser window leak can be observed if the
test starts at a homepage and opens another homepage tab in the test.

This patch works around the issue by initializing the window with about:blank.

Comment 40

[Rob Wu [:robwu]]

Attachment: Bug 1584391 - Revert last trace of debugging

Comment 41

[Rob Wu [:robwu]]

I believe that the patch at comment 39 fully fixes this bug.

Here is the green try run: https://treeherder.mozilla.org/#/jobs?repo=try&revision=19d33a1cfc436eb67f58d0bac22fea95fe134cf4
For comparison, I have had other try runs with <10 repetitions of TV jobs that had a couple of failures before I found a working patch.

The patch in comment 39 can be uplifted to ESR if needed.

Comment 42

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/b15294b60211
Fix intermittent leak in browser_ext_themes_ntp_colors_perwindow.js r=rpl
https://hg.mozilla.org/integration/autoland/rev/40a5321ec174
Revert last trace of debugging r=rpl

Comment 43

[Raul Gurzau (:RaulG)]

https://hg.mozilla.org/mozilla-central/rev/b15294b60211
https://hg.mozilla.org/mozilla-central/rev/40a5321ec174

Comment 44

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 10

Platform breakdown:

• linux64: 7
• windows10-64: 1
• macosx1014-64: 1
• windows10-64-qr: 1

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

Comment 45

[Rob Wu [:robwu]]

No more failures after the patch landed. I'm going to request uplifts.

Thanks for your patience Andreea.

Comment 46

[Rob Wu [:robwu]]

Comment on attachment 9112277 [details]
Bug 1584391 - Fix intermittent leak in browser_ext_themes_ntp_colors_perwindow.js

ESR Uplift Approval Request

• If this is not a sec:{high,crit} bug, please state case for ESR consideration: Fixes an intermittent test failure.
• User impact if declined: Intermittent test failure of test in debug builds.
• Fix Landed on Version: 72
• Risk to taking this patch: Low
• Why is the change risky/not risky? (and alternatives if risky): test-only change, verified with test-verify (TV) on try ( see comment 41 ), and fixed on m-c ( see comment 45 ).
• String or UUID changes made by this patch: none

Beta/Release Uplift Approval Request

• User impact if declined: Intermittent test failure of test in debug builds.
• Is this code covered by automated tests?: Yes
• Has the fix been verified in Nightly?: Yes
• Needs manual test from QE?: No
• If yes, steps to reproduce:
• List of other uplifts needed: None
• Risk to taking this patch: Low
• Why is the change risky/not risky? (and alternatives if risky): test-only change, verified with test-verify (TV) on try ( see comment 41 ), and fixed on m-c ( see comment 45 ).
• String changes made/needed: none

Beta/Release Uplift Approval Request

• User impact if declined: Intermittent test failure of test in debug builds.
• Is this code covered by automated tests?: Yes
• Has the fix been verified in Nightly?: No
• Needs manual test from QE?: No
• If yes, steps to reproduce: -
• List of other uplifts needed: -
• Risk to taking this patch: Low
• Why is the change risky/not risky? (and alternatives if risky): test-only change, verified with test-verify (TV) on try ( see comment 41 ), and fixed on m-c ( see comment 45 ).
• String changes made/needed: -

ESR Uplift Approval Request

• If this is not a sec:{high,crit} bug, please state case for ESR consideration: Fixes an intermittent test failure.
• User impact if declined: Intermittent test failure of test in debug builds.
• Fix Landed on Version: 72
• Risk to taking this patch: Low
• Why is the change risky/not risky? (and alternatives if risky): test-only change, verified with test-verify (TV) on try ( see comment 41 ), and fixed on m-c ( see comment 45 ).
• String or UUID changes made by this patch: -

Comment 47

[Andreea Pavel [:apavel]]

Thank you for fixing this!

Comment 48

[Ryan VanderMeulen [:RyanVM]]

Comment on attachment 9112277 [details]
Bug 1584391 - Fix intermittent leak in browser_ext_themes_ntp_colors_perwindow.js

I don't think we need to worry about landing this on mozilla-release for 71 at this point, but we can just land it a=test-only on ESR68.

Comment 49

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-esr68/rev/73b5825f32b5