Open Bug 1394671 Opened 7 years ago Updated 2 years ago

Intermittent dom/indexedDB/test/browser_perwindow_privateBrowsing.js | leaked 2 window(s) until shutdown [url = about:privatebrowsing]

Categories

(Core :: Storage: IndexedDB, defect, P2)

Product:
Core
Component:
Storage: IndexedDB
Type:
defect

Tracking

()

Tracking Flags:
Tracking Status
firefox58 --- disabled
firefox59 --- disabled

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure, leave-open, Whiteboard: [stockwell disabled]DWS_NEXT) 

In the last 7 days there have been 37 failures. 
Most of the failures occur on the Linux x64 and linux64-stylo-disabled platforms and also there are some that occur on the Linux and linux32-stylo-disabled.
The failures occur only on the debug build.

Here is an example of a recent log: https://treeherder.mozilla.org/logviewer.html#?repo=autoland&job_id=139734252&lineNumber=6206 

And a relevant snippet of the log:

[task 2017-10-26T04:21:01.278Z] 04:21:01     INFO - GECKO(2045) | nsStringStats
6198
[task 2017-10-26T04:21:01.280Z] 04:21:01     INFO - GECKO(2045) |  => mAllocCount:         172906
6199
[task 2017-10-26T04:21:01.281Z] 04:21:01     INFO - GECKO(2045) |  => mReallocCount:        16417
6200
[task 2017-10-26T04:21:01.282Z] 04:21:01     INFO - GECKO(2045) |  => mFreeCount:          172906
6201
[task 2017-10-26T04:21:01.283Z] 04:21:01     INFO - GECKO(2045) |  => mShareCount:         211872
6202
[task 2017-10-26T04:21:01.284Z] 04:21:01     INFO - GECKO(2045) |  => mAdoptCount:           5459
6203
[task 2017-10-26T04:21:01.284Z] 04:21:01     INFO - GECKO(2045) |  => mAdoptFreeCount:       5459
6204
[task 2017-10-26T04:21:01.285Z] 04:21:01     INFO - GECKO(2045) |  => Process ID: 2045, Thread ID: 140039160452928
6205
[task 2017-10-26T04:21:01.321Z] 04:21:01     INFO - TEST-INFO | Main app process: exit 0
6206
[task 2017-10-26T04:21:01.326Z] 04:21:01    ERROR - TEST-UNEXPECTED-FAIL | dom/indexedDB/test/browser_perwindow_privateBrowsing.js | leaked 2 window(s) until shutdown [url = about:privatebrowsing]
6207
[task 2017-10-26T04:21:01.327Z] 04:21:01     INFO - TEST-INFO | dom/indexedDB/test/browser_perwindow_privateBrowsing.js | windows(s) leaked: [pid = 2098] [serial = 11], [pid = 2098] [serial = 13]
6208
[task 2017-10-26T04:21:01.328Z] 04:21:01     INFO - runtests.py | Application ran for: 0:00:49.144118
6209
[task 2017-10-26T04:21:01.329Z] 04:21:01     INFO - zombiecheck | Reading PID log: /tmp/tmpOYN9_9pidlog
6210
[task 2017-10-26T04:21:01.330Z] 04:21:01     INFO - ==> process 2045 launched child process 2068
6211
[task 2017-10-26T04:21:01.334Z] 04:21:01     INFO - ==> process 2045 launched child process 2098
6212
[task 2017-10-26T04:21:01.339Z] 04:21:01     INFO - ==> process 2045 launched child process 2149
6213
[task 2017-10-26T04:21:01.340Z] 04:21:01     INFO - ==> process 2045 launched child process 2175
6214
[task 2017-10-26T04:21:01.341Z] 04:21:01     INFO - ==> process 2045 launched child process 2188
6215
[task 2017-10-26T04:21:01.342Z] 04:21:01     INFO - ==> process 2045 launched child process 2234
6216
[task 2017-10-26T04:21:01.342Z] 04:21:01     INFO - zombiecheck | Checking for orphan process with PID: 2068
6217
[task 2017-10-26T04:21:01.343Z] 04:21:01     INFO - zombiecheck | Checking for orphan process with PID: 2098
6218
[task 2017-10-26T04:21:01.344Z] 04:21:01     INFO - zombiecheck | Checking for orphan process with PID: 2149
6219
[task 2017-10-26T04:21:01.345Z] 04:21:01     INFO - zombiecheck | Checking for orphan process with PID: 2175
6220
[task 2017-10-26T04:21:01.346Z] 04:21:01     INFO - zombiecheck | Checking for orphan process with PID: 2188
6221
[task 2017-10-26T04:21:01.347Z] 04:21:01     INFO - zombiecheck | Checking for orphan process with PID: 2234
6222
[task 2017-10-26T04:21:01.348Z] 04:21:01     INFO - Stopping web server
6223
[task 2017-10-26T04:21:01.368Z] 04:21:01     INFO - Stopping web socket server
6224
[task 2017-10-26T04:21:01.384Z] 04:21:01     INFO - Stopping ssltunnel


	
:hsinyi, could you please take a look?
Flags: needinfo?(htsai)
Whiteboard: [stockwell needswork]
Hi Bevis,
Are you aware of any window leaking issue recently on Indexeddb?

Meanwhile, I may also check see if I can reproduce it locally.
Flags: needinfo?(btseng)
Unfotunately, no. :(
Flags: needinfo?(btseng)
Priority: -- → P2
In the last 7 days, there have been 55 failures.

:shawnjohnjr Did you have the chance to take a look at this and try to repro it locally?
Flags: needinfo?(shuang)
I did and I also give "--verify" argument on Linux x64 machine locally, but no luck.
I'm looking into window (about:privatebrowsing), since the leaking window url "about:privatebrowsing".
(In reply to Shawn Huang [:shawnjohnjr] from comment #14)
> I still don't have any idea. So add more logs.
> 
> https://treeherder.mozilla.org/#/
> jobs?repo=try&revision=e09bd87c9e322edd5ab123efe1e9ae134af6f639

I'm not sure why that info log doesn't show up. I guess info log by default was removed.

Try again.
https://treeherder.mozilla.org/#/jobs?repo=try&revision=f64bac86b4bac746dbc28455dade47a0da06ee57
I still can't reproduce locally. And I suspect that this is timing issue bewteen shutdown leak and dom window destruction because the problem happens after ShutdownLeaks collection completion.

I reviewed the log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=142308374&lineNumber=5634


[task 2017-11-06T01:40:01.188Z] 01:40:01     INFO - GECKO(2322) | Completed ShutdownLeaks collections in process 2371
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
DOM window deconstructor called after ShutdownLeaks collections in process 2371 completed.

[task 2017-11-06T01:40:01.191Z] 01:40:01     INFO - GECKO(2322) | --DOMWINDOW == 1 (0xe0b8d800) [pid = 2371] [serial = 11] [outer = (nil)] [url = about:privatebrowsing]
[task 2017-11-06T01:40:05.083Z] 01:40:05     INFO - GECKO(2322) | --DOMWINDOW == 0 (0xe25b4400) [pid = 2371] [serial = 13] [outer = (nil)] [url = about:privatebrowsing]


Then I saw leak reports.

[task 2017-11-06T01:40:10.754Z] 01:40:10    ERROR - TEST-UNEXPECTED-FAIL | dom/indexedDB/test/browser_perwindow_privateBrowsing.js | leaked 2 window(s) until shutdown [url = about:privatebrowsing]
[task 2017-11-06T01:40:10.756Z] 01:40:10     INFO - TEST-INFO | dom/indexedDB/test/browser_perwindow_privateBrowsing.js | windows(s) leaked: [pid = 2371] [serial = 11], [pid = 2371] [serial = 13]

Since I already added "win = null" at the end in browser_perwindow_privateBrowsing.js test case, I don't know what else I can do to force destruction before ShutdownLeaks collection completed.

Andrew, do you have any suggestion?
Flags: needinfo?(shuang) → needinfo?(continuation)
Ideally you'd get a CC log from the shutdown collections CCs and figure out why that window is still alive. I'm not sure how easy that is going to be if you can't reproduce it in isolation.
Flags: needinfo?(continuation)
Probably not related, but could you try to replace both `gBrowser.removeCurrentTab` [1] with `await BrowserTestUtils.removeTab` [2] to explicity wait until the tab gets closed?

[1] https://searchfox.org/mozilla-central/rev/a662f122c37704456457a526af90db4e3c0fd10e/dom/indexedDB/test/browser_perwindow_privateBrowsing.js#21,32
[2] https://searchfox.org/mozilla-central/rev/a662f122c37704456457a526af90db4e3c0fd10e/testing/mochitest/BrowserTestUtils/BrowserTestUtils.jsm#973

Alternatively, you can use `BrowserTestUtils.withNewTab` in both test cases which automatically adds a tab before calling `taskFn` and closes the tab after it finishes. It accepts different tabbrowser as a parameter, so for test2 you can pass win.gBrowser into it.

https://searchfox.org/mozilla-central/source/testing/mochitest/BrowserTestUtils/BrowserTestUtils.jsm#95
Pushed by gbrown@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/ee147ca3314d
Disable test browser_perwindow_privateBrowsing.js on linux/debug for frequent intermittent leaks; r=me,test-only
(In reply to OrangeFactor Robot from comment #20)
> ** This test has failed more than 200 times in the last 30 days. It should
> be disabled until it can be fixed. ** 

Thanks for all the efforts here. Hope this test can be re-enabled soon.
Keywords: leave-open
Whiteboard: [stockwell disable-recommended] → [stockwell disabled]
(In reply to Samael Wang [:freesamael] from comment #19)
> Probably not related, but could you try to replace both
> `gBrowser.removeCurrentTab` [1] with `await BrowserTestUtils.removeTab` [2]
> to explicity wait until the tab gets closed?
> 
> [1]
> https://searchfox.org/mozilla-central/rev/
> a662f122c37704456457a526af90db4e3c0fd10e/dom/indexedDB/test/
> browser_perwindow_privateBrowsing.js#21,32
> [2]
> https://searchfox.org/mozilla-central/rev/
> a662f122c37704456457a526af90db4e3c0fd10e/testing/mochitest/BrowserTestUtils/
> BrowserTestUtils.jsm#973
> 
> Alternatively, you can use `BrowserTestUtils.withNewTab` in both test cases
> which automatically adds a tab before calling `taskFn` and closes the tab
> after it finishes. It accepts different tabbrowser as a parameter, so for
> test2 you can pass win.gBrowser into it.
> 
> https://searchfox.org/mozilla-central/source/testing/mochitest/
> BrowserTestUtils/BrowserTestUtils.jsm#95

Awesome! Thanks for the suggestion. I need to test a longer for sure it won't happen again.
Assignee: nobody → jvarga
Janv, want to take a look?
Flags: needinfo?(jvarga)
Assignee: jvarga → nobody
Whiteboard: [stockwell disabled] → [stockwell disabled]DWS_NEXT
Blocks: 1541370
Flags: needinfo?(jvarga)
Severity: normal → S3
You need to log in before you can comment on or make changes to this bug.