Last Comment Bug 836488 - Use read-ahead when loading plugin shared libraries
: Use read-ahead when loading plugin shared libraries
Status: RESOLVED WONTFIX
[Snappy:P1][leave open]
:
Product: Core
Classification: Components
Component: Plug-ins (show other bugs)
: Trunk
: All All
: -- normal (vote)
: ---
Assigned To: Aaron Klotz [:aklotz]
:
Mentors:
Depends on: 845907
Blocks:
  Show dependency treegraph
 
Reported: 2013-01-30 13:51 PST by Vladan Djeric (:vladan)
Modified: 2014-02-19 13:39 PST (History)
12 users (show)
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---


Attachments
Adds telemetry for plugin library load timing (1.88 KB, patch)
2013-02-06 10:14 PST, Aaron Klotz [:aklotz]
no flags Details | Diff | Splinter Review
Adds telemetry for plugin library load timing rev. 2 (3.68 KB, patch)
2013-02-06 10:52 PST, Aaron Klotz [:aklotz]
no flags Details | Diff | Splinter Review
Adds telemetry for plugin library load timing rev. 3 (4.17 KB, patch)
2013-02-06 11:57 PST, Aaron Klotz [:aklotz]
benjamin: review-
Details | Diff | Splinter Review
Adds telemetry for plugin library metadata load timing (2.19 KB, patch)
2013-03-22 03:15 PDT, Aaron Klotz [:aklotz]
benjamin: review+
Details | Diff | Splinter Review
Patch for adding plugin readahead (3.92 KB, patch)
2013-03-22 03:19 PDT, Aaron Klotz [:aklotz]
benjamin: review+
Details | Diff | Splinter Review

Description Vladan Djeric (:vladan) 2013-01-30 13:51:58 PST
I frequently get main-thread jank of 100ms or more from the initial load of the Flash library. This is also the #1 source of chrome-hangs:

PR_WaitCondVar (in nspr4.dll)
 -> mozilla::CondVar::Wait(unsigned int) (in xul.dll)
 -> mozilla::ipc::GeckoChildProcessHost::SyncLaunch (in xul.dll)
 -> mozilla::plugins::PluginProcessParent::Launch(int) (in xul.dll)
 -> mozilla::plugins::PluginModuleParent::LoadModule(char const *) (in xul.dll)
 -> GetNewPluginLibrary(nsPluginTag *) (in xul.dll)
 -> nsNPAPIPlugin::CreatePlugin(nsPluginTag *,nsNPAPIPlugin * *) (in xul.dll)
 -> CreateNPAPIPlugin (in xul.dll)
 -> nsPluginHost::EnsurePluginLoaded(nsPluginTag *) (in xul.dll)

We should figure out if reading plugin libraries with the read-ahead flag (à la xul.dll) will help with plugin jank.  We can start by adding a histogram similar to PLUGIN_SHUTDOWN_MS.

* Preloading the Flash library after startup is another possibility but we can look into that in a separate bug if this fails.
Comment 1 Aaron Klotz [:aklotz] 2013-02-06 10:14:54 PST
Created attachment 710811 [details] [diff] [review]
Adds telemetry for plugin library load timing
Comment 2 Aaron Klotz [:aklotz] 2013-02-06 10:23:50 PST
Comment on attachment 710811 [details] [diff] [review]
Adds telemetry for plugin library load timing

Cancelling review request, this needs more work
Comment 3 Aaron Klotz [:aklotz] 2013-02-06 10:52:10 PST
Created attachment 710836 [details] [diff] [review]
Adds telemetry for plugin library load timing rev. 2

Here's the corrected version: Added telemetry for launching plugin-container in addition to in-process plugins. The histograms are separate for in-process vs OOP so that we aren't comparing apples to oranges.
Comment 4 Aaron Klotz [:aklotz] 2013-02-06 11:57:15 PST
Created attachment 710867 [details] [diff] [review]
Adds telemetry for plugin library load timing rev. 3

Forgot to include Telemetry.h
Comment 5 Benjamin Smedberg [:bsmedberg] 2013-02-11 07:29:28 PST
Comment on attachment 710867 [details] [diff] [review]
Adds telemetry for plugin library load timing rev. 3

The probe you have here won't actually hit the jank stack from comment 0: this codepath is for in-process plugins only (so only Java on Windows by default).

But note that probably most of the time spent here is in launching the process, not loading the library. We do also sometimes load the library (on Windows) in-process in order to pull the metadata such as the plugin MIME types/versions which are stored in the resource block.
Comment 6 Vladan Djeric (:vladan) 2013-02-12 11:18:17 PST
The load times might be less variable if we limit ourselves to only timing the Flash library
Comment 7 Vladan Djeric (:vladan) 2013-02-12 11:19:37 PST
^ as opposed to other plugins
Comment 8 Aaron Klotz [:aklotz] 2013-02-22 15:57:10 PST
(In reply to Benjamin Smedberg  [:bsmedberg] from comment #5)
> Comment on attachment 710867 [details] [diff] [review]
> Adds telemetry for plugin library load timing rev. 3
> 
> But note that probably most of the time spent here is in launching the
> process, not loading the library. We do also sometimes load the library (on
> Windows) in-process in order to pull the metadata such as the plugin MIME
> types/versions which are stored in the resource block.
My idea was that measuring the time from plugin-container launch to opening of the channel could be a proxy for the load time. We're not really interested in the load time itself; we're more interested in the change in load times between now and after the readahead patch lands.

Any suggestions?
Comment 9 (dormant account) 2013-03-11 16:51:34 PDT
Benjamin is there a better way to measure plugin dll-loading overhead for out-of-process plugins? We need to test whether readahead will reduce occurrences of blocking on stack in comment 0.
Comment 10 Benjamin Smedberg [:bsmedberg] 2013-03-18 08:18:15 PDT
I think this got resolved in person: measuring process launch time is going to be really noisy, so it would be valuable to measure the in-process load time (just for metadata) and to measure the load times in the other process I think we need to measure directly there.
Comment 11 Aaron Klotz [:aklotz] 2013-03-22 03:15:38 PDT
Created attachment 728126 [details] [diff] [review]
Adds telemetry for plugin library metadata load timing

This patch is to measure the plugin metadata load time as discussed earlier this week.
Comment 12 Aaron Klotz [:aklotz] 2013-03-22 03:19:29 PDT
Created attachment 728128 [details] [diff] [review]
Patch for adding plugin readahead

This is the patch that actually implements the plugin readahead. This won't land until after we have gathered sufficient telemetry for the "before" case.
Comment 13 Aaron Klotz [:aklotz] 2013-04-01 10:40:55 PDT
Telemetry patch:
https://hg.mozilla.org/integration/mozilla-inbound/rev/b23e5f546045
Comment 14 Ryan VanderMeulen [:RyanVM] 2013-04-02 11:47:54 PDT
https://hg.mozilla.org/mozilla-central/rev/b23e5f546045
Comment 15 Vladan Djeric (:vladan) 2013-07-23 12:13:05 PDT
Are we landing the 2nd patch?
Comment 16 Aaron Klotz [:aklotz] 2013-07-29 12:52:07 PDT
Data gathered via SystemTap runs showed a significant increase in load time when testing with libflashplayer.so with readahead.

Average load time without readahead: 5419ms
Average load time with readahead: 13551ms

(Note that the hardware used for this test is fairly old, so the non-readahead baseline is pretty bad to begin with)
Comment 17 Georg Fritzsche [:gfritzsche] 2014-02-19 13:38:28 PST
So was this found to not improve the situation and can be closed?
Comment 18 Aaron Klotz [:aklotz] 2014-02-19 13:39:01 PST
Correct.

Note You need to log in before you can comment on or make changes to this bug.