1011339 - Plugin container will not close on first run of a new profile

Status: RESOLVED FIXED

(Core Graveyard :: Plug-ins, defect, P3)

Description

[Qeole]

User Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:31.0) Gecko/20100101 Firefox/31.0 (Beta/Release)
Build ID: 20140515064222

Steps to reproduce:

I discovered this when working on bug 1007490 with version 32 on Linux (Kubuntu) and could reproduce it with version 31 (on same machine) and 29 (different machine, Xubuntu):
Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0
Mozilla/5.0 (Windows NT 6.1; rv:31.0) Gecko/20100101 Firefox/31.0
Mozilla/5.0 (X11; Ubuntu; Linux i686; rv:29.0) Gecko/20100101 Firefox/29.0

I could NOT reproduce under Windows:
Mozilla/5.0 (Windows NT 6.1; rv:31.0) Gecko/20100101 Firefox/31.0

Steps to reproduce:
1) Launch Firefox with profile manager ($ firefox -ProfileManager)
2) Create a new profile and start Firefox whith this new profile
3) Open new tab (CTRL+T)
4) Switch to newly opened tab and visit a page that requires Flash plugin (youtube.com for example)
5) Close this tab

---- On next instances of the profile, there is no problem:
6) Close Firefox (CTRL+Q, or even kill the Firefox process)
7) Launch Firefox again, with the same profile
8) Open a new tab
9) Switch to newly opened tab and visit a page that requires Flash plugin (youtube.com for example)
10) Close this tab


Actual results:

At step 5), the plugin-container running Flash does not close after expected 180-second timeout (I didn't see it closing, even if I wait longer).
The plugin-container is only closed at step 5), when I close Firefox..

This only happens during the first instance that runs with a new profile (unlike bug 577157?): the plugin-container is always closed after 180 seconds (as expected) at step 10) − whether or not I launched a plugin during the first instance (i.e. whether or not I realized steps 3) and 4)).




Expected results:

Plugin-container running Flash should close after 180 seconds (currently hardcoded at http://hg.mozilla.org/mozilla-central/annotate/2a03b34c8953/dom/plugins/base/nsPluginHost.cpp#l730, should be modified with bug 1007490), even on first run of a new profile.

Comment 1

[Qeole]

> Actual results:
> 
> The plugin-container is only closed at step 5), when I close Firefox.
In above sentence I meant that plugin-container is only closed at step 6) (and not 5). Sorry.

Comment 2

[Georg Fritzsche [:gfritzsche]]

I can't reproduce on OS X, but it would be great to figure out what's going wrong here.

I think as first steps it would be interesting to find out:
* if we hit nsPluginHost::OnPluginInstanceDestroyed() at all [1]
* whether we start the timer there
* do we hit nsPluginHost::Notify() [2]?
* what does IsPluginRunning() return there?
* what do we end up doing in nsPluginTag::TryUnloadPlugin()?

There is also plugin related logging to be activated that could help understand whats going on:
http://hg.mozilla.org/mozilla-central/annotate/58c5a3427997/dom/plugins/base/nsPluginLogging.h#l40

Qeole, would you be able to investigate this a little?

[1] http://hg.mozilla.org/mozilla-central/annotate/2a03b34c8953/dom/plugins/base/nsPluginHost.cpp#l697
[2] http://hg.mozilla.org/mozilla-central/annotate/2a03b34c8953/dom/plugins/base/nsPluginHost.cpp#l3412
[3] http://hg.mozilla.org/mozilla-central/annotate/58c5a3427997/dom/plugins/base/nsPluginTags.cpp#l486

Comment 3

[Qeole]

I will have a look at it next week.
Thanks (once more!) for providing steps and links.

Comment 4

[Qeole]

Investigation report: I started to have a look at what happens here.

Let [First_Run] be the case where I first run an instance with a new profile (i.e. case when unexpected behavior occurs), and let [Following_Runs] be… well, following runs with same profile − when no unexpected things happen.

(In reply to Georg Fritzsche [:gfritzsche] [away May 17 - June 1] from comment #2)
> I think as first steps it would be interesting to find out:
> 
> * if we hit nsPluginHost::OnPluginInstanceDestroyed() at all [1]
Yes we do, in both cases.

> * whether we start the timer there
Yes we do, with both cases. With expected timeout value (now 30 seconds by default in mozilla-central).

> * do we hit nsPluginHost::Notify() [2]?
Yes we do, in both cases.

> * what does IsPluginRunning() return there?
Returns “false”, in both cases.

> * what do we end up doing in nsPluginTag::TryUnloadPlugin() [3]?
Here there is a distinction.
In both cases the function is called with bool argument “inShutDown” set to “false”, but then:
− in case [First_Run], when TryUnloadPlugin is called at the end of timeout, condition “(mLibrary && !inShutDown)” (see [4]) is verified, so the function returns without doing anything (preventing the plugin-container to close?);
− in case [Following_Runs], condition “(mLibrary && !inShutDown)”, which comes down in our case to condition “(mLibrary)”, is not verified. Hence mPlugin->Shutdown() is called.

I observed that the call to mPlugin->Shutdown() *does* close the plugin-container. I enforced this call in function TryUnloadPlugin() to see what happens, and plugin-container would then effectively close even on [First_Run] case.
(Incidentally, Firefox would also crash on closing: maybe the code I removed was useful after all :).)

This is all I have right now, but I will try to find why mLibrary is set on [First_Run] case.

> […]
> 
> [1] http://hg.mozilla.org/mozilla-central/annotate/2a03b34c8953/dom/plugins/base/nsPluginHost.cpp#l697
> [2] http://hg.mozilla.org/mozilla-central/annotate/2a03b34c8953/dom/plugins/base/nsPluginHost.cpp#l3412
> [3] http://hg.mozilla.org/mozilla-central/annotate/58c5a3427997/dom/plugins/base/nsPluginTags.cpp#l486
[4] https://hg.mozilla.org/mozilla-central/annotate/e86a0d92d174/dom/plugins/base/nsPluginTags.cpp#l488

Comment 5

[Benjamin Smedberg]

Aha! I think this has to do with how we load and cache plugin data.

The first time we encounter a plugin, we load it directly and ask it for the basic data (name, description, mime types, file extensions, etc). We then save this info to pluginreg.dat along with the last-modified timestamp of the plugin.

On subsequent launches, if the timestamp of the plugin hasn't changed, we just re-use the plugin data and don't load it directly.

Loading the plugin to query the data causes the plugintag.mLibrary to be present. We don't want to ever unload plugins that are loaded in-process because all sorts of weird things happen. We only want to unload OOPP plugins.

So I expect we need to rejigger the code so that we unload the "OOPP part" of the plugin but don't unload the local mLibrary.

Comment 6

[Qeole]

(In reply to Benjamin Smedberg  [:bsmedberg] from comment #5)
> The first time we encounter a plugin, we load it directly and ask it for the
> basic data (name, description, mime types, file extensions, etc). We then
> save this info to pluginreg.dat along with the last-modified timestamp of
> the plugin.
I confirm that the bug is related to the absence of file pluginreg.dat. If I delete this file, the same behavior as on first launch of a new profile can be observed.
> 
> So I expect we need to rejigger the code so that we unload the "OOPP part"
> of the plugin but don't unload the local mLibrary.
I will look at this. If anyone has hints about it, they'd be welcome.

Comment 7

[Qeole]

Attachment: IsOPP.patch

Sorry for delay. I got back to this today.

I tried to modify condition in [1] used for returning from function TryUnloadPlugin without doing anything. I used the IsOOP() method to prevent OOPP plugin container from “just returning”, so that it can effectively try to unload plugin and close as desired.

It seems to work for me. Plugin container for Flash plugin effectively closes on first run of a profile, after dom.ipc.plugins.unloadTimeoutSecs is reached. It normally closes on following runs. Bonus point: this time Firefox does not even crash on exit!
Enclosed is my patch for feedback.

[1] https://hg.mozilla.org/mozilla-central/annotate/e86a0d92d174/dom/plugins/base/nsPluginTags.cpp#l488

Comment 8

[Qeole]

Attachment: IsOPP-v2.patch

bsmedberg: Thanks for review.
I've pushed to Try (https://tbpl.mozilla.org/?tree=Try&rev=892d16c44dee), but it turned out I had a bug (I wouldn't verify that mPlugin existed before to call it's method GetLibrary()).
It created bugs only on Linux builds (and only Linux is impacted by this bug, I suppose there is a link. Windows and Mac may never run TryUnloadPlugin() function with undefined mPlugin?).

I corrected that and created a new version of patch (enclosed).
I did a second puch to Try (https://tbpl.mozilla.org/?tree=Try&rev=1811f98dad28).

I'm not used to starring oranges yet, and I'm afraid I've messed up a bit on this push. But I don't see how to delete comments.
(In particular:
  * I'm unsure that bug 984649 is relevant to explain failed test bc1;
  * 3rd build on WindowsXP is starred but there is a remaining error not related to bug 836829)
I'm not sure how important it is, as I launched those build/tests again and they ran well; anyway, I'd appreciate some quick help or documentation about dealing with Try results (I've read this: http://ehsanakhgari.org/blog/2010-04-09/assisted-starring-oranges).

Comment 9

[Georg Fritzsche [:gfritzsche]]

(In reply to qeole from comment #8)
> I'm not used to starring oranges yet, and I'm afraid I've messed up a bit on
> this push. But I don't see how to delete comments.
> (In particular:
>   * I'm unsure that bug 984649 is relevant to explain failed test bc1;
>   * 3rd build on WindowsXP is starred but there is a remaining error not
> related to bug 836829)

bc1 seems to be covered fine by the linked bugs and also doesn't look related to the patch here.

For WinXP 3, bug 836829 covers it.
The command timeout etc. is about the testing infrastructure and not relevant here.

Comment 10

[Benjamin Smedberg]

Comment on attachment 8449250 [details] [diff] [review]
IsOPP-v2.patch

The condition is hard to read now. Can we split it up entirely?

if (!mPlugin) {
  return;
}
if (mLibrary && !inShutdown) {
  return;
}
if (mPlugin->GetLibrary()->IsOOP()) {
  return;
}
mPlugin->Shutdown();
mPlugin = nullptr;

Comment 11

[Qeole]

Of course it's possible to split up, but I disagree with your code, though.
If (mLibrary && !inShutdown) returns true, function simply exits without checking for (mPlugin->GetLibrary()->IsOOP()). Plugin has no chance to be unloaded, that's why we have a bug.

Instead I suggest an intermediary solution:

----
if (!mPlugin) {
  return;
}
if (mLibrary && !inShutdown && !mPlugin->GetLibrary()->IsOOP()) {
  return;
}
mPlugin->Shutdown();
mPlugin = nullptr;
----

Note that if IsOOP() function returns true iff we need to unload the plugin, we could simply have something like:

----
if (mPlugin && mPlugin->GetLibrary()->IsOOP()) {
  mPlugin->Shutdown();
  mPlugin = nullptr;
}
----

but I don't know the code well enough for that (I just can tell it worked for me on a quick test).

Comment 12

[Benjamin Smedberg]

ok, good point (and I didn't understand your condition!)

Looking at this, I'm not sure why we have the mLibrary check at all. I suspect that it was only there because we were using it as a proxy for "plugin is in-process".

AIUI, the conditions we want are:

if the plugin is OOP or we're at shutdown-time

So perhaps:

if (!mPlugin) {
  return;
}
if (inShutdown || mPlugin->GetLibrary()->IsOOP()) {
  mPlugin->Shutdown();
  mPlugin = nullptr;
}

Does that make sense?

Comment 13

[Qeole]

Attachment: IsOPP-v3.patch

Totally makes sense to me. I understand it the same way (I just forgot the shutdown-time case in my previous comment).

I've enclosed a new patch (it contains exactly the code of comment #12, so review should be fast).
I suppose I should perform a new Try push?

Comment 14

[Benjamin Smedberg]

Comment on attachment 8449489 [details] [diff] [review]
IsOPP-v3.patch

Yes, that's probably a good idea.

Comment 15

[Qeole]

There it is : https://tbpl.mozilla.org/?tree=Try&rev=759b0303cd6e
Everything's green.

Asking for check-in.

Comment 16

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/dc33d9f11d84

Comment 17

[Ryan VanderMeulen [:RyanVM]]

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