Track performance of toBlob and its complete timeout delay

third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp

Index: third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp
diff --git a/third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp b/third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp
index 01136649524082b8b79b83dda662a2a4852c957e..b5f26dd0a417202c5fcf39cf20cd357b647151d3 100644
--- a/third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp
+++ b/third_party/WebKit/Source/core/html/canvas/CanvasAsyncBlobCreator.cpp
@@ -5,6 +5,7 @@
 #include "core/html/canvas/CanvasAsyncBlobCreator.h"
 
 #include "core/fileapi/Blob.h"
+#include "platform/Histogram.h"
 #include "platform/ThreadSafeFunctional.h"
 #include "platform/graphics/ImageBuffer.h"
 #include "platform/image-encoders/JPEGImageEncoder.h"
@@ -78,16 +79,17 @@ CanvasAsyncBlobCreator::MimeType convertMimeTypeStringToEnum(const String& mimeT
 
 } // anonymous namespace
 
-CanvasAsyncBlobCreator* CanvasAsyncBlobCreator::create(DOMUint8ClampedArray* unpremultipliedRGBAImageData, const String& mimeType, const IntSize& size, BlobCallback* callback)
+CanvasAsyncBlobCreator* CanvasAsyncBlobCreator::create(DOMUint8ClampedArray* unpremultipliedRGBAImageData, const String& mimeType, const IntSize& size, BlobCallback* callback, double startTime)
 {
-    return new CanvasAsyncBlobCreator(unpremultipliedRGBAImageData, convertMimeTypeStringToEnum(mimeType), size, callback);
+    return new CanvasAsyncBlobCreator(unpremultipliedRGBAImageData, convertMimeTypeStringToEnum(mimeType), size, callback, startTime);
 }
 
-CanvasAsyncBlobCreator::CanvasAsyncBlobCreator(DOMUint8ClampedArray* data, MimeType mimeType, const IntSize& size, BlobCallback* callback)
+CanvasAsyncBlobCreator::CanvasAsyncBlobCreator(DOMUint8ClampedArray* data, MimeType mimeType, const IntSize& size, BlobCallback* callback, double startTime)
     : m_data(data)
     , m_size(size)
     , m_mimeType(mimeType)
     , m_callback(callback)
+    , m_startTime(startTime)
 {
     ASSERT(m_data->length() == (unsigned) (size.height() * size.width() * 4));
     m_encodedImage = adoptPtr(new Vector<unsigned char>());
@@ -118,7 +120,8 @@ void CanvasAsyncBlobCreator::scheduleAsyncBlobCreation(bool canUseIdlePeriodSche
         }
         // We post the below task to check if the above idle task isn't late.
         // There's no risk of concurrency as both tasks are on main thread.
-        this->postDelayedTaskToMainThread(BLINK_FROM_HERE, bind(&CanvasAsyncBlobCreator::idleTaskStartTimeoutEvent, this, quality), IdleTaskStartTimeoutDelay);
+        double startTime = WTF::monotonicallyIncreasingTime();
+        this->postDelayedTaskToMainThread(BLINK_FROM_HERE, bind(&CanvasAsyncBlobCreator::idleTaskStartTimeoutEvent, this, quality, startTime), IdleTaskStartTimeoutDelay);
     } else if (m_mimeType == MimeTypeWebp) {
         BackgroundTaskRunner::TaskSize taskSize = (m_size.height() * m_size.width() >= LongTaskImageSizeThreshold) ? BackgroundTaskRunner::TaskSizeLongRunningTask : BackgroundTaskRunner::TaskSizeShortRunningTask;
         BackgroundTaskRunner::postOnBackgroundThread(BLINK_FROM_HERE, threadSafeBind(&CanvasAsyncBlobCreator::encodeImageOnEncoderThread, wrapCrossThreadPersistent(this), quality), taskSize);
@@ -260,6 +263,17 @@ void CanvasAsyncBlobCreator::createBlobAndInvokeCallback()
     // non-GC members to allow teardown of CanvasAsyncBlobCreator.
     m_data.clear();
     m_callback.clear();
+    double elapsedTime = WTF::monotonicallyIncreasingTime()  - m_startTime;
+    if (m_mimeType == MimeTypePng) {
+        DEFINE_THREAD_SAFE_STATIC_LOCAL(CustomCountHistogram, toBlobPNGCounter, new CustomCountHistogram("Blink.Canvas.ToBlob.PNG", 0, 10000000, 50));
+        toBlobPNGCounter.count(elapsedTime * 1000000.0);
+    } else if (m_mimeType == MimeTypeJpeg) {
+        DEFINE_THREAD_SAFE_STATIC_LOCAL(CustomCountHistogram, toBlobJPEGCounter, new CustomCountHistogram("Blink.Canvas.ToBlob.JPEG", 0, 10000000, 50));
+        toBlobJPEGCounter.count(elapsedTime * 1000000.0);
+    } else {
+        DEFINE_THREAD_SAFE_STATIC_LOCAL(CustomCountHistogram, toBlobWEBPCounter, new CustomCountHistogram("Blink.Canvas.ToBlob.WEBP", 0, 10000000, 50));
+        toBlobWEBPCounter.count(elapsedTime * 1000000.0);
+    }
 }
 
 void CanvasAsyncBlobCreator::createNullAndInvokeCallback()
@@ -305,11 +319,35 @@ bool CanvasAsyncBlobCreator::initializeJpegStruct(double quality)
     return true;
 }
 
-void CanvasAsyncBlobCreator::idleTaskStartTimeoutEvent(double quality)
+void CanvasAsyncBlobCreator::recordTimeoutSwitch(IdleTaskTimeoutType type)
+{
+    if (m_mimeType == MimeTypePng) {
+        DEFINE_THREAD_SAFE_STATIC_LOCAL(EnumerationHistogram, idleTaskTimeoutSwitchPNG, new EnumerationHistogram("Canvas.ToBlob.IdleTaskTimeoutSwitch.PNG", IdleTaskTimeoutSupported));
+        idleTaskTimeoutSwitchPNG.count(type);
+    } else {
+        DEFINE_THREAD_SAFE_STATIC_LOCAL(EnumerationHistogram, idleTaskTimeoutSwitchJPEG, new EnumerationHistogram("Canvas.ToBlob.IdleTaskTimeoutSwitch.JPEG", IdleTaskTimeoutSupported));
+        idleTaskTimeoutSwitchJPEG.count(type);
+    }
+}
+
+void CanvasAsyncBlobCreator::idleTaskStartTimeoutEvent(double quality, double startTime)
 {
+    double elapsedTime = WTF::monotonicallyIncreasingTime()  - startTime;
+    if (m_mimeType == MimeTypePng) {
+        DEFINE_THREAD_SAFE_STATIC_LOCAL(CustomCountHistogram, toBlobPNGStartTimeoutCounter, new CustomCountHistogram("Blink.Canvas.ToBlobTimeoutDuration.PNG.Start", 0, 10000000, 50));
+        toBlobPNGStartTimeoutCounter.count(elapsedTime * 1000000.0);
+    } else if (m_mimeType == MimeTypeJpeg) {
+        DEFINE_THREAD_SAFE_STATIC_LOCAL(CustomCountHistogram, toBlobJPEGStartTimeoutCounter, new CustomCountHistogram("Blink.Canvas.ToBlobTimeoutDuration.JPEG.Start", 0, 10000000, 50));
+        toBlobJPEGStartTimeoutCounter.count(elapsedTime * 1000000.0);
+    } else {
+        DEFINE_THREAD_SAFE_STATIC_LOCAL(CustomCountHistogram, toBlobWEBPStartTimeoutCounter, new CustomCountHistogram("Blink.Canvas.ToBlobTimeoutDuration.WEBP.Start", 0, 10000000, 50));
+        toBlobWEBPStartTimeoutCounter.count(elapsedTime * 1000000.0);
+    }

[xidachen, 2016/06/07 20:46:29]

Is this recording meaningful now that we change to record how many times it
switch from idle to main thread?

+
     if (m_idleTaskStatus == IdleTaskStarted) {
         // Even if the task started quickly, we still want to ensure completion
-        this->postDelayedTaskToMainThread(BLINK_FROM_HERE, bind(&CanvasAsyncBlobCreator::idleTaskCompleteTimeoutEvent, this), IdleTaskCompleteTimeoutDelay);
+        startTime = WTF::monotonicallyIncreasingTime();
+        this->postDelayedTaskToMainThread(BLINK_FROM_HERE, bind(&CanvasAsyncBlobCreator::idleTaskCompleteTimeoutEvent, this, startTime), IdleTaskCompleteTimeoutDelay);
     } else if (m_idleTaskStatus == IdleTaskNotStarted) {
         // If the idle task does not start after a delay threshold, we will
         // force it to happen on main thread (even though it may cause more
@@ -319,6 +357,7 @@ void CanvasAsyncBlobCreator::idleTaskStartTimeoutEvent(double quality)
 
         if (m_mimeType == MimeTypePng) {
             if (initializePngStruct()) {
+                recordTimeoutSwitch(IdleTaskStartTimeout);
                 Platform::current()->mainThread()->getWebTaskRunner()->postTask(BLINK_FROM_HERE, bind(&CanvasAsyncBlobCreator::encodeRowsPngOnMainThread, this));
             } else {
                 // Failing in initialization of png struct
@@ -327,6 +366,7 @@ void CanvasAsyncBlobCreator::idleTaskStartTimeoutEvent(double quality)
         } else {
             ASSERT(m_mimeType == MimeTypeJpeg);
             if (initializeJpegStruct(quality)) {
+                recordTimeoutSwitch(IdleTaskStartTimeout);
                 Platform::current()->mainThread()->getWebTaskRunner()->postTask(BLINK_FROM_HERE, bind(&CanvasAsyncBlobCreator::encodeRowsJpegOnMainThread, this));
             } else {
                 // Failing in initialization of jpeg struct
@@ -340,9 +380,20 @@ void CanvasAsyncBlobCreator::idleTaskStartTimeoutEvent(double quality)
 
 }
 
-void CanvasAsyncBlobCreator::idleTaskCompleteTimeoutEvent()
+void CanvasAsyncBlobCreator::idleTaskCompleteTimeoutEvent(double startTime)
 {
     ASSERT(m_idleTaskStatus != IdleTaskNotStarted);
+    double elapsedTime = WTF::monotonicallyIncreasingTime()  - startTime;
+    if (m_mimeType == MimeTypePng) {
+        DEFINE_THREAD_SAFE_STATIC_LOCAL(CustomCountHistogram, toBlobPNGCompleteTimeoutCounter, new CustomCountHistogram("Blink.Canvas.ToBlobTimeoutDuration.PNG.Complete", 0, 10000000, 50));
+        toBlobPNGCompleteTimeoutCounter.count(elapsedTime * 1000000.0);
+    } else if (m_mimeType == MimeTypeJpeg) {
+        DEFINE_THREAD_SAFE_STATIC_LOCAL(CustomCountHistogram, toBlobJPEGCompleteTimeoutCounter, new CustomCountHistogram("Blink.Canvas.ToBlobTimeoutDuration.JPEG.Complete", 0, 10000000, 50));
+        toBlobJPEGCompleteTimeoutCounter.count(elapsedTime * 1000000.0);
+    } else {
+        DEFINE_THREAD_SAFE_STATIC_LOCAL(CustomCountHistogram, toBlobWEBPCompleteTimeoutCounter, new CustomCountHistogram("Blink.Canvas.ToBlobTimeoutDuration.WEBP.Complete", 0, 10000000, 50));
+        toBlobWEBPCompleteTimeoutCounter.count(elapsedTime * 1000000.0);
+    }
 
     if (m_idleTaskStatus == IdleTaskStarted) {
         // It has taken too long to complete for the idle task.
@@ -350,9 +401,11 @@ void CanvasAsyncBlobCreator::idleTaskCompleteTimeoutEvent()
         signalTaskSwitchInCompleteTimeoutEventForTesting();
 
         if (m_mimeType == MimeTypePng) {
+            recordTimeoutSwitch(IdleTaskCompleteTimeout);
             Platform::current()->mainThread()->getWebTaskRunner()->postTask(BLINK_FROM_HERE, bind(&CanvasAsyncBlobCreator::encodeRowsPngOnMainThread, this));
         } else {
             ASSERT(m_mimeType == MimeTypeJpeg);
+            recordTimeoutSwitch(IdleTaskCompleteTimeout);
             Platform::current()->mainThread()->getWebTaskRunner()->postTask(BLINK_FROM_HERE, bind(&CanvasAsyncBlobCreator::encodeRowsJpegOnMainThread, this));
         }
     } else {