Backed out changeset 419e1a311337 (bug 1314378)
authorIris Hsiao <ihsiao@mozilla.com>
Wed, 16 Nov 2016 15:30:57 +0800
changeset 894392 87b4c375fe750de1df65036619da70e7d151228c
parent 894391 03614ff20ee0880f6c5ee538bf0a0072f1c683d4
child 894393 02189fae47d774e93efd90bdc82775c1dc67813f
child 894527 09d9c83ae3a9477ce74f3ab62da8e8d0bbae0f2a
child 894682 cf322e3fd2e849bfc1f191f3414491f84b878588
child 895068 f63cea1a016e62b6508cb83e1e5422cfedd6b826
push id155090
push userjcoppeard@mozilla.com
push dateWed, 16 Nov 2016 11:30:43 +0000
treeherdertry@d330f4adbe83 [default view] [failures only]
bugs1314378
milestone53.0a1
backs out419e1a311337ecdf208f5474f182d1f88102cc9f
Backed out changeset 419e1a311337 (bug 1314378)
startupcache/StartupCache.cpp
startupcache/StartupCache.h
startupcache/nsIStartupCache.idl
startupcache/test/TestStartupCache.cpp
startupcache/test/TestStartupCacheTelemetry.js
startupcache/test/TestStartupCacheTelemetry.manifest
startupcache/test/moz.build
toolkit/components/telemetry/Histograms.json
toolkit/components/telemetry/histogram-whitelists.json
--- a/startupcache/StartupCache.cpp
+++ b/startupcache/StartupCache.cpp
@@ -108,16 +108,17 @@ StartupCache::InitSingleton()
     StartupCache::gStartupCache = nullptr;
   }
   return rv;
 }
 
 StaticRefPtr<StartupCache> StartupCache::gStartupCache;
 bool StartupCache::gShutdownInitiated;
 bool StartupCache::gIgnoreDiskCache;
+enum StartupCache::TelemetrifyAge StartupCache::gPostFlushAgeAction = StartupCache::IGNORE_AGE;
 
 NS_IMPL_ISUPPORTS(StartupCache, nsIMemoryReporter)
 
 StartupCache::StartupCache()
   : mArchive(nullptr), mStartupWriteInitiated(false), mWriteThread(nullptr)
 { }
 
 StartupCache::~StartupCache()
@@ -205,17 +206,17 @@ StartupCache::Init()
   mListener = new StartupCacheListener();
   rv = mObserverService->AddObserver(mListener, NS_XPCOM_SHUTDOWN_OBSERVER_ID,
                                      false);
   NS_ENSURE_SUCCESS(rv, rv);
   rv = mObserverService->AddObserver(mListener, "startupcache-invalidate",
                                      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.
   if (gIgnoreDiskCache || (NS_FAILED(rv) && rv != NS_ERROR_FILE_NOT_FOUND)) {
     NS_WARNING("Failed to load startupcache file correctly, removing!");
     InvalidateCache();
   }
 
@@ -223,29 +224,55 @@ StartupCache::Init()
 
   return NS_OK;
 }
 
 /**
  * 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;
 
   bool exists;
   mArchive = nullptr;
   nsresult rv = mFile->Exists(&exists);
   if (NS_FAILED(rv) || !exists)
     return NS_ERROR_FILE_NOT_FOUND;
   
   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;
 }
 
 namespace {
 
 nsresult
 GetBufferFromZipArchive(nsZipArchive *zip, bool doCRC, const char* id,
                         UniquePtr<char[]>* outbuf, uint32_t* length)
@@ -414,17 +441,17 @@ StartupCache::WriteToDisk()
   rv = zipW->Open(mFile, PR_RDWR | PR_CREATE_FILE);
   if (NS_FAILED(rv)) {
     NS_WARNING("could not open zipfile for write");
     return;
   } 
 
   // 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) {
     nsCString comment;
     comment.Assign((char *)&now, sizeof(now));
     zipW->SetComment(comment);
   }
 
@@ -449,36 +476,37 @@ StartupCache::WriteToDisk()
   // Close the archive so Windows doesn't choke.
   mArchive = nullptr;
   zipW->Close();
 
   // We succesfully wrote the archive to disk; mark the disk file as trusted
   gIgnoreDiskCache = false;
 
   // Our reader's view of the archive is outdated now, reload it.
-  LoadArchive();
+  LoadArchive(gPostFlushAgeAction);
   
   return;
 }
 
 void
 StartupCache::InvalidateCache() 
 {
   WaitOnWriteThread();
   mPendingWrites.Clear();
   mTable.Clear();
   mArchive = nullptr;
   nsresult rv = mFile->Remove(false);
   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
 StartupCache::IgnoreDiskCache()
 {
   gIgnoreDiskCache = true;
   if (gStartupCache)
     gStartupCache->InvalidateCache();
@@ -590,16 +618,23 @@ StartupCache::ResetStartupWriteTimer()
     rv = mTimer->Cancel();
   NS_ENSURE_SUCCESS(rv, rv);
   // Wait for 10 seconds, then write out the cache.
   mTimer->InitWithFuncCallback(StartupCache::WriteTimeout, this, 60000,
                                nsITimer::TYPE_ONE_SHOT);
   return NS_OK;
 }
 
+nsresult
+StartupCache::RecordAgesAlways()
+{
+  gPostFlushAgeAction = RECORD_AGE;
+  return NS_OK;
+}
+
 // StartupCacheDebugOutputStream implementation
 #ifdef DEBUG
 NS_IMPL_ISUPPORTS(StartupCacheDebugOutputStream, nsIObjectOutputStream, 
                   nsIBinaryOutputStream, nsIOutputStream)
 
 bool
 StartupCacheDebugOutputStream::CheckReferences(nsISupports* aObject)
 {
@@ -779,10 +814,16 @@ StartupCacheWrapper::GetObserver(nsIObse
   StartupCache* sc = StartupCache::GetSingleton();
   if (!sc) {
     return NS_ERROR_NOT_INITIALIZED;
   }
   NS_ADDREF(*obv = sc->mListener);
   return NS_OK;
 }
 
+nsresult
+StartupCacheWrapper::RecordAgesAlways() {
+  StartupCache *sc = StartupCache::GetSingleton();
+  return sc ? sc->RecordAgesAlways() : NS_ERROR_NOT_INITIALIZED;
+}
+
 } // namespace scache
 } // namespace mozilla
--- a/startupcache/StartupCache.h
+++ b/startupcache/StartupCache.h
@@ -124,30 +124,38 @@ public:
   // Signal that data should not be loaded from the cache file
   static void IgnoreDiskCache();
 
   // In DEBUG builds, returns a stream that will attempt to check for
   // and disallow multiple writes of the same object.
   nsresult GetDebugObjectOutputStream(nsIObjectOutputStream* aStream,
                                       nsIObjectOutputStream** outStream);
 
+  nsresult RecordAgesAlways();
+
   static StartupCache* GetSingleton();
   static void DeleteSingleton();
 
   // This measures all the heap memory used by the StartupCache, i.e. it
   // excludes the mapping.
   size_t HeapSizeOfIncludingThis(mozilla::MallocSizeOf mallocSizeOf) const;
 
   size_t SizeOfMapping();
 
 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();
   void WaitOnWriteThread();
 
   static nsresult InitSingleton();
   static void WriteTimeout(nsITimer *aTimer, void *aClosure);
   static void ThreadedWrite(void *aClosure);
--- a/startupcache/nsIStartupCache.idl
+++ b/startupcache/nsIStartupCache.idl
@@ -50,12 +50,16 @@ interface nsIStartupCache : nsISupports
 
   /* Allows clients to check whether the one-time writeout after startup 
    * has finished yet, and also to set this variable as needed (so test
    * code can fire mulitple startup writes if needed).
    */
   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;
 };
 
--- a/startupcache/test/TestStartupCache.cpp
+++ b/startupcache/test/TestStartupCache.cpp
@@ -405,16 +405,58 @@ int main(int argc, char** argv)
     fail("prefs");
     return 1;
   }
   prefs->SetIntPref("hangmonitor.timeout", 0);
 
   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))
     rv = 1;
   else
     sc->RecordAgesAlways();
   if (NS_FAILED(TestStartupWriteRead()))
     rv = 1;
@@ -423,10 +465,16 @@ int main(int argc, char** argv)
   if (NS_FAILED(TestWriteObject()))
     rv = 1;
   nsCOMPtr<nsIFile> profileDir = xpcom.GetProfileDirectory();
   if (NS_FAILED(TestIgnoreDiskCache(profileDir)))
     rv = 1;
   if (NS_FAILED(TestEarlyShutdown()))
     rv = 1;
 
+  scrv = telemetryThing->Observe(nullptr, "save-initial", nullptr);
+  if (NS_FAILED(scrv)) {
+    fail("check-final");
+    rv = 1;
+  }
+
   return rv;
 }
new file mode 100644
--- /dev/null
+++ b/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]);
new file mode 100644
--- /dev/null
+++ b/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}
--- a/startupcache/test/moz.build
+++ b/startupcache/test/moz.build
@@ -2,8 +2,13 @@
 # vim: set filetype=python:
 # This Source Code Form is subject to the terms of the Mozilla Public
 # License, v. 2.0. If a copy of the MPL was not distributed with this
 # file, You can obtain one at http://mozilla.org/MPL/2.0/.
 
 GeckoCppUnitTests([
     'TestStartupCache',
 ])
+
+EXTRA_COMPONENTS += [
+    'TestStartupCacheTelemetry.js',
+    'TestStartupCacheTelemetry.manifest',
+]
--- a/toolkit/components/telemetry/Histograms.json
+++ b/toolkit/components/telemetry/Histograms.json
@@ -1233,16 +1233,29 @@
   },
   "GRADIENT_RETENTION_TIME": {
     "expires_in_version": "never",
     "kind": "linear",
     "high": 10000,
     "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",
     "high": 256,
     "n_buckets": 30,
     "description": "Word cache hits, content text (chars)"
   },
   "WORD_CACHE_HITS_CHROME": {
--- a/toolkit/components/telemetry/histogram-whitelists.json
+++ b/toolkit/components/telemetry/histogram-whitelists.json
@@ -632,18 +632,19 @@
     "SPDY_SETTINGS_MAX_STREAMS",
     "SPDY_SETTINGS_RETRANS",
     "SPDY_SETTINGS_RTT",
     "SPDY_SETTINGS_UL_BW",
     "SPDY_SYN_RATIO",
     "SPDY_SYN_REPLY_RATIO",
     "SPDY_SYN_REPLY_SIZE",
     "SPDY_SYN_SIZE",
+    "SPDY_VERSION2",
+    "STARTUP_CACHE_AGE_HOURS",
     "STARTUP_CRASH_DETECTED",
-    "SPDY_VERSION2",
     "STARTUP_MEASUREMENT_ERRORS",
     "STS_NUMBER_OF_ONSOCKETREADY_CALLS",
     "STS_NUMBER_OF_PENDING_EVENTS",
     "STS_NUMBER_OF_PENDING_EVENTS_IN_THE_LAST_CYCLE",
     "STS_POLL_AND_EVENTS_CYCLE",
     "STS_POLL_AND_EVENT_THE_LAST_CYCLE",
     "STS_POLL_BLOCK_TIME",
     "STS_POLL_CYCLE",
@@ -1563,16 +1564,18 @@
     "SSL_TLS10_INTOLERANCE_REASON_POST",
     "SSL_TLS10_INTOLERANCE_REASON_PRE",
     "SSL_TLS11_INTOLERANCE_REASON_POST",
     "SSL_TLS11_INTOLERANCE_REASON_PRE",
     "SSL_TLS12_INTOLERANCE_REASON_POST",
     "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",
     "STS_NUMBER_OF_PENDING_EVENTS",
     "STS_NUMBER_OF_PENDING_EVENTS_IN_THE_LAST_CYCLE",
     "STS_POLL_AND_EVENTS_CYCLE",
     "STS_POLL_AND_EVENT_THE_LAST_CYCLE",
     "STS_POLL_BLOCK_TIME",
@@ -1945,16 +1948,17 @@
     "GEOLOCATION_ACCURACY_EXPONENTIAL",
     "FX_SESSION_RESTORE_READ_FILE_MS",
     "CHANGES_OF_DETECTED_LANGUAGE",
     "OSFILE_WORKER_READY_MS",
     "PDF_VIEWER_FORM",
     "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",
     "MOZ_SQLITE_OTHER_WRITE_B",
     "LOCALDOMSTORAGE_SHUTDOWN_DATABASE_MS",
     "SSL_CERT_VERIFICATION_ERRORS",
     "FX_SESSION_RESTORE_NUMBER_OF_WINDOWS_RESTORED",
     "MOZ_SQLITE_PLACES_WRITE_MS",