1064480 - Telemetry regression in XPIDB_SAVES_LATE

Status: RESOLVED INACTIVE

(Toolkit :: Add-ons Manager, defect)

Description

[:Irving Reid (No longer working on Firefox)]

The telemetry regression dashboard at https://tbpl.mozilla.org/?tree=Try&rev=f9e54ceec78f&pusher=[e-mail] indicates a regression in the SIMPLE_MEASURES_XPIDB_SAVES_LATE measure on the 2014-08-20 nightly build.

This measure is 1 when the extensions.json data is dirty and needs to be written out at shutdown time; a regression indicates that something is likely changing add-on state that needs to be stored in the DB during shutdown.

At its peak (build IDs 08-25 to 08-31) as many as 75% of shutdowns have late writes, the number drops off again from 09-01 to 09-04 though I'm not sure yet whether that's an artifact of telemetry collection. Nightly 35 is averaging 27% of sessions with a late save (out of 142k submissions) so far.

http://telemetry.mozilla.org/#filter=nightly%2F34%2FSIMPLE_MEASURES_ADDONMANAGER_XPIDB_SAVES_LATE&aggregates=multiselect-all!Submissions!Mean!5th%20percentile!25th%20percentile!median!75th%20percentile!95th%20percentile&evoOver=Builds&locked=true&sanitize=true&renderhistogram=Graph

Comment 1

[:Irving Reid (No longer working on Firefox)]

bah, copypasta error on the regression dashboard, it's at http://vitillo.github.io/cerberus/dashboard/#2014-08-20SIMPLE_MEASURES_ADDONMANAGER_XPIDB_SAVES_LATE

Comment 2

[:Irving Reid (No longer working on Firefox)]

Attachment: Diagnostic telemetry for late XPI database saves

Can't find any relevant code changes that might have triggered this regression; I'd like to land some temporary telemetry to see if Nightly will tell us what's up.

If this proves useful, we might want to code up a stack summarizer that gives us a more concise identification of who called into the Addon Manager rather than collecting full (rather large) stacks like this patch does; otherwise I plan to back it out before it graduates from Nightly.

Comment 3

[Dave Townsend [:mossop]]

(In reply to :Irving Reid from comment #1)
> bah, copypasta error on the regression dashboard, it's at
> http://vitillo.github.io/cerberus/dashboard/#2014-08-
> 20SIMPLE_MEASURES_ADDONMANAGER_XPIDB_SAVES_LATE

I can't see that page either :(

Comment 4

[:Irving Reid (No longer working on Firefox)]

The dashboards just moved, now at http://mozilla.github.io/cerberus/dashboard/#2014-08-20SIMPLE_MEASURES_ADDONMANAGER_XPIDB_SAVES_LATE

Comment 5

[:Irving Reid (No longer working on Firefox)]

https://tbpl.mozilla.org/?tree=Try&rev=dfc290f6d73c

Comment 6

[:Irving Reid (No longer working on Firefox)]

Diagnostic telemetry landed: https://hg.mozilla.org/integration/fx-team/rev/2e00bcf7448d

Comment 7

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/2e00bcf7448d

Comment 8

[:Irving Reid (No longer working on Firefox)]

Attachment: Telemetry stacks for late XPI database changes

Here's the stacks collected by Telemetry. Unfortunately, by the time the probe rolled out to Nightly, the spike in late saves had gone away.

The rate dropped off again sharply around Sept. 8 / 9 nightly build IDs; it's a bit hard to tell from the dashboard whether the drop correlates better with submission date or build ID.

There was a Nightly telemetry experiment running from Aug 14 - Sept. 10, see https://telemetry-experiment.cdn.mozilla.net/ and bug 1052714. I suspect that was the cause, and that there's either a code path that disables and/or removes the experiment at shut down time, or a path that leaves the XPI Provider thinking there are pending changes that need to be cleaned up at shut down.

This isn't a major issue (a few extra milliseconds of shut down delay) so I don't think it's worth a lot more time.

Comment 9

[BMO Automation]

Per policy at https://wiki.mozilla.org/Bug_Triage/Projects/Bug_Handling/Bug_Husbandry#Inactive_Bugs. If this bug is not an enhancement request or a bug not present in a supported release of Firefox, then it may be reopened.