Closed Bug 766886 Opened 13 years ago Closed 13 years ago

Intermittent test_pluginstream_seek_close.html leak of 1 nsAuthURLParser, 1 nsHashtable, 1 nsNPAPIPluginInstance, 1 nsNPAPIPluginStreamListener, 1 nsPluginStreamListenerPeer with leaked dom/plugins/test/neverending.sjs

Categories

(Core Graveyard :: Plug-ins, defect)

Product:
Core Graveyard
Component:
Plug-ins
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(firefox18 fixed, firefox19 fixed)

Status:
RESOLVED FIXED
Milestone:
mozilla19
Tracking Flags:
Tracking Status
firefox18 --- fixed
firefox19 --- fixed

People

(Reporter: emorley, Assigned: johns)

References

Details

(Keywords: intermittent-failure, memory-leak)

Attachments

(1 file)

Fix
1.95 KB, patch
benjamin
: review+
bajaj
: approval-mozilla-aurora+
johns
: checkin+
Details | Diff | Splinter Review
Rev4 MacOSX Lion 10.7 mozilla-inbound debug test mochitests-2/5 on 2012-06-20 08:40:59 PDT for push 1b1b8f3a4266 slave: talos-r4-lion-046 https://tbpl.mozilla.org/php/getParsedLog.php?id=12830402&tree=Mozilla-Inbound { == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, default process 445 |<----------------Class--------------->|<-----Bytes------>|<----------------Objects---------------->|<--------------References-------------->| Per-Inst Leaked Total Rem Mean StdDev Total Rem Mean StdDev 0 TOTAL 20 952 103544185 15 (23607.41 +/- 36532.72) 219335432 10 (42051518673.80 +/- 0.00) 427 nsAuthURLParser 24 24 2 1 ( 1.33 +/- 0.58) 283228 1 ( 8134.98 +/- 2123.79) 766 nsHashtable 72 72 4149 1 ( 450.47 +/- 108.79) 0 0 ( 0.00 +/- 0.00) 886 nsNPAPIPluginInstance 152 152 69 1 ( 3.22 +/- 2.02) 8679 2 ( 5.60 +/- 3.11) 887 nsNPAPIPluginStreamListener 136 136 44 1 ( 1.10 +/- 1.27) 134 1 ( 1.68 +/- 1.16) 943 nsPluginStreamListenerPeer 224 224 42 1 ( 0.96 +/- 1.04) 621 1 ( 5.57 +/- 4.25) 1043 nsStandardURL 248 248 87868 1 ( 8279.42 +/- 2080.08) 3850366 1 (18020.74 +/- 2826.11) 1055 nsStringBuffer 8 24 1440375 3 (73391.47 +/- 23956.39) 4581140 4 (106450.96 +/- 45247.65) 1100 nsTArray_base 8 32 33322072 4 (61476.22 +/- 23054.38) 0 0 ( 0.00 +/- 0.00) 1147 nsVoidArray 8 8 958994 1 (11584.67 +/- 2830.88) 0 0 ( 0.00 +/- 0.00) 1149 nsWeakReference 32 32 16465 1 ( 567.84 +/- 179.89) 488571 1 ( 1844.02 +/- 1076.53) nsTraceRefcntImpl::DumpStatistics: 1251 entries TEST-UNEXPECTED-FAIL | automationutils.processLeakLog() | leaked 952 bytes during test execution TEST-UNEXPECTED-FAIL | automationutils.processLeakLog() | leaked 1 instance of nsAuthURLParser with size 24 bytes TEST-UNEXPECTED-FAIL | automationutils.processLeakLog() | leaked 1 instance of nsHashtable with size 72 bytes TEST-UNEXPECTED-FAIL | automationutils.processLeakLog() | leaked 1 instance of nsNPAPIPluginInstance with size 152 bytes TEST-UNEXPECTED-FAIL | automationutils.processLeakLog() | leaked 1 instance of nsNPAPIPluginStreamListener with size 136 bytes TEST-UNEXPECTED-FAIL | automationutils.processLeakLog() | leaked 1 instance of nsPluginStreamListenerPeer with size 224 bytes TEST-INFO | automationutils.processLeakLog() | leaked 1 instance of nsStandardURL with size 248 bytes TEST-INFO | automationutils.processLeakLog() | leaked 3 instances of nsStringBuffer with size 8 bytes each (24 bytes total) TEST-INFO | automationutils.processLeakLog() | leaked 4 instances of nsTArray_base with size 8 bytes each (32 bytes total) TEST-INFO | automationutils.processLeakLog() | leaked 1 instance of nsVoidArray with size 8 bytes TEST-INFO | automationutils.processLeakLog() | leaked 1 instance of nsWeakReference with size 32 bytes }
https://tbpl.mozilla.org/php/getParsedLog.php?id=13136703&tree=Mozilla-Inbound
Summary: Intermittent mochitest-plain-2 leak of 952 bytes (1 nsAuthURLParser, 1 nsHashtable, 1 nsNPAPIPluginInstance, 1 nsNPAPIPluginStreamListener, 1 nsPluginStreamListenerPeer) with leaked URL http://mochi.test:8888/tests/dom/plugins/test/neverending.sjs → Intermittent mochitest-plain-2 leak of 608 or 952 bytes (1 nsAuthURLParser, 1 nsHashtable, 1 nsNPAPIPluginInstance, 1 nsNPAPIPluginStreamListener, 1 nsPluginStreamListenerPeer) with leaked URL http://mochi.test:8888/tests/dom/plugins/test/neverending.sjs
https://tbpl.mozilla.org/php/getParsedLog.php?id=13150078&tree=Services-Central
Summary: Intermittent mochitest-plain-2 leak of 608 or 952 bytes (1 nsAuthURLParser, 1 nsHashtable, 1 nsNPAPIPluginInstance, 1 nsNPAPIPluginStreamListener, 1 nsPluginStreamListenerPeer) with leaked URL http://mochi.test:8888/tests/dom/plugins/test/neverending.sjs → Intermittent M2 or reftest leak of 608 or 952 bytes (1 nsAuthURLParser, 1 nsHashtable, 1 nsNPAPIPluginInstance, 1 nsNPAPIPluginStreamListener, 1 nsPluginStreamListenerPeer) with leaked URL http://mochi.test:8888/tests/dom/plugins/test/neverending.sjs
https://tbpl.mozilla.org/php/getParsedLog.php?id=13723120&tree=Firefox
Summary: Intermittent M2 or reftest leak of 608 or 952 bytes (1 nsAuthURLParser, 1 nsHashtable, 1 nsNPAPIPluginInstance, 1 nsNPAPIPluginStreamListener, 1 nsPluginStreamListenerPeer) with leaked URL http://mochi.test:8888/tests/dom/plugins/test/neverending.sjs → Intermittent M2 or reftest leak of 604, 608 or 952 bytes (1 nsAuthURLParser, 1 nsHashtable, 1 nsNPAPIPluginInstance, 1 nsNPAPIPluginStreamListener 1 nsPluginStreamListenerPeer) with leaked URL http://mochi.test:8888/tests/dom/plugins/test/neverending.sjs
https://tbpl.mozilla.org/php/getParsedLog.php?id=14460674&tree=Mozilla-Inbound
Summary: Intermittent M2 or reftest leak of 604, 608 or 952 bytes (1 nsAuthURLParser, 1 nsHashtable, 1 nsNPAPIPluginInstance, 1 nsNPAPIPluginStreamListener 1 nsPluginStreamListenerPeer) with leaked URL http://mochi.test:8888/tests/dom/plugins/test/neverending.sjs → Intermittent M2 or reftest leak of 604, 608, 952, 1196 bytes (1 nsAuthURLParser, 1 nsHashtable, 1 nsNPAPIPluginInstance, 1 nsNPAPIPluginStreamListener 1 nsPluginStreamListenerPeer) with leaked http://mochi.test:8888/tests/dom/plugins/test/neverending.sjs
https://tbpl.mozilla.org/php/getParsedLog.php?id=15665397&tree=Mozilla-Inbound
Summary: Intermittent M2 or reftest leak of 604, 608, 952, 1196 bytes (1 nsAuthURLParser, 1 nsHashtable, 1 nsNPAPIPluginInstance, 1 nsNPAPIPluginStreamListener 1 nsPluginStreamListenerPeer) with leaked http://mochi.test:8888/tests/dom/plugins/test/neverending.sjs → Intermittent leak of 600, 604, 608, 952, 1196 bytes (1 nsAuthURLParser, 1 nsHashtable, 1 nsNPAPIPluginInstance, 1 nsNPAPIPluginStreamListener, 1 nsPluginStreamListenerPeer) with leaked http://mochi.test:8888/tests/dom/plugins/test/neverending.sjs
I looked into this a little, but I'm not any closer to understanding what's going on. When we leak the plugin instance, we get a second call to nsPluginStreamListenerPeer::OnStopRequest, note aStatus NS_ERROR_NOT_INITIALIZED #0 nsPluginStreamListenerPeer::OnStopRequest (this=0x7fffb699ed60, request=0x7fffaf52c058, aContext=0x0, aStatus=NS_ERROR_NOT_INITIALIZED) at /home/johns/moz/moz-git/dom/plugins/base/nsPluginStreamListenerPeer.cpp:961 #1 0x00007ffff0f191f6 in mozilla::net::HttpBaseChannel::DoNotifyListener (this=0x7fffaf52c000) at /home/johns/moz/moz-git/netwerk/protocol/http/HttpBaseChannel.cpp:1432 #2 0x00007ffff0f298d0 in mozilla::net::HttpAsyncAborter<mozilla::net::nsHttpChannel>::HandleAsyncAbort (this=0x7fffaf52c2c0) at /home/johns/moz/moz-git/netwerk/protocol/http/HttpBaseChannel.h:339 #3 0x00007ffff0f297ec in mozilla::net::nsHttpChannel::HandleAsyncAbort (this=0x7fffaf52c000) at /home/johns/moz/moz-git/netwerk/protocol/http/nsHttpChannel.cpp:1844 #4 0x00007ffff0f3e7e8 in nsRunnableMethodImpl<void (mozilla::net::nsHttpChannel::*)(), true>::Run (this=0x7fffaf549a00) at ../../../dist/include/nsThreadUtils.h:349 #5 0x00007ffff2fbbe6f in nsThread::ProcessNextEvent (this=0x7ffff6d793d0, mayWait=true, result=0x7fffffffb38e) at /home/johns/moz/moz-git/xpcom/threads/nsThread.cpp:612 #6 0x00007ffff2f2fd59 in NS_ProcessNextEvent_P (thread=0x7ffff6d793d0, mayWait=true) at nsThreadUtils.cpp:220 #7 0x00007ffff2a04c98 in mozilla::places::(anonymous namespace)::BlockingConnectionCloseCallback::Spin (this=0x7fffaf50cb00) at /home/johns/moz/moz-git/toolkit/components/places/Database.cpp:246 #8 0x00007ffff2a04ab3 in mozilla::places::Database::Shutdown (this=0x7ffff6d221f0) at /home/johns/moz/moz-git/toolkit/components/places/Database.cpp:1899 #9 0x00007ffff2a058b7 in mozilla::places::Database::Observe (this=0x7ffff6d221f0, aSubject=0x7fffaf510e00, aTopic=0x7ffff4189a4b "profile-before-change", aData=0x7ffff41899d0 <nsXREDirProvider::DoShutdown()::kShutdownPersist>) at /home/johns/moz/moz-git/toolkit/components/places/Database.cpp:1996 #10 0x00007ffff2f5b816 in nsObserverList::NotifyObservers (this=0x7fffc4a10270, aSubject=0x7fffaf510e00, aTopic=0x7ffff4189a4b "profile-before-change", someData=0x7ffff41899d0 <nsXREDirProvider::DoShutdown()::kShutdownPersist>) at /home/johns/moz/moz-git/xpcom/ds/nsObserverList.cpp:99 #11 0x00007ffff2f5dc96 in nsObserverService::NotifyObservers (this=0x7fffe7df3880, aSubject=0x7fffaf510e00, aTopic=0x7ffff4189a4b "profile-before-change", someData=0x7ffff41899d0 <nsXREDirProvider::DoShutdown()::kShutdownPersist>) at /home/johns/moz/moz-git/xpcom/ds/nsObserverService.cpp:149 #12 0x00007ffff0d55cd0 in nsXREDirProvider::DoShutdown (this=0x7fffffffb9d8) at /home/johns/moz/moz-git/toolkit/xre/nsXREDirProvider.cpp:861 ...whereas we only ever get one call when the test does not leak, from InputStreamPump.
bsmedberg, do you have any ideas about this pretty frequent leak (see John's initial assessment at comment 150)?
(In reply to Ed Morley (PTO/travelling until 24th Oct) [:edmorley UTC+1] from comment #280) > bsmedberg, do you have any ideas about this pretty frequent leak (see John's > initial assessment at comment 150)? I guess that's a no. That's OK, manually starring this bug frequently throughout the day is fun anyway... https://tbpl.mozilla.org/php/getParsedLog.php?id=16375382&tree=Firefox
https://tbpl.mozilla.org/php/getParsedLog.php?id=16509695&tree=Mozilla-Inbound Looks like we're probably on our own here. Alas, it's not as easy to disable our way to victory as the (former) summary would make it seem - neverending.sjs is only used by test_pluginstream_seek_close.html, but the reftests we've been dropping in here so long that I thought that was what the bug was about seem to be leaking something that http://mxr.mozilla.org/mozilla-central/search?string=black140x100.ogv says is used in 33 reftests. So probably our first step is going to be to file a separate Video/Audio bug for them, and then we can use this bug to just disable test_pluginstream_seek_close.html since nobody wants to fix it, and see whether or not anyone will want to fix those once they are in the right lap.
Summary: Intermittent leak of 600, 604, 608, 952, 1196 bytes (1 nsAuthURLParser, 1 nsHashtable, 1 nsNPAPIPluginInstance, 1 nsNPAPIPluginStreamListener, 1 nsPluginStreamListenerPeer) with leaked http://mochi.test:8888/tests/dom/plugins/test/neverending.sjs → Intermittent leak of 1 nsAuthURLParser, 1 nsHashtable, 1 nsNPAPIPluginInstance, 1 nsNPAPIPluginStreamListener, 1 nsPluginStreamListenerPeer with leaked dom/plugins/test/neverending.sjs or ogg-video/black140x100.ogv
Blocks: 806133
I've disabled test_pluginstream_seek_close.html due to lack of action in this bug (see comment 354): https://hg.mozilla.org/integration/mozilla-inbound/rev/eb63fc7d719d
Summary: Intermittent leak of 1 nsAuthURLParser, 1 nsHashtable, 1 nsNPAPIPluginInstance, 1 nsNPAPIPluginStreamListener, 1 nsPluginStreamListenerPeer with leaked dom/plugins/test/neverending.sjs or ogg-video/black140x100.ogv → Intermittent test_pluginstream_seek_close.html leak of 1 nsAuthURLParser, 1 nsHashtable, 1 nsNPAPIPluginInstance, 1 nsNPAPIPluginStreamListener, 1 nsPluginStreamListenerPeer with leaked dom/plugins/test/neverending.sjs
Whiteboard: [orange] → [orange][test disabled][leave open]
Apparently I have a mxr-reading-comprehension problem, since once https://tbpl.mozilla.org/php/getParsedLog.php?id=16532622&tree=Firefox leaked demonstrating that it wasn't just test_pluginstream_seek_close.html, it was pretty obvious that test_streamatclose.html uses it too. Now that we know test_streamatclose.html leaks, we should probably disable it (more subtly, since it'll be easier to only disable it if SpecialPowers.isDebugBuild) and reenable test_pluginstream_seek_close.html to see whether or not it also leaks.
It's going to take us a while to remember that bug 806133, which both of those are, exists, isn't it?
/me deletes from history
My awesomebar is trained on "604", sorry...
Attached patch Fix — — Splinter Review
Okay so I can reproduce this reliably and I think I sort of understand what is going on. This code scares me. 1) the nsNPAPIPluginInstance is stopped, and destroys its streams 2) nsNPAPIPluginStreamListener::CleanUpStream is called, but this stream has not gotten OnStartBinding 3) nsPluginStreamListenerPeer calls nsNPAPIPluginStreamListener->OnStartBinding / OnStopBinding (who owns this? Should it be killed earlier?) 4) In OnStopBinding() we finally cancel the actual request The resultant number of trips through the event loop for this channel to die and dependancy chain to unwind explains why this leak happens if we shut down the browser immediately, but not otherwise. I think. This patch has CleanUpStream cancel pending requests immediately if it is aware of its associated nsPluginSteamListenerPeer, and also causes OnStartBinding to bail out if we've already been cleaned up. It seems to fix the leak. @bsmedberg - Does any of this make any sense? I've no idea what I'm doing.
Attachment #679943 - Flags: review?(benjamin)
Attachment #679943 - Flags: review?(benjamin) → review+
Try run for c4b05fdd5971 is complete. Detailed breakdown of the results available here: https://tbpl.mozilla.org/?tree=Try&rev=c4b05fdd5971 Results (out of 103 total builds): success: 91 warnings: 11 failure: 1 Builds (or logs if builds failed) available at: http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/jschoenick@mozilla.com-c4b05fdd5971
Unfortunately, your try push was for linux64, and my feeling (without having loaded a hundred logs to double-check) is that 806133 is 100% linux32.
(In reply to Phil Ringnalda (:philor) from comment #372) > Unfortunately, your try push was for linux64, and my feeling (without having > loaded a hundred logs to double-check) is that 806133 is 100% linux32. Indeed: http://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=806133&entireHistory=true&tree=trunk
(In reply to Phil Ringnalda (:philor) from comment #372) > Unfortunately, your try push was for linux64, and my feeling (without having > loaded a hundred logs to double-check) is that 806133 is 100% linux32. The patch fixes the local testcase I came up with to reproduce this, the try push was more to ensure this didn't cause any further failures -- I didn't hammer any tests on it. If more failures occur after this push, I'll need to go back and find a different repro.
Good news: I triggered 20 linux32 debug reftests on your inbound push, and got zero leaks, three fewer than I would have expected if it was still leaking Bad news: we hadn't noticed that we had a permaorange failure in linux32 debug reftest from somewhere way down below you, so now your push looks like crap ;)
No longer blocks: 806133
(In reply to John Schoenick [:johns] from comment #370) > Waiting to see if this stops bug 806133 before re-enabling the test here Looks like this fixed bug 806133 :-) I've backed out the test-disabling: https://hg.mozilla.org/integration/mozilla-inbound/rev/1f553fc1265e
Assignee: nobody → jschoenick
Status: NEW → ASSIGNED
status-firefox18: --- → affected
status-firefox19: --- → fixed
Whiteboard: [orange][test disabled][leave open] → [orange]
Target Milestone: --- → mozilla19
John, thank you for fixing this :-) Please may you request uplift to aurora? (I can't really speak for the patch's risk etc)
https://hg.mozilla.org/mozilla-central/rev/1f553fc1265e
Status: ASSIGNED → RESOLVED
Closed: 13 years ago
Flags: in-testsuite+
Resolution: --- → FIXED
Comment on attachment 679943 [details] [diff] [review] Fix [Approval Request Comment] Bug caused by (feature/regressing bug #): Unknown User impact if declined: No user impact, but continuing frequent orange on FF18 Testing completed (on m-c, etc.): on m-c Risk to taking this patch (and alternatives if risky): Low, small tweak to ordering of plugin stream cleanup. String or UUID changes made by this patch: None
Attachment #679943 - Attachment description: Fix of questionable correctness → Fix
Attachment #679943 - Flags: approval-mozilla-aurora?
Comment on attachment 679943 [details] [diff] [review] Fix Approving on aurora as it has no user impact and fixes an orange on FF18
Attachment #679943 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
Blocks: 812629
Whiteboard: [orange]
Product: Core → Core Graveyard
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: