574094 - Send "Install Age" (InstallTime) with crash reports

Status: RESOLVED FIXED

(Camino Graveyard :: General, enhancement)

Description

[Smokey Ardisson (offline for a while; not following bugs - do not email)]

Socorro has started to display an "Install Age" value on crash reports; currently for every Camino crash I've looked at, it's identical to the uptime, and I find that hard to believe ;)  It seems like there's some sort of additional value we should send with crashes to report how long a given Camino version has been installed.

I'm not sure what sorts of interesting things it would tell us, or additional Socorro reports having a correct value there would enable, but ENH.

Comment 1

[Smokey Ardisson (offline for a while; not following bugs - do not email)]

Seems like this is done in 
http://mxr.mozilla.org/mozilla1.9.2/source/toolkit/crashreporter/nsExceptionHandler.cpp#669
http://mxr.mozilla.org/mozilla1.9.2/source/toolkit/crashreporter/nsExceptionHandler.cpp#682 and http://mxr.mozilla.org/mozilla1.9.2/source/toolkit/crashreporter/nsExceptionHandler.cpp#732

Or, in human terms, it writes an InstallTime<BUILDID> file containing a Unix timestamp on first startup of the app with that buildid, and then at some point read back and sent with the crash.  It was originally implemented in bug 376720 (and modified later).

Per bug 488513 comment 8, we also don't have LastCrash date/time support; for reference, in Core that was implemented in bug 376721.  That's also been surfaced in Socorro since I lasted looked.  (We can spin this off to a separate bug if desired when this one gets fixed, but mentioning it in a related and open bug is better than it being lost in bug 488513 comment 8 ;) )

Comment 2

[Smokey Ardisson (offline for a while; not following bugs - do not email)]

Attachment: First cut at IntallTime

While trying to see if I could figure out anything we could do to fix bug 488618 (in hopes of finding something useful for the evil bug 636261), I discovered it was "trivial" to implement InstallTime.

(I think LastCrash is going to require some changes in Breakpad to support, though I didn't dig deep enough to really see; OTOH, Breakpad will have the info it needs to write a LastCrash placeholder--buildID and crash time--so changes there could well be "trivial", plus another "trivial" file read+parameter set here in BreakpadWrapper…)

So…

This patch probably needs some architecture/design love in my new methods, where I don't even know enough to ask the right questions ;-)  

Beyond that, one thing that specifically comes to mind: what's the best way to go about storing this data?  Firefox uses one file per build, InstallTime<BuildID>, and this patch copys that (save the prefix).  Ordinary users won't run many builds, so there won't be a proliferation of such files; nightly users will end up with lots of them.  Writing (and reading) a single file/build is certainly easier for me to implement, but would a plist be better (or faster, etc.)?  In either case, do we need a "purge" mechanism, so we don't end up with tons of files forever (or giant plists), à la bug 388649 and bug 410143?

Also, is there anything saner to do in the failure cases?

FWIW, https://crash-stats.mozilla.com/report/index/215c6995-b88e-4b82-a5e4-745f42110922 shows InstallTime in action (Install Time/Install Age, which now differ from uptime), as well as my hard-coded "Notes" field :P

Comment 3

[Smokey Ardisson (offline for a while; not following bugs - do not email)]

Heh, looking back at the patch, I already see I have capitalization issues in my method names :P

Comment 4

[Stuart Morgan]

So I like the idea of a plist instead of files, and it would make some parts much easier actually (one file name, no need to convert dates to strings, just do a dictionary lookup by build ID after reading it). And I think we should probably just keep it in our profile folder, since we aren't trying to make something really generic that doesn't know about profiles, supports different applications, etc., although I'm not attached to that.

We could probably go even easier though, and just have a single pref that we reset when we're launching a new build, since we probably don't care about the edge case of people flipping back and forth. Thoughts?

Comment 5

[Smokey Ardisson (offline for a while; not following bugs - do not email)]

(In reply to Stuart Morgan from comment #4)
> should probably just keep it in our profile folder, since we aren't trying
> to make something really generic that doesn't know about profiles, supports
> different applications, etc., although I'm not attached to that.

I was trying to keep all the crash reporting detritus in the same place, but that argument makes sense from a high-level point of view.

OTOH, I think from an implementation and usage perspective, it's somewhat less compelling: to stick the file in the profile, we'd have to do the reading/writing from somewhere later on in the startup process that knows about the profile, though, since Breakpad gets set up very early in the launch sequence (BreakpadWrapper is called in main.m), and then call back to BreakpadWrapper to set the value (like we do for the URL) at some point once we have Gecko/a profile.  For an early-crash-on-launch when upgrading to a new version (like 2.0 and the font crashes, maybe?), we'd likely never get InstallTime set.

Also, we try to be app-agnostic--in the sense we read keys and not hard-code "Camino"--in a lot of places in Camino code.  On the one hand the era of embedding Camino/CHBrowserView is at an end; on the other hand, why start being inconsistent unless there's a real penalty to the older style?

And we're still going to have to convert the dates to strings when we pass to Socorro, because Breakpad needs a string as the server URL parameter, and Socorro can't handle decimal values for InstallTime (I learned that the hard way).

> We could probably go even easier though, and just have a single pref that we
> reset when we're launching a new build, since we probably don't care about
> the edge case of people flipping back and forth. Thoughts?

Generally that seems OK, although I wonder how often we get people switching to, say, a beta and then back to release when they find something that doesn't work in the beta.

Other than that, though, I'm always using separate profiles for any testing and going forward otherwise, so it wouldn't leave *me* with a bad value.

But I think that this solution also has some of the same drawbacks as storing the file in the plist, in that we'd have to read/write the value later on and we could die before we get there.

I'm open to doing whatever method you think is best, but the fact that (it seems to me that) a profile file or a pref solution means we have to get Gecko up and running before we can read/write/set the value, and thereby could end up with the value not getting set, bothers the QA side of me a lot.  One of the places that this value is most useful is in differentiating between "random startup crash" and "startup crash that happens when installing a new version" (new-version is not always going to be significant, of course, but we can't tell unless we know).

So, given all that, I think I'd rather get this value read/written/set as early as possible.  If you don't object to my counter-arguments, I'll switch to storing these as parts of a plist in the crash dumps folder.

(The wrinkle/drawback to that, though, vs. any of the per-profile solutions, is that we'll need to store all seen builds, or we'll "reset" the time for anyone who ever tests another build, even via Troubleshoot Camino, which would defeat having InstallTime at all.  But storing them all leaves no worse off than we were file-per-build in some ways, and at least less visible clutter in other ways…)

Comment 6

[Smokey Ardisson (offline for a while; not following bugs - do not email)]

Comment on attachment 561825 [details] [diff] [review]
First cut at IntallTime

Cancelling this review; per irc discussion last night, we'll go with

[02:43am] smorgan: So plist (or individual files if the plist turns out to suck) in the breakpad folder works for me

Comment 7

[Smokey Ardisson (offline for a while; not following bugs - do not email)]

Attachment: Smokey's First Property List

Here's the plist version.  It's a little bit more complicated, because there are more steps that can (potentially?) fail.  There are probably still some architectural improvements that can be made, but I'm not sure how to make them.  And, of course, questions!

1) The two places I make NSData, do the NSData items need to be null-checked before using them?  (Other examples in the tree don't seem to be.)

2) What's the correct/safe thing to do in the "we know a file exists, but we somehow didn't get useable data out of it" error case (the last else in |versionFirstInstalledTime|)?

3) I call

 installTime = [self setUpInstalledTimeForNewVersion];
 [installTimeData setValue:installTime forKey:buildID];
 [self writeInstalledTimeData:installTimeData toFile:installTimeFilePath];

in several places (though not always immediately after each other), but I couldn't figure out a way to factor them out into their own method cleanly (in some cases there's a existing dictionary that needs to be passed and appended to, while in others we just have the current install time, which needs to be made into a dictionary with the corresponding build ID.  And any helper method would need to know the file path.  So we'd need to pass the helper a variable number of variables based on what I know :-P  Is there a way to have a sane helper for that part (and if so, is it worth it)?

4) On the flip side, is |writeInstalledTimeData:toFile:| an over-helperization?

5) The NSPropertyListSerialization propertyListFromData docs lie; they claim that the mutabilityOption parameter is unused/ignored and we should just pass "0", but that throws and crashes (at least when I want to make a mutable dictionary from the existing data so I can append new build/time to it if necessary).  So I chose the constant that seemed like its jargony description described the behavior I wanted, but I couldn't find a decoder ring for the jargon, so dunno if I picked correctly.

I think that's all the specific questions.  I've tested all but the utter-failure condition and seen that the right thing was happening; not sure how to test that exactly.

Comment 8

[Stuart Morgan]

Comment on attachment 562224 [details] [diff] [review]
Smokey's First Property List

>+  NSString *libraryPath = [NSSearchPathForDirectoriesInDomains(NSLibraryDirectory,
>+                              NSUserDomainMask, YES) objectAtIndex:0];
>+  NSString* installTimeFilePath = [[[libraryPath stringByAppendingPathComponent:@"Breakpad"]
>+                                                 stringByAppendingPathComponent:appName]
>+                                                 stringByAppendingPathComponent:@"InstallTime.plist"];

Make all this into a helper function that returns the path.

>+  NSString* installTime;

Initialize this to nil; the logic is complex enough that it makes me nervous not to.

>+    installTime = [self setUpInstalledTimeForNewVersion];
>+    NSMutableDictionary* installTimeData = [NSMutableDictionary dictionary];
>+    [installTimeData setValue:installTime forKey:buildID];
>+    [self writeInstalledTimeData:installTimeData toFile:installTimeFilePath];

3) You could make this into a helper function that takes an NSMutableDictionary and the build ID, and does the writing (getting the path by calling the helper you made for the earlier code, and getting the time from your existing helper). In the cases where we're adding, you pass the old dictionary. In the case where you are making a new file, pass an empty NSMutableDictionary ([NSMutableDictionary dictionary]).

>+    NSData* stateData = [NSData dataWithContentsOfFile:installTimeFilePath];
>+    // XXsa does |stateData| need null-checking?

1) Yes (generally a bad idea to pass potentially-nil things to Apple APIs)

>+    if (installTimeData) {
...
>+    else {
...
>+      // XXsa We've declared |installTimeData| but failed to read it; is it
>+      // safe to |setValue:forKey:|?

It's safe, but it doesn't do anything; it would be sending a message to nil, which would be a no-op.

I'd suggest structuring the code like this, roughly, so you can group the operations that are the same:
NSMutableDictionary* installTimes = nil;
if (<the file exists>) {
  <read the data>
  if (<got data>) {
    installTimes = <convert data to plist>
  }
}

if (installTimes) {
  // yay, success@
} else {
  // something failed; start a new file.
}

2) Stomp it and start over; a file we can't understand is no good to us.

>+- (NSString*)setUpInstalledTimeForNewVersion

Call this something like currentEpochTimeAsString since that's really what it is.

>+- (void)writeInstalledTimeData:(NSDictionary*)installData toFile:(NSString*)filePath

4) This seems fine to me; small clearly named functions are good for readability :)

5) You decoded correctly.

Comment 9

[Smokey Ardisson (offline for a while; not following bugs - do not email)]

Attachment: Now with Stuart-style flow control

Stuart, thanks for all the comments and pointers; your flow control makes my head spin a whole lot less :-)

I think I only have two questions with this go-round:

1) In |writeInstallTimesToFile:|, is there anything we can/should do if converting the plist to NSData fails, or if writing NSData to the file fails?  (Will we even know in the latter case?)  Hopefully any failure we can't handle will produce abject garbage that our reading will bail on later…

2) In |isValidSocorroTimeString:|, is inverting the decimal set and |rangeOfCharacterFromSet:| performant (because we're making a set of every character in the world except those 10, and then looking for any of them in the timeString)?  We do the same thing in History prefPane's |isPartialStringValid:|, so I guess it's probably OK, but it seems dodgy to me.

Alternatively, is there a better way to ensure that all the characters in timeString are from the [0-9] set?

(I hit this validation case trying to make sure that |valueForKey:| returned something, and used "" in my sample plist and made Socorro cry, and I already knew from my initial development that Socorro cries if you feed it a time with decimals.)

Comment 10

[Stuart Morgan]

Comment on attachment 563281 [details] [diff] [review]
Now with Stuart-style flow control

sr=smorgan with some minor changes; looks good!

1) No, we'll just handle it on the reading side.
2) Probably not, in the sense that I'd find a better solution if this were being called a whole lot, but for once per run it shouldn't be a big deal.

>+    if ((!currentBuildInstallTime) ||
>+        (![self isValidSocorroTimeString:currentBuildInstallTime]))

Remove the inner parens on these, since each is a single condition.

>+      currentBuildInstallTime = [self currentEpochTimeAsString];
>+      [self writeInstallTime:currentBuildInstallTime
...
>+    currentBuildInstallTime = [self currentEpochTimeAsString];
>+    [self writeInstallTime:currentBuildInstallTime

Simplify here by removing the install time argument and having the helper call [self currentEpockTimeAsString], since that's the only way it's ever used. (Sorry, much easier to see these things when looking at code than when making stuff up in comments ;) )

>+- (NSString*)currentEpochTimeAsString
>+{
>+  NSTimeInterval now = [[NSDate date] timeIntervalSince1970];
>+  NSString* nowString = [NSString stringWithFormat:@"%.f", now];
>+  return nowString;

Combine the last two lines (return [NSString stringWithFormat:...];)

>+      ([timeString length] < 10) ||
>+      ([timeString length] > 10))

Also known as [timeString length] != 10 ;)

>+  {
>+    return NO;
>+  }
>+  return YES;

I'd make the whole method:

return ([timeString rangeOfCharacterFromSet:nonDigitSet].location != NSNotFound) &&
        [timeString length] == 10);
                                                     errorDescription:NULL];
>+  if (dataFromPlist) {
>+    [dataFromPlist writeToFile:[self installTimeFilePath] atomically:YES];
>+  }

Camino style generally prefers no {} on one-line ifs.

Comment 11

[Smokey Ardisson (offline for a while; not following bugs - do not email)]

(In reply to Stuart Morgan from comment #10)

> >+      currentBuildInstallTime = [self currentEpochTimeAsString];
> >+      [self writeInstallTime:currentBuildInstallTime
> ...
> >+    currentBuildInstallTime = [self currentEpochTimeAsString];
> >+    [self writeInstallTime:currentBuildInstallTime
> 
> Simplify here by removing the install time argument and having the helper
> call [self currentEpockTimeAsString], since that's the only way it's ever
> used.

But |versionFirstInstalledTime| has to return currentBuildInstallTime. Do you want me to change |writeInstallTime:| to return currentBuildInstallTime when it's done writing the dictionary and calling out to write the file, so that |versionFirstInstalledTime| will be able to return the time in those two cases?  That seems…odd, flow-wise.  This seems slightly redundant, but overall a more logical grouping, IMO.

> >+  if (dataFromPlist) {
> >+    [dataFromPlist writeToFile:[self installTimeFilePath] atomically:YES];
> >+  }
> 
> Camino style generally prefers no {} on one-line ifs.

Oops; there was a comment in there when I was (re)writing that code, and I forgot to remove the braces when deleting the comment ;-)

Comment 12

[Stuart Morgan]

Yeah, I'm an idiot; ignore me. Tunnel-vision review fail.

Comment 13

[Smokey Ardisson (offline for a while; not following bugs - do not email)]

(In reply to Stuart Morgan from comment #10)
> I'd make the whole method:
> 
> return ([timeString rangeOfCharacterFromSet:nonDigitSet].location !=  NSNotFound) &&
>         [timeString length] == 10);

By which I assume you meant 

> return (([timeString rangeOfCharacterFromSet:nonDigitSet].location == NSNotFound) &&
>         ([timeString length] == 10));  

(or some variation thereof with the parens, but I think each part is a two-part condition), since we want nonDigitSet items to be NotFound, just like we want length to be 10, right ;)  I'd've caught that in the first comment if I was more awake, but double-checking the double-negatives definitely had to be a post-caffeine activity.

Thanks for the simplifications in the other places!

Landed all the changes (with the exception of the comment 11/12 discussion, and using the correction to |isValidSocorroTimeString:| in this comment; I can fix anything I misunderstood tomorrow): http://hg.mozilla.org/camino/rev/075fc17bc144

Comment 14

[Smokey Ardisson (offline for a while; not following bugs - do not email)]

Per irc, I did correct the logic correctly, and all six of the parens are actually superfluous due to precedence rules :O