Closed Bug 1666843 Opened 4 years ago Closed 4 years ago

Intermittent [FIssion] dom/tests/browser/browser_pointerlock_warning.js | leaked 1 window(s) until shutdown [url = data:text/html,<body><iframe src="http://example.org/document-builder.sjs?html=%3Cbody%20onpointerdown='this.requestPointerLock()'%20style=

Categories

(Core :: DOM: Core & HTML, defect, P3)

defect

Tracking

()

RESOLVED FIXED
83 Branch
Fission Milestone M7
Tracking Status
firefox-esr78 --- unaffected
firefox81 --- unaffected
firefox82 --- unaffected
firefox83 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: edgar)

References

(Regression)

Details

(Keywords: intermittent-failure, regression)

Attachments

(2 files)

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


[task 2020-09-23T14:58:08.794Z] 14:58:08     INFO - GECKO(6082) | [Parent 6082: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (0x7f3ba2a7d000) [pid = 6082] [serial = 9] [outer = (nil)] [url = resource://gre-resources/hiddenWindow.html]
[task 2020-09-23T14:58:08.835Z] 14:58:08     INFO - GECKO(6082) | [Parent 6082, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp, line 3359
[task 2020-09-23T14:58:08.943Z] 14:58:08     INFO - GECKO(6082) | [Parent 6082, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp, line 4287
[task 2020-09-23T14:58:09.004Z] 14:58:09     INFO - TEST-INFO | Main app process: exit 0
[task 2020-09-23T14:58:09.004Z] 14:58:09     INFO - TEST-INFO | Confirming we saw 741 DOCSHELL created and 741 destroyed log strings.
[task 2020-09-23T14:58:09.004Z] 14:58:09     INFO - TEST-INFO | Confirming we saw 1982 DOMWINDOW created and 1982 destroyed log strings.
[task 2020-09-23T14:58:09.005Z] 14:58:09    ERROR - TEST-UNEXPECTED-FAIL | dom/tests/browser/browser_pointerlock_warning.js | leaked 1 window(s) until shutdown [url = data:text/html,<body><iframe src="http://example.org/document-builder.sjs?html=%3Cbody%20onpointerdown='this.requestPointerLock()'%20style='width:%20100px;%20height:%20100px;'%3E%3C/body%3E"></iframe></body>]
[task 2020-09-23T14:58:09.005Z] 14:58:09     INFO - TEST-INFO | dom/tests/browser/browser_pointerlock_warning.js | windows(s) leaked: [pid = 7022] [serial = 19]
[task 2020-09-23T14:58:09.005Z] 14:58:09     INFO - TEST-INFO | dom/tests/browser/browser_pointerlock_warning.js | This test created 1 hidden window(s)
[task 2020-09-23T14:58:09.006Z] 14:58:09     INFO - TEST-INFO | dom/tests/browser/browser_pointerlock_warning.js | This test created 1 hidden docshell(s)
[task 2020-09-23T14:58:09.006Z] 14:58:09     INFO - TEST-INFO | dom/tests/browser/browser_ConsoleAPI_originAttributes.js | This test created 1 hidden window(s)
[task 2020-09-23T14:58:09.006Z] 14:58:09     INFO - TEST-INFO | dom/tests/browser/browser_ConsoleAPI_originAttributes.js | This test created 1 hidden docshell(s)
Has Regression Range: --- → yes

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

I don't see anything in bug 1664952 that would cause a leak like this. This is more likely a leak within the pointerlock code that was exposed by the test I added.

The leak only affects fission. Edgar, as you only recently implemented pointer lock for fission, do you have any ideas what might be wrong here?

Flags: needinfo?(enndeakin)
Fission Milestone: --- → ?
Fission Milestone: ? → M7
Flags: needinfo?(echen)
Priority: P5 → P3

I could reproduce this locally on test verify, I did some quick test,

  • The leak is reproduced on fission only.
  • Backing out recent pointer lock changes for fission (bug 1662587 and bug 1646493) doesn't help.

It seems not a regression but probably an already existing issue, and somehow only happens on OOP iframe.
I will keep investigating.

I tried to get CC and GC log, but the leaked window doesn't show on the CC log at all, so the issue might be not too complicated.
Then I checked when does the last nsGlobalWindowOuter::Release happen, I got

(rr) bt
#0 0x00007f3b5ba65890 in nsCycleCollectingAutoRefCnt::get() const (this=<optimized out>) at /home/edgar/Workspace/mercurial/mozilla-central/objdir-debug/dist/include/nsISupportsImpl.h:302
#1 0x00007f3b5ba65890 in nsCycleCollectingAutoRefCnt::operator unsigned long() const (this=<optimized out>) at /home/edgar/Workspace/mercurial/mozilla-central/objdir-debug/dist/include/nsISupportsImpl.h:305
#2 0x00007f3b5ba65890 in nsGlobalWindowOuter::Release() (this=0x7f3b6c995260) at /home/edgar/Workspace/mercurial/mozilla-central/dom/base/nsGlobalWindowOuter.cpp:1550
#3 0x00007f3b5bc21f8d in nsCOMPtr<nsPIDOMWindowOuter>::assign_assuming_AddRef(nsPIDOMWindowOuter*) (this=<optimized out>, aNewPtr=0x0)
at /home/edgar/Workspace/mercurial/mozilla-central/objdir-debug/dist/include/nsCOMPtr.h:428
#4 0x00007f3b5bc21f8d in nsCOMPtr<nsPIDOMWindowOuter>::operator=(decltype(nullptr)) (this=<optimized out>) at /home/edgar/Workspace/mercurial/mozilla-central/objdir-debug/dist/include/nsCOMPtr.h:697
#5 0x00007f3b5bc21f8d in nsFocusManager::Observe(nsISupports*, char const*, char16_t const*) (this=0x7f3b6c9651a0, aSubject=<optimized out>, aTopic=<optimized out>, aData=<optimized out>)
at /home/edgar/Workspace/mercurial/mozilla-central/dom/base/nsFocusManager.cpp:245
#6 0x00007f3b5bc22071 in non-virtual thunk to nsFocusManager::Observe(nsISupports*, char const*, char16_t const*) () at /home/edgar/Workspace/mercurial/mozilla-central/objdir-debug/dist/bin/libxul.so
#7 0x00007f3b5a7bc64b in nsObserverList::NotifyObservers(nsISupports*, char const*, char16_t const*) (this=<optimized out>, aSubject=0x7f3b6c9db328, aTopic=0x7f3b56328880 "xpcom-shutdown", someData=0x0)
at /home/edgar/Workspace/mercurial/mozilla-central/xpcom/ds/nsObserverList.cpp:70
#8 0x00007f3b5a7c5b83 in nsObserverService::NotifyObservers(nsISupports*, char const*, char16_t const*) (this=<optimized out>, aSubject=0x7f3b6c9db328, aTopic=0x7f3b56328880 "xpcom-shutdown", aSomeData=0x0)
at /home/edgar/Workspace/mercurial/mozilla-central/xpcom/ds/nsObserverService.cpp:288
#9 0x00007f3b5a881ac2 in mozilla::ShutdownXPCOM(nsIServiceManager*) (aServMgr=0x0) at /home/edgar/Workspace/mercurial/mozilla-central/xpcom/build/XPCOMInit.cpp:620

It looks like nsFocusManager hold the window until xpcom shutdown, https://searchfox.org/mozilla-central/rev/dfd9c0f72f9765bd4a187444e0c1e19e8834a506/dom/base/nsFocusManager.cpp#245.

It seems the issue happens when focus is in OOP iframe and the process of parent window won't clear mFocusedWindow when blur, looks like a bug?

What the test does is to create a new tab that loads a page contains an OOP iframe, and sythesizes a mouse down event to the OOP iframe, so the focus moves to OOP iframe and then preform some pointer lock test. After finish, test will remove the new created tab, then tabbrowser try to blur current focued XULFrame first which trigger sending a Deactivate IPC to the process of test page and also the process of OOP iframe.

When process of test page receive Deactivate IPC, it try to lower the window which calls nsFocusManager::Blur, but doesn't run the blur steps given the mFocusedBrowsingContextInContent is the OOP iframe one, not an in-process bc. So mFocusedWindow won't be cleared. Is this intentional?

Furthermore, process of test page receives Destroy IPC later soon while tab is really being removed, which is from https://searchfox.org/mozilla-central/rev/222e4f64b769413ac1a1991d2397b13a0acb5d9d/dom/ipc/BrowserParent.cpp#616 due to https://searchfox.org/mozilla-central/rev/222e4f64b769413ac1a1991d2397b13a0acb5d9d/browser/base/content/tabbrowser.js#3703, but mFocusedWindow still won't be cleared.

Most of case, we don't get leak is because focus moves to in-process about:blank and make the mFocusedWindow could be cleared properly. But if that does not happen, then we get a leaked window. Henri, do you have any ideas about what should we do for this? Thanks!

Flags: needinfo?(echen) → needinfo?(hsivonen)

Clear mFocusedWindow in nsFocusManager::Blur call if the focus is in another process, i.e. https://hg.mozilla.org/try/rev/b55ba44219a197514c72d82c393cc4455fe46fbe, could fix the leak, and try result seems good, https://treeherder.mozilla.org/#/jobs?repo=try&group_state=expanded&revision=da0be917863e7b406d60df61be6c2310a7c0da9e.

Assignee: nobody → apavel
Status: NEW → ASSIGNED
Attachment #9180182 - Attachment description: Bug 1666843 - disable /browser_pointerlock_warning.js on fission r=Aryx → Bug 1666843 - disable /browser_pointerlock_warning.js on fission
Attachment #9180182 - Attachment description: Bug 1666843 - disable /browser_pointerlock_warning.js on fission → Bug 1666843 - disable browser_pointerlock_warning.js on Linux debug fission
Summary: Intermittent dom/tests/browser/browser_pointerlock_warning.js | leaked 1 window(s) until shutdown [url = data:text/html,<body><iframe src="http://example.org/document-builder.sjs?html=%3Cbody%20onpointerdown='this.requestPointerLock()'%20style='width:%201 → Intermittent [FIssion] dom/tests/browser/browser_pointerlock_warning.js | leaked 1 window(s) until shutdown [url = data:text/html,<body><iframe src="http://example.org/document-builder.sjs?html=%3Cbody%20onpointerdown='this.requestPointerLock()'%20style=
Pushed by archaeopteryx@coole-files.de:
https://hg.mozilla.org/integration/autoland/rev/5543df8ac2d3
disable browser_pointerlock_warning.js on Linux debug fission DONTBUILD
Keywords: leave-open

(In reply to Edgar Chen [:edgar] (PTO 10/8 and 10/9) from comment #9)

Clear mFocusedWindow in nsFocusManager::Blur call if the focus is in another process, i.e. https://hg.mozilla.org/try/rev/b55ba44219a197514c72d82c393cc4455fe46fbe, could fix the leak, and try result seems good, https://treeherder.mozilla.org/#/jobs?repo=try&group_state=expanded&revision=da0be917863e7b406d60df61be6c2310a7c0da9e.

I think the expectation is that the blurring would eventually result in an IPC message doing this anyway, but since, evidently, we can't rely on that, it seems both useful and harmless to do this. Thanks!

Flags: needinfo?(hsivonen)

The patch really needs a comment explaining the line, though.

Whiteboard: [stockwell disable-recommended] → [stockwell disabled]

(In reply to Henri Sivonen (:hsivonen) from comment #19)

The patch really needs a comment explaining the line, though.

Yeah, I will prepare a formal patch for review.

(In reply to Henri Sivonen (:hsivonen) from comment #18)

I think the expectation is that the blurring would eventually result in an IPC message doing this anyway, but since, evidently, we can't rely on that, it seems both useful and harmless to do this. Thanks!

I guess you mean OOP iframe would bounce an IPC message to the parent frame and result in https://searchfox.org/mozilla-central/rev/c2e3ac11be4837718c2604e58085fbc8252b69dd/dom/base/nsFocusManager.cpp#2102? But in comment #8 case, that doesn't happen, because the focus is in OOP iframe, the process of OOP iframe won't try to bounce an IPC message to its parent frame.

The expectation is that the blurring would eventually result in an IPC message
doing this anyway, but this doesn't happen if the focus is in OOP iframe which
won't try to bounce an IPC message to its parent frame.

Keywords: leave-open
Pushed by echen@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/6d79ef2d6881
Clear mFocusedWindow while burring; r=hsivonen
Assignee: apavel → echen
Status: ASSIGNED → RESOLVED
Closed: 4 years ago
Resolution: --- → FIXED
Target Milestone: --- → 83 Branch
Whiteboard: [stockwell disabled]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: