Closed Bug 810149 Opened 7 years ago Closed 2 years ago

Never recursively scan addon directories on startup

Categories

(Toolkit :: Add-ons Manager, defect)

x86_64
Windows 7
defect
Not set

Tracking

()

RESOLVED FIXED

People

(Reporter: taras.mozilla, Assigned: Infinity)

References

(Blocks 1 open bug)

Details

(Whiteboard: [Snappy:P1] c=startup_addons u= p=)

Attachments

(2 files, 3 obsolete files)

At the moment we do recursive scan to figure out extension last modified time. This is especially back for jetpack addons because they have lots of files.
Whiteboard: [Snappy:P1]
Blocks: start-faster
This could cause bustage when a third-party app or developer changes the extension's files and we don't properly clear the startup cache. I honestly don't know how often that might be a problem but we might want to figure out how we could run some tests like that.
I had similar worries. We might be able to get away with just scanning install.rdf, and requiring that other vendors *must* update/touch that file when any other file changes. Which really, they should be doing to bump the version string anyway.

In general, recursively scanning all files does seem like a poor tradeoff (in terms of IO), for what should be a rare edge-case.
Blair, can you post the link to the problematic code in question so we can drop in some telemetry to measure the impact of a fix?
If necessary, we could just scan install.rdf at startup, and scan recursively much later, in a background thread, to catch any problem with offending add-ons.
(In reply to Taras Glek (:taras) from comment #3)
> Blair, can you post the link to the problematic code in question so we can
> drop in some telemetry to measure the impact of a fix?

This is the call on startup that leads to recursively checking the last modified timestamp:
https://hg.mozilla.org/mozilla-central/file/b857905d82b4/toolkit/mozapps/extensions/XPIProvider.jsm#l2989

The code change would mean replacing the call to recursiveLastModifiedTime, with something that only looked at install.rdf, here:
https://hg.mozilla.org/mozilla-central/file/b857905d82b4/toolkit/mozapps/extensions/XPIProvider.jsm#l1826
(In reply to David Rajchenbach Teller [:Yoric] from comment #4)
> If necessary, we could just scan install.rdf at startup, and scan
> recursively much later, in a background thread, to catch any problem with
> offending add-ons.

By then it's too late to be useful. We either do this on startup, or not at all.

Saying that, we could potentially do what you suggest, but only use it to report the behavior to AMO and the extension author - so it can be fixed (I'm currently building something specifically for this type of reporting in bug 775253).
(In reply to Dave Townsend (:Mossop) from comment #1)
> This could cause bustage when a third-party app or developer changes the
> extension's files and we don't properly clear the startup cache.

I think it's fine to break third party apps that would do that. As for developers, if we can solve the problem by adding a pref to disable startup cache for them to use when they want to fiddle with addons in-place.
(In reply to Mike Hommey [:glandium] from comment #7)
> (In reply to Dave Townsend (:Mossop) from comment #1)
> > This could cause bustage when a third-party app or developer changes the
> > extension's files and we don't properly clear the startup cache.
> 
> I think it's fine to break third party apps that would do that. As for
> developers, if we can solve the problem by adding a pref to disable startup
> cache for them to use when they want to fiddle with addons in-place.

The problem is never that we're breaking third party apps, but that that bustage shows up as bugs in Firefox that the users then blame us for.
Attached patch Telemetry Probe (obsolete) — Splinter Review
I'm not really sure about the parameters I have specified inside Histogram.json for the Telemetry probe "CHECK_ADDONS_MODIFIED_MS".
Other than that I am hoping this should be fine.
Attachment #682709 - Flags: feedback?(vdjeric)
Attachment #682709 - Flags: feedback?(dteller)
Comment on attachment 682709 [details] [diff] [review]
Telemetry Probe

Review of attachment 682709 [details] [diff] [review]:
-----------------------------------------------------------------

Vladan and I have decided to split the work. He'll take this bug, I'll be on the next one.
Attachment #682709 - Flags: feedback?(dteller)
Comment on attachment 682709 [details] [diff] [review]
Telemetry Probe

>diff --git a/toolkit/components/telemetry/Histograms.json b/toolkit/components/telemetry/Histograms.json
>+  },
>+  "CHECK_ADDONS_MODIFIED_MS": {
>+		"kind": "exponential",
>+		"high": "5000"
>+		"n_buckets": 30,
>+		"description": "Time (ms) it takes to figure out extension last modified time"
>+  },

- Use spaces instead of tabs
- Just a small nitpick: we can probably use fewer buckets here, maybe 10 or 15


>diff --git a/toolkit/mozapps/extensions/XPIProvider.jsm b/toolkit/mozapps/extensions/XPIProvider.jsm
>--- a/toolkit/mozapps/extensions/XPIProvider.jsm
>+++ b/toolkit/mozapps/extensions/XPIProvider.jsm
>+    let telemetry = Services.telemetry;
>+    telemetry.getHistogramById("CHECK_ADDONS_MODIFIED_MS").add(new Date() - telemetryCaptureTime);

You need to break this up a bit and you need a try-except block.. an exception is very unlikely here as long as the histogram exists but we don't want to ever risk exceptions in chrome code
Attachment #682709 - Flags: feedback?(vdjeric)
(In reply to Vladan Djeric (:vladan) from comment #11)
> >+    telemetry.getHistogramById("CHECK_ADDONS_MODIFIED_MS").add(new Date() - telemetryCaptureTime);
> 
> You need to break this up a bit and you need a try-except block.. an
> exception is very unlikely here as long as the histogram exists but we don't
> want to ever risk exceptions in chrome code

That seems far too conservative of a policy. What could realistically cause that to throw an exception? We already call getHistogramById() all over the place without a try/catch, and sprinkling them all over the place without a clear need doesn't sound ideal either.
(In reply to :Gavin Sharp (use gavin@gavinsharp.com for email) from comment #12)
> That seems far too conservative of a policy. What could realistically cause
> that to throw an exception? We already call getHistogramById() all over the
> place without a try/catch, and sprinkling them all over the place without a
> clear need doesn't sound ideal either.

Maybe you're right. The histogram name would have to by typo-ed in the getHistogramById call or the histogram would have to be missing or contain incorrect parameters, and I guess in those cases it might be preferable to fail visibly.
Nagarjuna, can you make the changes above and we'll get this landed :)
Attached patch Telemetry ProbeSplinter Review
Sorry vlad! Was kinda caught up with some work at uni (don't get me started) ! Hope this is fine!

PS Sorry for the relatively low metadata associated with the patch...my MQ has gone for a toss. Fixing it!
Attachment #682709 - Attachment is obsolete: true
Attachment #685184 - Flags: review?(vdjeric)
https://hg.mozilla.org/mozilla-central/rev/4af18f114939
Assignee: nobody → junky.argonaut
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla20
Reopening this bug as we have only landed the probe, not the fix
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Assignee: junky.argonaut → nobody
(In reply to Vladan Djeric (:vladan) from comment #18)
> Reopening this bug as we have only landed the probe, not the fix

To prevent the merge tool from closing bugs, you can use [leave open] in the bug whiteboard :-)
Given that we only have this data for the nightly channel(thus less addons), it  be can amazingly slow to do this check. http://is.gd/iO7VnY over ~6.5% startups take over 775ms.

Thanks for the probe, Infinity.
Infinity, Taras and Vladan asked me to look into this as well. I have some ideas for additional telemetry probes - email me or catch me on IRC (irving in #perf)

What I'm thinking of are:

* Count of packed (xpi) vs. unpacked extensions

* Extensions that are discovered to have updated file timestamps at startup (names if possible, otherwise count)

* Unpacked extensions where other files are updated but install.rdf is not (name if possible, else count)

* whether the extension DB needed to be updated at startup, and (if we can figure it out) the reason why
When we update the plugin DB at startup time, we run the entire scan a second time at http://dxr.mozilla.org/mozilla-central/toolkit/mozapps/extensions/XPIProvider.jsm.html#l2895 (hopefully faster because all the directories should be in the OS disk cache)
(In reply to Mike Hommey [:glandium] from comment #7)
> (In reply to Dave Townsend (:Mossop) from comment #1)
> > This could cause bustage when a third-party app or developer changes the
> > extension's files and we don't properly clear the startup cache.
> 
> I think it's fine to break third party apps that would do that. As for
> developers, if we can solve the problem by adding a pref to disable startup
> cache for them to use when they want to fiddle with addons in-place.

Is the --purgecaches command line option good enough for that, or do we really need a pref?
Based on conversations with Vladan and Taras, I'm going to draft a patch that uses a pref to choose either complete scan or check only install.rdf
Assignee: nobody → irving
Target Milestone: mozilla20 → ---
This patch requires the telemetry probe patch from bug 810146 be applied first.

For now, the default is to do the complete scan (existing behaviour); you need to manually set the "extensions.scanUnpacked" preference to false to change to not-scanning. I still check the timestamp on the root directory (for unpacked) or XPI file (packed), mostly to help generate the telemetry for 810146.
Attachment #706059 - Flags: feedback?(vdjeric)
Attachment #706059 - Flags: feedback?(taras.mozilla)
Comment on attachment 706059 [details] [diff] [review]
Control whether to recursively scan unpacked addons with a pref

Review of attachment 706059 [details] [diff] [review]:
-----------------------------------------------------------------

::: toolkit/mozapps/extensions/XPIProvider.jsm
@@ +1836,5 @@
> +      if (scanUnpacked)
> +        state.mtime = recursiveLastModifiedTime(file);
> +      else
> +        // get the mtime of the .xpi file or parent directory
> +        state.mtime = file.lastModifiedTime;

Certain filesystems (notably FAT) don't alter the modification time of a directory when its contents change (the whole reason we do a recursive scan). If the extension is unpacked you should at least use the install.rdf modification time.
Attachment #706059 - Flags: feedback-
Comment on attachment 706059 [details] [diff] [review]
Control whether to recursively scan unpacked addons with a pref

I agree with Dave about not relying on direction mod times for anything. I think strictly checking install.rdf is the way go.
Attachment #706059 - Flags: feedback?(taras.mozilla) → feedback-
Good point about the directory modification time. I've reorganized the logic and added some comments to make it more obvious what timestamps we're using for what purpose, and to not use the directory timestamp.
Attachment #706059 - Attachment is obsolete: true
Attachment #706059 - Flags: feedback?(vdjeric)
Attachment #706512 - Flags: review?(taras.mozilla)
Attachment #706512 - Flags: review?(dtownsend+bugmail)
Comment on attachment 706512 [details] [diff] [review]
Control whether to recursively scan unpacked addons with a pref (v2)

Review of attachment 706512 [details] [diff] [review]:
-----------------------------------------------------------------

::: toolkit/mozapps/extensions/XPIProvider.jsm
@@ +1838,5 @@
>        };
> +
> +      // the logic we want here is:
> +      // if scan, mod time is recursive and rdfTime is remembered for the unpacked addon telemetry
> +      // if !scan, mod time is: install.rdf if unpacked, foo.xpi if packed

s/scan/scanUnpacked/
s/mod time/mtime/

@@ +1860,5 @@
> +          // this is an unpacked extension
> +          state.mtime = rdfTime;
> +        else
> +          // get the mtime of the .xpi file
> +          state.mtime = file.lastModifiedTime;

By not setting state.rdfTime in this path you're messing up telemetry readings for unpacked add-ons. Just always set it outside of the if blocks.

@@ +1880,5 @@
>     */
>    getInstallLocationStates: function XPI_getInstallLocationStates() {
>      let states = [];
> +    let scanUnpacked = Prefs.getBoolPref(PREF_XPI_SCAN_UNPACKED, true);
> +    

Nit: whitespace
Attachment #706512 - Flags: review?(dtownsend+bugmail) → review+
Fixed :mossop's comments.

Based on a conversation with Vladan, we want to put this on hold until we get a clearer picture from the telemetry probes in bug 810146 before we make changes to directory scanning.
Attachment #706512 - Attachment is obsolete: true
Attachment #706512 - Flags: review?(taras.mozilla)
Whiteboard: [Snappy:P1] → [Snappy:P1] c=startup_addons u= p=
Depends on: 940014
Depends on: 930548
Let's use add-on signing as a way to make this happen. Signed add-ons should not be allowed to modify their contents, so we have the option of either enforcing that via the developer agreement, or checking the timestamp of the manifest rather than recursively scanning.

We'll theoretically be scanning for checksum mismatches in the background after startup, so any add-ons which don't match their signatures will be disabled in any case.

There's still the question of developer workflow, but it's a much easier one to solve than the general case.
Depends on: 1038072
(In reply to Kris Maglione [:kmag] from comment #31)
> Let's use add-on signing as a way to make this happen.
> ...
> There's still the question of developer workflow, but it's a much easier one
> to solve than the general case.

Are you saying we should switch to signed addons in order to never scan recursively?

Signed addons has a very big effect on developers, and a decision to move to signed addons policy should not be based solely, or at all, on a need to never scan recursively IMO.

Such a big move needs much wider consensus, or at the very least IMO some proper discussion.
(In reply to Avi Halachmi (:avih) from comment #32)
> Are you saying we should switch to signed addons in order to never scan
> recursively?

It's the other way around. We're moving to signed add-ons, so that can be used to avoid the recursive scan.

> Signed addons has a very big effect on developers, and a decision to move to
> signed addons policy should not be based solely, or at all, on a need to
> never scan recursively IMO.
> 
> Such a big move needs much wider consensus, or at the very least IMO some
> proper discussion.

The discussion is happening here: https://groups.google.com/forum/#!forum/mozilla.addons.user-experience. It should move to a broader audience soon.
Assignee: irving → nobody
Whiteboard: [Snappy:P1] c=startup_addons u= p= → [fxperf][Snappy:P1] c=startup_addons u= p=
This is irrelevant now that we (mostly) don't support unpacked extensions.
We have related issues about fixing other aspects of addon manager startup, but I think this can be safely closed.
Status: REOPENED → RESOLVED
Closed: 7 years ago2 years ago
Resolution: --- → INVALID
I actually fixed this ages ago.
Resolution: INVALID → FIXED
Whiteboard: [fxperf][Snappy:P1] c=startup_addons u= p= → [Snappy:P1] c=startup_addons u= p=
Assignee: nobody → junky.argonaut
You need to log in before you can comment on or make changes to this bug.