Bug 672207. imglib-telemetry: record the full time it takes to decode images. r=jlebar,joe
authorJeff Muizelaar <jmuizelaar@mozilla.com>
Thu, 04 Aug 2011 16:25:12 -0400
changeset 73867 cd6c34e9b28fc75da8a5a91831363734967c0d65
parent 73866 99e317c11f2836220e25a45b7a3f3b6370b5ef51
child 73868 81c341716ad99a90e85469ba75393e249f8ed2b5
push id2
push userbsmedberg@mozilla.com
push dateFri, 19 Aug 2011 14:38:13 +0000
reviewersjlebar, joe
bugs672207
milestone8.0a1
Bug 672207. imglib-telemetry: record the full time it takes to decode images. r=jlebar,joe Do this by accumulating decode latency in mDecodeTime which is added to imgDecodeWorker.
modules/libpr0n/src/RasterImage.cpp
modules/libpr0n/src/RasterImage.h
toolkit/components/telemetry/TelemetryHistograms.h
--- a/modules/libpr0n/src/RasterImage.cpp
+++ b/modules/libpr0n/src/RasterImage.cpp
@@ -2706,28 +2706,32 @@ imgDecodeWorker::Run()
     // Figure out if we still have more data
     haveMoreData =
       image->mSourceData.Length() > image->mBytesDecoded;
   }
 
   TimeDuration decodeLatency = TimeStamp::Now() - start;
   Telemetry::Accumulate(Telemetry::IMAGE_DECODE_LATENCY, PRInt32(decodeLatency.ToMicroseconds()));
 
+  // accumulate the total decode time
+  mDecodeTime += decodeLatency;
+
   // Flush invalidations _after_ we've written everything we're going to.
   // Furthermore, if this is a redecode, we don't want to do progressive
   // display at all. In that case, let Decoder::PostFrameStop() do the
   // flush once the whole frame is ready.
   if (!image->mHasBeenDecoded) {
     image->mInDecoder = PR_TRUE;
     image->mDecoder->FlushInvalidations();
     image->mInDecoder = PR_FALSE;
   }
 
   // If the decode finished, shutdown the decoder
   if (image->mDecoder && image->IsDecodeFinished()) {
+    Telemetry::Accumulate(Telemetry::IMAGE_DECODE_TIME, PRInt32(mDecodeTime.ToMicroseconds()));
     rv = image->ShutdownDecoder(RasterImage::eShutdownIntent_Done);
     if (NS_FAILED(rv)) {
       image->DoError();
       return rv;
     }
   }
 
   // If Conditions 1 & 2 are still true, then the only reason we bailed was
--- a/modules/libpr0n/src/RasterImage.h
+++ b/modules/libpr0n/src/RasterImage.h
@@ -59,16 +59,17 @@
 #include "imgIContainer.h"
 #include "nsIProperties.h"
 #include "nsITimer.h"
 #include "nsWeakReference.h"
 #include "nsTArray.h"
 #include "imgFrame.h"
 #include "nsThreadUtils.h"
 #include "DiscardTracker.h"
+#include "mozilla/TimeStamp.h"
 #ifdef DEBUG
   #include "imgIContainerDebug.h"
 #endif
 
 class imgIDecoder;
 class nsIInputStream;
 
 #define NS_RASTERIMAGE_CID \
@@ -566,16 +567,17 @@ class imgDecodeWorker : public nsRunnabl
     imgDecodeWorker(imgIContainer* aContainer) {
       mContainer = do_GetWeakReference(aContainer);
     }
     NS_IMETHOD Run();
     NS_METHOD  Dispatch();
 
   private:
     nsWeakPtr mContainer;
+    TimeDuration mDecodeTime; // the default constructor initializes to 0
 };
 
 // Asynchronous Decode Requestor
 //
 // We use this class when someone calls requestDecode() from within a decode
 // notification. Since requestDecode() involves modifying the decoder's state
 // (for example, possibly shutting down a header-only decode and starting a
 // full decode), we don't want to do this from inside a decoder.
--- a/toolkit/components/telemetry/TelemetryHistograms.h
+++ b/toolkit/components/telemetry/TelemetryHistograms.h
@@ -78,17 +78,18 @@ HISTOGRAM(DWRITEFONT_DELAYEDINITFONTLIST
 HISTOGRAM(DWRITEFONT_DELAYEDINITFONTLIST_COLLECT, 1, 30000, 10, EXPONENTIAL, "gfxDWriteFontList::DelayedInitFontList GetSystemFontCollection (ms)")
 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(SHUTDOWN_OK, 0, 1, 2, BOOLEAN, "Did the browser start after a successful shutdown")
 
-HISTOGRAM(IMAGE_DECODE_LATENCY, 50, 5000000, 100, EXPONENTIAL, "Time spent decoding an image chunk (us)")
+HISTOGRAM(IMAGE_DECODE_LATENCY, 50,  5000000, 100, EXPONENTIAL, "Time spent decoding an image chunk (us)")
+HISTOGRAM(IMAGE_DECODE_TIME,    50, 50000000, 100, EXPONENTIAL, "Time spent decoding an image (us)")
 
 /**
  * Networking telemetry
  */
 HISTOGRAM(TOTAL_CONTENT_PAGE_LOAD_TIME, 100, 10000, 100, EXPONENTIAL, "HTTP: Total page load time (ms)")
 HISTOGRAM(HTTP_SUBITEM_OPEN_LATENCY_TIME, 1, 30000, 50, EXPONENTIAL, "HTTP subitem: Page start -> subitem open() (ms)")
 HISTOGRAM(HTTP_SUBITEM_FIRST_BYTE_LATENCY_TIME, 1, 30000, 50, EXPONENTIAL, "HTTP subitem: Page start -> first byte received for subitem reply (ms)")
 HISTOGRAM(HTTP_REQUEST_PER_PAGE, 1, 1000, 50, EXPONENTIAL, "HTTP: Requests per page (count)")