Last Comment Bug 952543 - Report startup exceptions in AddonManager and XPIProvider through telemetry
: Report startup exceptions in AddonManager and XPIProvider through telemetry
Status: RESOLVED FIXED
:
Product: Toolkit
Classification: Components
Component: Add-ons Manager (show other bugs)
: unspecified
: All All
-- normal (vote)
: mozilla29
Assigned To: :Irving Reid (No longer working on Firefox)
:
: Andy McKay [:andym]
Mentors:
Depends on:
Blocks: AsyncShutdown 1071792 972852 985998 986000 986080 986104
  Show dependency treegraph
 
Reported: 2013-12-20 09:26 PST by :Irving Reid (No longer working on Firefox)
Modified: 2014-09-23 12:39 PDT (History)
5 users (show)
ryanvm: in‑testsuite-
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---


Attachments
Catch exceptions in several places and record in telemetry (8.90 KB, patch)
2013-12-20 11:54 PST, :Irving Reid (No longer working on Firefox)
dtownsend: review+
vladan.bugzilla: feedback+
Details | Diff | Splinter Review
Record exceptions in telemetry, without depending on AddonLogging.jsm (26.63 KB, patch)
2014-01-07 13:34 PST, :Irving Reid (No longer working on Firefox)
dtownsend: review+
Details | Diff | Splinter Review
Telemetry for add-on manager exceptions, nit fixed for check-in (26.63 KB, patch)
2014-01-08 09:11 PST, :Irving Reid (No longer working on Firefox)
irving: review+
Details | Diff | Splinter Review
Record exceptions in telemetry, test failure fixed (27.78 KB, patch)
2014-01-09 12:31 PST, :Irving Reid (No longer working on Firefox)
irving: review+
Details | Diff | Splinter Review

Description User image :Irving Reid (No longer working on Firefox) 2013-12-20 09:26:57 PST
Telemetry review of the simple measures AMI_startup_end, XPI_startup_end, and XPI_bootstrap_end show that in roughly 1 in 10 000 Firefox Nightly / Windows sessions, one of these phases of the start up process does not complete - the _end timestamp is not in the telemetry packet, even though other later timestamps are present.

A triage pass over bugs in the Add-on Manager component didn't find any obvious reports of problems, so I'd like to record an exception summary in the simpleMeasures/addonManager section to see if we can identify any problems based on reports from the field.

Open question: do we record a one line entry, exception text and file/line, or a full stack? Note that Android telemetry does include some stacks (e.g. bug 826053, for Application Not Responding events) but these are Java, not JS.
Comment 1 User image :Irving Reid (No longer working on Firefox) 2013-12-20 11:54:48 PST
Created attachment 8350731 [details] [diff] [review]
Catch exceptions in several places and record in telemetry
Comment 2 User image Dave Townsend [:mossop] 2014-01-02 09:21:16 PST
Comment on attachment 8350731 [details] [diff] [review]
Catch exceptions in several places and record in telemetry

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

::: toolkit/mozapps/extensions/AddonManager.jsm
@@ +469,5 @@
>     * Initializes the AddonManager, loading any known providers and initializing
>     * them.
>     */
>    startup: function AMI_startup() {
> +   try {

Nice for review but before landing make the indent right

@@ +576,5 @@
>          Components.utils.import(url, {});
>        }
>        catch (e) {
> +        AddonManagerPrivate.recordSimpleMeasure("exception",
> +          LogManager.formatLogMessage("ERROR", "AMI", "provider " + url + " load failed", e));

These exceptions are already caught, doesn't that mean they can't be the cause of problems?

@@ +599,5 @@
>          delete this.startupChanges[type];
>      }
>  
> +      this.foo.bar();
> +    

I suspect you didn't mean to include this in the patch
Comment 3 User image Vladan Djeric (:vladan) 2014-01-02 16:09:02 PST
Comment on attachment 8350731 [details] [diff] [review]
Catch exceptions in several places and record in telemetry

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

Aside from dtownsend's remarks, looks good
Comment 4 User image :Irving Reid (No longer working on Firefox) 2014-01-07 13:34:43 PST
Created attachment 8356781 [details] [diff] [review]
Record exceptions in telemetry, without depending on AddonLogging.jsm

I was just wrapping up testing my cleanup from these comments when I remembered bug 661982, and figured that if I'm helping to get rid of AddonLogging.jsm I'd better not add a new dependency on it in this patch. I changed things to record the exception details as a JSON blob rather than a string.

(In reply to Dave Townsend (:Mossop) from comment #2)
> Review of attachment 8350731 [details] [diff] [review]:
> -----------------------------------------------------------------
> @@ +576,5 @@
> >          Components.utils.import(url, {});
> >        }
> >        catch (e) {
> > +        AddonManagerPrivate.recordSimpleMeasure("exception",
> > +          LogManager.formatLogMessage("ERROR", "AMI", "provider " + url + " load failed", e));
> 
> These exceptions are already caught, doesn't that mean they can't be the
> cause of problems?

Yes, but I figured an exception here is serious enough that we'd be interested to find out about it.

> @@ +599,5 @@
> >          delete this.startupChanges[type];
> >      }
> >  
> > +      this.foo.bar();
> > +    
> 
> I suspect you didn't mean to include this in the patch

Oops, that was how I caused the exceptions for manual testing...
Comment 5 User image Dave Townsend [:mossop] 2014-01-07 16:18:40 PST
Comment on attachment 8356781 [details] [diff] [review]
Record exceptions in telemetry, without depending on AddonLogging.jsm

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

::: toolkit/mozapps/extensions/AddonManager.jsm
@@ +2239,5 @@
> +        report.file = aException.fileName;
> +        report.line = aException.lineNumber;
> +      }
> +    }
> +      

Nit: Trailing whitespace
Comment 6 User image :Irving Reid (No longer working on Firefox) 2014-01-08 09:11:40 PST
Created attachment 8357205 [details] [diff] [review]
Telemetry for add-on manager exceptions, nit fixed for check-in

Carrying forward Dave's r+ in comment 5
Comment 7 User image :Irving Reid (No longer working on Firefox) 2014-01-08 09:12:09 PST
This doesn't need a build of its own
Comment 8 User image Ryan VanderMeulen [:RyanVM] 2014-01-08 13:01:46 PST
https://hg.mozilla.org/integration/fx-team/rev/c260f6234cc1
Comment 10 User image :Irving Reid (No longer working on Firefox) 2014-01-09 12:31:50 PST
Created attachment 8357954 [details] [diff] [review]
Record exceptions in telemetry, test failure fixed

Bah, test_shutdown.js / test_functions() assumes that every method in AddonManager and AddonManagerPrivate should throw a NOT_INITIALIZED exception, unless the method is explicitly ignored in the test. This is the n+1'th time I've been burned by this.

Updated patch just adds AddonManagerPrivate.recordException() to the ignore list in test_shutdown.js; rs=mossop in IRC #fx-team.
Comment 11 User image Ryan VanderMeulen [:RyanVM] 2014-01-10 05:17:38 PST
https://hg.mozilla.org/integration/fx-team/rev/e977e3694048
Comment 12 User image Ryan VanderMeulen [:RyanVM] 2014-01-10 11:45:13 PST
https://hg.mozilla.org/mozilla-central/rev/e977e3694048

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