Bug 711297 - report age of startup cache via telemetry; r=taras
authorNathan Froyd <froydnj@mozilla.com>
Wed, 22 Feb 2012 14:03:52 -0500
changeset 90740 579029d9950a099182182ef8c97d5f114f9931bf
parent 90739 bc6306feba6c983801747a4f1a8843ebe167b2ec
child 90741 69b718a5a15e4e3b035bd9e21f95c6861a724f8c
push id136
push userlsblakk@mozilla.com
push dateFri, 01 Jun 2012 02:39:32 +0000
treeherdermozilla-release@7ebf7352c959 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewerstaras
bugs711297
milestone13.0a1
first release with
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
last release without
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
Bug 711297 - report age of startup cache via telemetry; r=taras
startupcache/StartupCache.cpp
startupcache/StartupCache.h
toolkit/components/telemetry/TelemetryHistograms.h
--- a/startupcache/StartupCache.cpp
+++ b/startupcache/StartupCache.cpp
@@ -35,16 +35,17 @@
  * the provisions above, a recipient may use your version of this file under
  * the terms of any one of the MPL, the GPL or the LGPL.
  *
  * ***** END LICENSE BLOCK ***** */
 
 #include "prio.h"
 #include "prtypes.h"
 #include "pldhash.h"
+#include "nsXPCOMStrings.h"
 #include "mozilla/scache/StartupCache.h"
 
 #include "nsAutoPtr.h"
 #include "nsClassHashtable.h"
 #include "nsComponentManagerUtils.h"
 #include "nsDirectoryServiceUtils.h"
 #include "nsIClassInfo.h"
 #include "nsIFile.h"
@@ -61,16 +62,17 @@
 #include "nsITimer.h"
 #include "nsIZipWriter.h"
 #include "nsIZipReader.h"
 #include "nsWeakReference.h"
 #include "nsZipArchive.h"
 #include "mozilla/Omnijar.h"
 #include "prenv.h"
 #include "mozilla/FunctionTimer.h"
+#include "mozilla/Telemetry.h"
 #include "nsThreadUtils.h"
 #include "nsXULAppAPI.h"
 #include "nsIProtocolHandler.h"
 
 #ifdef IS_BIG_ENDIAN
 #define SC_ENDIAN "big"
 #else
 #define SC_ENDIAN "little"
@@ -232,17 +234,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 (NS_FAILED(rv) && rv != NS_ERROR_FILE_NOT_FOUND) {
     NS_WARNING("Failed to load startupcache file correctly, removing!");
     InvalidateCache();
   }
 
@@ -253,26 +255,53 @@ 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)
 {
   bool exists;
   mArchive = NULL;
   nsresult rv = mFile->Exists(&exists);
   if (NS_FAILED(rv) || !exists)
     return NS_ERROR_FILE_NOT_FOUND;
   
   mArchive = new nsZipArchive();
-  return mArchive->OpenArchive(mFile);
+  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();
+    PRInt64 diff = current - creationStamp;
+
+    // We can't use AccumulateTimeDelta here because we have no way of
+    // reifying a TimeStamp from creationStamp.
+    PRInt64 usec_per_hour = PR_USEC_PER_SEC * PRInt64(3600);
+    PRInt64 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,
                         char** outbuf, PRUint32* length)
 {
@@ -430,48 +459,59 @@ StartupCache::WriteToDisk()
     return;
 
   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 will be useful for
+  // Telemetry statistics.
+  PRTime now = PR_Now();
+  if (!mArchive) {
+    nsCString comment;
+    comment.Assign((char *)&now, sizeof(now));
+    zipW->SetComment(comment);
+  }
+
   nsCOMPtr<nsIStringInputStream> stream 
     = do_CreateInstance("@mozilla.org/io/string-input-stream;1", &rv);
   if (NS_FAILED(rv)) {
     NS_WARNING("Couldn't create string input stream.");
     return;
   }
 
   CacheWriteHolder holder;
   holder.stream = stream;
   holder.writer = zipW;
-  holder.time = PR_Now();
+  holder.time = now;
 
   mTable.Enumerate(CacheCloseHelper, &holder);
 
   // Close the archive so Windows doesn't choke.
   mArchive = NULL;
   zipW->Close();
 
-  // our reader's view of the archive is outdated now, reload it.
-  LoadArchive();
+  // Our reader's view of the archive is outdated now, reload it.
+  LoadArchive(IGNORE_AGE);
   
   return;
 }
 
 void
 StartupCache::InvalidateCache() 
 {
   WaitOnWriteThread();
   mTable.Clear();
   mArchive = NULL;
   mFile->Remove(false);
-  LoadArchive();
+  LoadArchive(IGNORE_AGE);
 }
 
 /*
  * WaitOnWriteThread() is called from a main thread to wait for the worker
  * thread to finish. However since the same code is used in the worker thread and
  * main thread, the worker thread can also call WaitOnWriteThread() which is a no-op.
  */
 void
--- a/startupcache/StartupCache.h
+++ b/startupcache/StartupCache.h
@@ -159,17 +159,22 @@ public:
   size_t HeapSizeOfIncludingThis(nsMallocSizeOfFun mallocSizeOf);
 
   size_t SizeOfMapping();
 
 private:
   StartupCache();
   ~StartupCache();
 
-  nsresult LoadArchive();
+  enum TelemetrifyAge {
+    IGNORE_AGE = 0,
+    RECORD_AGE = 1
+  };
+
+  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/toolkit/components/telemetry/TelemetryHistograms.h
+++ b/toolkit/components/telemetry/TelemetryHistograms.h
@@ -126,16 +126,17 @@ HISTOGRAM(DWRITEFONT_DELAYEDINITFONTLIST
 HISTOGRAM(DWRITEFONT_DELAYEDINITFONTLIST_ITERATE, 1, 30000, 10, EXPONENTIAL, "gfxDWriteFontList::DelayedInitFontList iterate over families (ms)")
 HISTOGRAM(GDI_INITFONTLIST_TOTAL, 1, 30000, 10, EXPONENTIAL, "gfxGDIFontList::InitFontList Total (ms)")
 #elif defined(XP_MACOSX)
 HISTOGRAM(MAC_INITFONTLIST_TOTAL, 1, 30000, 10, EXPONENTIAL, "gfxMacPlatformFontList::InitFontList Total (ms)")
 #endif
 
 HISTOGRAM(SYSTEM_FONT_FALLBACK, 1, 100000, 50, EXPONENTIAL, "System font fallback (us)")
 HISTOGRAM(SYSTEM_FONT_FALLBACK_FIRST, 1, 40000, 20, EXPONENTIAL, "System font fallback, first call (ms)")
+HISTOGRAM(STARTUP_CACHE_AGE_HOURS, 1, 3000, 20, EXPONENTIAL, "Startup cache age (hours)")
 
 /**
  * Word cache - one count for overall lookups, the other for the number of times a word is found
  * Note: range and number of buckets must match
  */
 HISTOGRAM(WORD_CACHE_LOOKUP_LEN, 1, 256, 30, EXPONENTIAL, "Word cache lookup (chars)")
 HISTOGRAM(WORD_CACHE_HIT_LEN, 1, 256, 30, EXPONENTIAL, "Word cache hit (chars)")
 HISTOGRAM(WORD_CACHE_LOOKUP_SCRIPT, 1, 110, 111, LINEAR, "Word cache lookup (script)")