Backed out changeset 419e1a311337 (bug 1314378)

startupcache/StartupCache.cpp

@@ -113,6 +113,7 @@ StartupCache::InitSingleton()
 StaticRefPtr<StartupCache> StartupCache::gStartupCache;
 bool StartupCache::gShutdownInitiated;
 bool StartupCache::gIgnoreDiskCache;
+enum StartupCache::TelemetrifyAge StartupCache::gPostFlushAgeAction = StartupCache::IGNORE_AGE;
 
 NS_IMPL_ISUPPORTS(StartupCache, nsIMemoryReporter)
 
@@ -210,7 +211,7 @@ StartupCache::Init()
                                      false);
   NS_ENSURE_SUCCESS(rv, rv);
 
-  rv = LoadArchive();
+  rv = LoadArchive(RECORD_AGE);
 
   // Sometimes we don't have a cache yet, that's ok.
   // If it's corrupted, just remove it and start over.
@@ -228,7 +229,7 @@ StartupCache::Init()
  * LoadArchive can be called from the main thread or while reloading cache on write thread.
  */
 nsresult
-StartupCache::LoadArchive()
+StartupCache::LoadArchive(enum TelemetrifyAge flag)
 {
   if (gIgnoreDiskCache)
     return NS_ERROR_FAILURE;
@@ -241,6 +242,32 @@ StartupCache::LoadArchive()
   
   mArchive = new nsZipArchive();
   rv = mArchive->OpenArchive(mFile);
+  if (NS_FAILED(rv) || flag == IGNORE_AGE)
+    return rv;
+
+  nsCString comment;
+  if (!mArchive->GetComment(comment)) {
+    return rv;
+  }
+
+  const char *data;
+  size_t len = NS_CStringGetData(comment, &data);
+  PRTime creationStamp;
+  // We might not have a comment if the startup cache file was created
+  // before we started recording creation times in the comment.
+  if (len == sizeof(creationStamp)) {
+    memcpy(&creationStamp, data, len);
+    PRTime current = PR_Now();
+    int64_t diff = current - creationStamp;
+
+    // We can't use AccumulateTimeDelta here because we have no way of
+    // reifying a TimeStamp from creationStamp.
+    int64_t usec_per_hour = PR_USEC_PER_SEC * int64_t(3600);
+    int64_t hour_diff = (diff + usec_per_hour - 1) / usec_per_hour;
+    mozilla::Telemetry::Accumulate(Telemetry::STARTUP_CACHE_AGE_HOURS,
+                                   hour_diff);
+  }
+
   return rv;
 }
 
@@ -419,7 +446,7 @@ StartupCache::WriteToDisk()
 
   // If we didn't have an mArchive member, that means that we failed to
   // open the startup cache for reading.  Therefore, we need to record
-  // the time of creation in a zipfile comment; this has been useful for
+  // the time of creation in a zipfile comment; this will be useful for
   // Telemetry statistics.
   PRTime now = PR_Now();
   if (!mArchive) {
@@ -454,7 +481,7 @@ StartupCache::WriteToDisk()
   gIgnoreDiskCache = false;
 
   // Our reader's view of the archive is outdated now, reload it.
-  LoadArchive();
+  LoadArchive(gPostFlushAgeAction);
   
   return;
 }
@@ -470,10 +497,11 @@ StartupCache::InvalidateCache()
   if (NS_FAILED(rv) && rv != NS_ERROR_FILE_TARGET_DOES_NOT_EXIST &&
       rv != NS_ERROR_FILE_NOT_FOUND) {
     gIgnoreDiskCache = true;
+    mozilla::Telemetry::Accumulate(Telemetry::STARTUP_CACHE_INVALID, true);
     return;
   }
   gIgnoreDiskCache = false;
-  LoadArchive();
+  LoadArchive(gPostFlushAgeAction);
 }
 
 void
@@ -595,6 +623,13 @@ StartupCache::ResetStartupWriteTimer()
   return NS_OK;
 }
 
+nsresult
+StartupCache::RecordAgesAlways()
+{
+  gPostFlushAgeAction = RECORD_AGE;
+  return NS_OK;
+}
+
 // StartupCacheDebugOutputStream implementation
 #ifdef DEBUG
 NS_IMPL_ISUPPORTS(StartupCacheDebugOutputStream, nsIObjectOutputStream, 
@@ -784,5 +819,11 @@ StartupCacheWrapper::GetObserver(nsIObserver** obv) {
   return NS_OK;
 }
 
+nsresult
+StartupCacheWrapper::RecordAgesAlways() {
+  StartupCache *sc = StartupCache::GetSingleton();
+  return sc ? sc->RecordAgesAlways() : NS_ERROR_NOT_INITIALIZED;
+}
+
 } // namespace scache
 } // namespace mozilla

startupcache/StartupCache.h

@@ -129,6 +129,8 @@ public:
   nsresult GetDebugObjectOutputStream(nsIObjectOutputStream* aStream,
                                       nsIObjectOutputStream** outStream);
 
+  nsresult RecordAgesAlways();
+
   static StartupCache* GetSingleton();
   static void DeleteSingleton();
 
@@ -142,7 +144,13 @@ private:
   StartupCache();
   virtual ~StartupCache();
 
-  nsresult LoadArchive();
+  enum TelemetrifyAge {
+    IGNORE_AGE = 0,
+    RECORD_AGE = 1
+  };
+  static enum TelemetrifyAge gPostFlushAgeAction;
+
+  nsresult LoadArchive(enum TelemetrifyAge flag);
   nsresult Init();
   void WriteToDisk();
   nsresult ResetStartupWriteTimer();

startupcache/nsIStartupCache.idl

@@ -55,6 +55,10 @@ interface nsIStartupCache : nsISupports
   boolean startupWriteComplete();
   void resetStartupWriteTimer();
 
+  /* Instruct clients to always post cache ages to Telemetry, even in
+     cases where it would not normally make sense.  */
+  void recordAgesAlways();
+
   /* Allows clients to simulate the behavior of ObserverService. */
   readonly attribute nsIObserver observer;
 };

startupcache/test/TestStartupCache.cpp

@@ -410,6 +410,48 @@ int main(int argc, char** argv)
   int rv = 0;
   nsresult scrv;
 
+  // Register TestStartupCacheTelemetry
+  nsCOMPtr<nsIFile> manifest;
+  scrv = NS_GetSpecialDirectory(NS_GRE_DIR,
+                                getter_AddRefs(manifest));
+  if (NS_FAILED(scrv)) {
+    fail("NS_XPCOM_CURRENT_PROCESS_DIR");
+    return 1;
+  }
+
+#ifdef XP_MACOSX
+  nsCOMPtr<nsIFile> tempManifest;
+  manifest->Clone(getter_AddRefs(tempManifest));
+  manifest->AppendNative(
+    NS_LITERAL_CSTRING("TestStartupCacheTelemetry.manifest"));
+  bool exists;
+  manifest->Exists(&exists);
+  if (!exists) {
+    // Workaround for bug 1080338 in mozharness.
+    manifest = tempManifest.forget();
+    manifest->SetNativeLeafName(NS_LITERAL_CSTRING("MacOS"));
+    manifest->AppendNative(
+      NS_LITERAL_CSTRING("TestStartupCacheTelemetry.manifest"));
+  }
+#else
+  manifest->AppendNative(
+    NS_LITERAL_CSTRING("TestStartupCacheTelemetry.manifest"));
+#endif
+
+  XRE_AddManifestLocation(NS_APP_LOCATION, manifest);
+
+  nsCOMPtr<nsIObserver> telemetryThing =
+    do_GetService("@mozilla.org/testing/startup-cache-telemetry.js");
+  if (!telemetryThing) {
+    fail("telemetryThing");
+    return 1;
+  }
+  scrv = telemetryThing->Observe(nullptr, "save-initial", nullptr);
+  if (NS_FAILED(scrv)) {
+    fail("save-initial");
+    rv = 1;
+  }
+
   nsCOMPtr<nsIStartupCache> sc 
     = do_GetService("@mozilla.org/startupcache/cache;1", &scrv);
   if (NS_FAILED(scrv))
@@ -428,5 +470,11 @@ int main(int argc, char** argv)
   if (NS_FAILED(TestEarlyShutdown()))
     rv = 1;
 
+  scrv = telemetryThing->Observe(nullptr, "save-initial", nullptr);
+  if (NS_FAILED(scrv)) {
+    fail("check-final");
+    rv = 1;
+  }
+
   return rv;
 }

startupcache/test/TestStartupCacheTelemetry.js

@@ -0,0 +1,60 @@
+const Cc = Components.classes;
+const Ci = Components.interfaces;
+const Cu = Components.utils;
+
+Cu.import("resource://gre/modules/Services.jsm");
+Cu.import("resource://gre/modules/XPCOMUtils.jsm");
+
+function shouldHaveChanged(a, b)
+{
+  if (a.length != b.length) {
+    throw Error("TEST-UNEXPECTED-FAIL: telemetry count array size changed");
+  }
+
+  for (let i = 0; i < a.length; ++i) {
+    if (a[i] == b[i]) {
+      continue;
+    }
+    return; // something was different, that's all that matters
+  }
+  throw Error("TEST-UNEXPECTED-FAIL: telemetry data didn't change");
+}
+
+function TestStartupCacheTelemetry() { }
+
+TestStartupCacheTelemetry.prototype = {
+  classID: Components.ID("{73cbeffd-d6c7-42f0-aaf3-f176430dcfc8}"),
+  QueryInterface: XPCOMUtils.generateQI([Ci.nsIObserver]),
+
+  saveInitial: function() {
+    let t = Services.telemetry;
+    this._age = t.getHistogramById("STARTUP_CACHE_AGE_HOURS").snapshot.counts;
+    this._invalid = t.getHistogramById("STARTUP_CACHE_INVALID").snapshot.counts;
+  },
+
+  checkFinal: function() {
+    let t = Services.telemetry;
+    let newAge = t.getHistogramById("STARTUP_CACHE_AGE_HOURS").snapshot.counts;
+    shouldHaveChanged(this._age, newAge);
+
+    let newInvalid = t.getHistogramById("STARTUP_CACHE_INVALID").snapshot.counts;
+    shouldHaveChanged(this._invalid, newInvalid);
+  },
+
+  observe: function(subject, topic, data) {
+    switch (topic) {
+    case "save-initial":
+      this.saveInitial();
+      break;
+
+    case "check-final":
+      this.checkFinal();
+      break;
+
+    default:
+      throw Error("BADDOG, NO MILKBONE FOR YOU");
+    }
+  },
+};
+
+this.NSGetFactory = XPCOMUtils.generateNSGetFactory([TestStartupCacheTelemetry]);

startupcache/test/TestStartupCacheTelemetry.manifest

@@ -0,0 +1,2 @@
+component {73cbeffd-d6c7-42f0-aaf3-f176430dcfc8} TestStartupCacheTelemetry.js
+contract @mozilla.org/testing/startup-cache-telemetry.js {73cbeffd-d6c7-42f0-aaf3-f176430dcfc8}

startupcache/test/moz.build

@@ -7,3 +7,8 @@
 GeckoCppUnitTests([
     'TestStartupCache',
 ])
+
+EXTRA_COMPONENTS += [
+    'TestStartupCacheTelemetry.js',
+    'TestStartupCacheTelemetry.manifest',
+]

toolkit/components/telemetry/Histograms.json

@@ -1238,6 +1238,19 @@
     "n_buckets": 20,
     "description": "Maximum retention time for the gradient cache. (ms)"
   },
+  "STARTUP_CACHE_AGE_HOURS": {
+    "expires_in_version": "default",
+    "kind": "exponential",
+    "high": 3000,
+    "n_buckets": 20,
+    "description": "Startup cache age (hours)"
+  },
+  "STARTUP_CACHE_INVALID": {
+    "alert_emails": ["perf-telemetry-alerts@mozilla.com"],
+    "expires_in_version": "never",
+    "kind": "flag",
+    "description": "Was the disk startup cache file detected as invalid"
+  },
   "WORD_CACHE_HITS_CONTENT": {
     "expires_in_version": "never",
     "kind": "exponential",

toolkit/components/telemetry/histogram-whitelists.json

@@ -637,8 +637,9 @@
     "SPDY_SYN_REPLY_RATIO",
     "SPDY_SYN_REPLY_SIZE",
     "SPDY_SYN_SIZE",
-    "STARTUP_CRASH_DETECTED",
     "SPDY_VERSION2",
+    "STARTUP_CACHE_AGE_HOURS",
+    "STARTUP_CRASH_DETECTED",
     "STARTUP_MEASUREMENT_ERRORS",
     "STS_NUMBER_OF_ONSOCKETREADY_CALLS",
     "STS_NUMBER_OF_PENDING_EVENTS",
@@ -1568,6 +1569,8 @@
     "SSL_TLS12_INTOLERANCE_REASON_PRE",
     "SSL_VERSION_FALLBACK_INAPPROPRIATE",
     "SSL_WEAK_CIPHERS_FALLBACK",
+    "STARTUP_CACHE_AGE_HOURS",
+    "STARTUP_CACHE_INVALID",
     "STARTUP_CRASH_DETECTED",
     "STARTUP_MEASUREMENT_ERRORS",
     "STS_NUMBER_OF_ONSOCKETREADY_CALLS",
@@ -1950,6 +1953,7 @@
     "FX_SESSION_RESTORE_AUTO_RESTORE_DURATION_UNTIL_EAGER_TABS_RESTORED_MS",
     "FX_SESSION_RESTORE_COLLECT_DATA_MS",
     "FX_SESSION_RESTORE_FILE_SIZE_BYTES",
+    "STARTUP_CACHE_AGE_HOURS",
     "FX_SESSION_RESTORE_DOM_STORAGE_SIZE_ESTIMATE_CHARS",
     "DATA_STORAGE_ENTRIES",
     "TRANSLATED_PAGES_BY_LANGUAGE",