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 69 matching lines @@
     : m_data(data)
     , m_size(size)
     , m_mimeType(mimeType)
     , m_callback(callback)
 {
     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;
+    m_startTime = WTF::monotonicallyIncreasingTime();
 }
 
 CanvasAsyncBlobCreator::~CanvasAsyncBlobCreator()
 {
 }
 
 void CanvasAsyncBlobCreator::scheduleAsyncBlobCreation(bool canUseIdlePeriodScheduling, const double& quality)
 {
     ASSERT(isMainThread());
 
@@ skipping 137 matching lines @@
     // Continue encoding from the last completed row
     if (JPEGImageEncoder::encodeWithPreInitializedState(std::move(m_jpegEncoderState), m_data->data(), m_numRowsCompleted)) {
         this->createBlobAndInvokeCallback();
     } else {
         this->createNullAndInvokeCallback();
     }
 
     this->signalAlternativeCodePathFinishedForTesting();
 }
 
+void CanvasAsyncBlobCreator::recordElapsedTime()
+{
+    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 if (m_mimeType == MimeTypeWebp) {
+        DEFINE_THREAD_SAFE_STATIC_LOCAL(CustomCountHistogram, toBlobWEBPCounter, new CustomCountHistogram("Blink.Canvas.ToBlob.WEBP", 0, 10000000, 50));
+        toBlobWEBPCounter.count(elapsedTime * 1000000.0);
+    } else {
+        DEFINE_THREAD_SAFE_STATIC_LOCAL(CustomCountHistogram, toBlobUnknownCounter, new CustomCountHistogram("Blink.Canvas.ToBlob.Unknown", 0, 10000000, 50));
+        toBlobUnknownCounter.count(elapsedTime * 1000000.0);
+    }
+}
+
 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();
+    recordElapsedTime();
 }
 
 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();
+    recordElapsedTime();

[Justin Novosad, 2016/06/06 15:16:03]

The failure case should not be recording to the same timing metrics as the
success case.  We could probably do without capturing time for the failure
cases.  However, it would be relevant to have a fail vs. succeed histogram for
each mime type.

 }
 
 void CanvasAsyncBlobCreator::encodeImageOnEncoderThread(double quality)
 {
     ASSERT(!isMainThread());
     ASSERT(m_mimeType == MimeTypeWebp);
 
     if (!ImageDataBuffer(m_size, m_data->data()).encodeImage("image/webp", quality, m_encodedImage.get())) {
         Platform::current()->mainThread()->getWebTaskRunner()->postTask(BLINK_FROM_HERE, threadSafeBind(&BlobCallback::handleEvent, wrapCrossThreadPersistent(m_callback.get()), nullptr));
         return;
@@ skipping 54 matching lines @@
         ASSERT(m_idleTaskStatus == IdleTaskFailed || m_idleTaskStatus == IdleTaskCompleted);
         this->signalAlternativeCodePathFinishedForTesting();
     }
 
 }
 
 void CanvasAsyncBlobCreator::idleTaskCompleteTimeoutEvent()
 {
     ASSERT(m_idleTaskStatus != IdleTaskNotStarted);
 
+    DEFINE_THREAD_SAFE_STATIC_LOCAL(EnumerationHistogram, idleTaskCompleteTimeoutDelayHistogram, new EnumerationHistogram("Canvas.ToBlob.IdleTaskCompleteTimeoutDelay", NumberOfMimeTypeSupported));

[Justin Novosad, 2016/06/06 15:16:03]

This histogram does not provide very significant info on its own. It would be
better to have a separate histogram per mime type, and for each such histogram,
the bins should be idleTaskTimeout vs. idleTaskCompleted.  That way we get
histograms that tell us the fraction of tasks that timed-out, which is directly
relevant data.  Also, the word "Delay" is not very relevant here.

+    idleTaskCompleteTimeoutDelayHistogram.count(m_mimeType);
+
     if (m_idleTaskStatus == IdleTaskStarted) {
         // It has taken too long to complete for the idle task.
         m_idleTaskStatus = IdleTaskSwitchedToMainThreadTask;
         signalTaskSwitchInCompleteTimeoutEventForTesting();
 
         if (m_mimeType == MimeTypePng) {
             Platform::current()->mainThread()->getWebTaskRunner()->postTask(BLINK_FROM_HERE, bind(&CanvasAsyncBlobCreator::encodeRowsPngOnMainThread, this));
         } else {
             ASSERT(m_mimeType == MimeTypeJpeg);
             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