Track performance of toBlob and its complete timeout delay

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

 // Copyright 2015 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #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"
 #include "platform/image-encoders/PNGImageEncoder.h"
 #include "platform/threading/BackgroundTaskRunner.h"
 #include "public/platform/Platform.h"
 #include "public/platform/WebScheduler.h"
 #include "public/platform/WebTaskRunner.h"
 #include "public/platform/WebThread.h"
 #include "public/platform/WebTraceLocation.h"
@@ skipping 53 matching lines @@
     } else if (mimeType == "image/webp") {
         mimeTypeEnum = CanvasAsyncBlobCreator::MimeTypeWebp;
     } else {
         mimeTypeEnum = CanvasAsyncBlobCreator::NumberOfMimeTypeSupported;
     }
     return mimeTypeEnum;
 }
 
 } // 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>());
     m_pixelRowStride = size.width() * NumChannelsPng;
     m_idleTaskStatus = IdleTaskNotSupported;
     m_numRowsCompleted = 0;
 }
 
 CanvasAsyncBlobCreator::~CanvasAsyncBlobCreator()
 {
@@ skipping 10 matching lines @@
         } else if (m_mimeType == MimeTypeJpeg) {
             this->scheduleInitiateJpegEncoding(quality);
         } else {
             // Progressive encoding is only applicable to png and jpeg image format,
             // and thus idle tasks scheduling can only be applied to these image formats.
             // TODO(xlai): Progressive encoding on webp image formats (crbug.com/571399)
             ASSERT_NOT_REACHED();
         }
         // 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);
     }
 }
 
 void CanvasAsyncBlobCreator::scheduleInitiateJpegEncoding(const double& quality)
 {
     Platform::current()->mainThread()->scheduler()->postIdleTask(BLINK_FROM_HERE, bind<double>(&CanvasAsyncBlobCreator::initiateJpegEncoding, this, quality));
 }
@@ skipping 121 matching lines @@
 
 void CanvasAsyncBlobCreator::createBlobAndInvokeCallback()
 {
     ASSERT(isMainThread());
     Blob* resultBlob = Blob::create(m_encodedImage->data(), m_encodedImage->size(), convertMimeTypeEnumToString(m_mimeType));
     Platform::current()->mainThread()->getWebTaskRunner()->postTask(BLINK_FROM_HERE, bind(&BlobCallback::handleEvent, m_callback, resultBlob));
     // Since toBlob is done, timeout events are no longer needed. So we clear
     // 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()
 {
     ASSERT(isMainThread());
     Platform::current()->mainThread()->getWebTaskRunner()->postTask(BLINK_FROM_HERE, bind(&BlobCallback::handleEvent, m_callback, nullptr));
     // Since toBlob is done (failed), timeout events are no longer needed. So we
     // clear non-GC members to allow teardown of CanvasAsyncBlobCreator.
     m_data.clear();
     m_callback.clear();
@@ skipping 25 matching lines @@
 bool CanvasAsyncBlobCreator::initializeJpegStruct(double quality)
 {
     m_jpegEncoderState = JPEGImageEncoderState::create(m_size, quality, m_encodedImage.get());
     if (!m_jpegEncoderState) {
         this->createNullAndInvokeCallback();
         return false;
     }
     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
         // janks) to prevent toBlob being postponed forever in extreme cases.
         m_idleTaskStatus = IdleTaskSwitchedToMainThreadTask;
         signalTaskSwitchInStartTimeoutEventForTesting();
 
         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
                 this->signalAlternativeCodePathFinishedForTesting();
             }
         } 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
                 this->signalAlternativeCodePathFinishedForTesting();
             }
         }
     } else {
         ASSERT(m_idleTaskStatus == IdleTaskFailed || m_idleTaskStatus == IdleTaskCompleted);
         this->signalAlternativeCodePathFinishedForTesting();
     }
 
 }
 
-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.
         m_idleTaskStatus = IdleTaskSwitchedToMainThreadTask;
         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 {
         ASSERT(m_idleTaskStatus == IdleTaskFailed || m_idleTaskStatus == IdleTaskCompleted);
         this->signalAlternativeCodePathFinishedForTesting();
     }
 }
 
 void CanvasAsyncBlobCreator::postDelayedTaskToMainThread(const WebTraceLocation& location, std::unique_ptr<SameThreadClosure> task, double delayMs)
 {
     DCHECK(isMainThread());
     Platform::current()->mainThread()->getWebTaskRunner()->postDelayedTask(location, std::move(task), delayMs);
 }
 
 } // namespace blink