Add flow events to trace thumbnail capture and storage

Bug: 1090038, 1148631
Change-Id: I33a9cbf31e93e56c6e2a81b7736b016100427fe0
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2587648
Commit-Queue: Collin Baker <collinbaker@chromium.org>
Reviewed-by: Dana Fried <dfried@chromium.org>
Cr-Commit-Position: refs/heads/master@{#842743}

chrome/browser/ui/thumbnails/background_thumbnail_video_capturer.cc

@@ -9,6 +9,7 @@
 
 #include "base/metrics/histogram_macros.h"
 #include "base/trace_event/trace_event.h"
+#include "base/trace_event/trace_id_helper.h"
 #include "content/public/browser/render_frame_host.h"
 #include "content/public/browser/render_view_host.h"
 #include "content/public/browser/render_widget_host.h"
@@ -128,6 +129,10 @@ void BackgroundThumbnailVideoCapturer::OnFrameCaptured(
                        num_received_frames_);
   ++num_received_frames_;
 
+  uint64_t frame_id = base::trace_event::GetNextGlobalTraceId();
+  TRACE_EVENT_WITH_FLOW0("ui", "Tab.Preview.ProcessVideoCaptureFrame", frame_id,
+                         TRACE_EVENT_FLAG_FLOW_OUT);
+
   // The SkBitmap's pixels will be marked as immutable, but the installPixels()
   // API requires a non-const pointer. So, cast away the const.
   void* const pixels = const_cast<void*>(mapping.memory());
@@ -172,15 +177,18 @@ void BackgroundThumbnailVideoCapturer::OnFrameCaptured(
   frame.setImmutable();
 
   SkBitmap cropped_frame;
-  if (frame.extractSubset(&cropped_frame,
-                          gfx::RectToSkIRect(effective_content_rect))) {
-    UMA_HISTOGRAM_CUSTOM_MICROSECONDS_TIMES(
-        "Tab.Preview.TimeToStoreAfterFrameReceived",
-        base::TimeTicks::Now() - time_of_call,
-        base::TimeDelta::FromMicroseconds(10),
-        base::TimeDelta::FromMilliseconds(10), 50);
-    got_frame_callback_.Run(cropped_frame);
+  if (!frame.extractSubset(&cropped_frame,
+                           gfx::RectToSkIRect(effective_content_rect))) {
+    return;
   }
+
+  UMA_HISTOGRAM_CUSTOM_MICROSECONDS_TIMES(
+      "Tab.Preview.TimeToStoreAfterFrameReceived",
+      base::TimeTicks::Now() - time_of_call,
+      base::TimeDelta::FromMicroseconds(10),
+      base::TimeDelta::FromMilliseconds(10), 50);
+
+  got_frame_callback_.Run(cropped_frame, frame_id);
 }
 
 void BackgroundThumbnailVideoCapturer::OnStopped() {}

chrome/browser/ui/thumbnails/background_thumbnail_video_capturer.h

@@ -24,7 +24,11 @@ class BackgroundThumbnailVideoCapturer
     : public BackgroundThumbnailCapturer,
       public viz::mojom::FrameSinkVideoConsumer {
  public:
-  using GotFrameCallback = base::RepeatingCallback<void(const SkBitmap&)>;
+  // Client receives `SkBitmap` frames and `uin64_t` unique IDs for each
+  // frame. IDs are globally unique for a given browser process and are
+  // used for TRACE_EVENT_FLOW_* macros
+  using GotFrameCallback =
+      base::RepeatingCallback<void(const SkBitmap&, uint64_t)>;
   BackgroundThumbnailVideoCapturer(content::WebContents* contents,
                                    GotFrameCallback got_frame_callback);
   ~BackgroundThumbnailVideoCapturer() override;

chrome/browser/ui/thumbnails/thumbnail_image.cc

@@ -13,6 +13,7 @@
 #include "base/task/task_traits.h"
 #include "base/task/thread_pool.h"
 #include "base/time/time.h"
+#include "base/trace_event/trace_event.h"
 #include "chrome/browser/ui/thumbnails/thumbnail_stats_tracker.h"
 #include "ui/gfx/codec/jpeg_codec.h"
 #include "ui/gfx/skia_util.h"
@@ -58,14 +59,17 @@ std::unique_ptr<ThumbnailImage::Subscription> ThumbnailImage::Subscribe() {
   return subscription;
 }
 
-void ThumbnailImage::AssignSkBitmap(SkBitmap bitmap) {
+void ThumbnailImage::AssignSkBitmap(SkBitmap bitmap,
+                                    base::Optional<uint64_t> frame_id) {
   base::ThreadPool::PostTaskAndReplyWithResult(
       FROM_HERE,
       {base::TaskPriority::USER_VISIBLE,
        base::TaskShutdownBehavior::CONTINUE_ON_SHUTDOWN},
-      base::BindOnce(&ThumbnailImage::CompressBitmap, std::move(bitmap)),
+      base::BindOnce(&ThumbnailImage::CompressBitmap, std::move(bitmap),
+                     frame_id),
       base::BindOnce(&ThumbnailImage::AssignJPEGData,
-                     weak_ptr_factory_.GetWeakPtr(), base::TimeTicks::Now()));
+                     weak_ptr_factory_.GetWeakPtr(), base::TimeTicks::Now(),
+                     frame_id));
 }
 
 void ThumbnailImage::ClearData() {
@@ -101,16 +105,34 @@ size_t ThumbnailImage::GetCompressedDataSizeInBytes() const {
 }
 
 void ThumbnailImage::AssignJPEGData(base::TimeTicks assign_sk_bitmap_time,
+                                    base::Optional<uint64_t> frame_id,
                                     std::vector<uint8_t> data) {
   data_ = base::MakeRefCounted<base::RefCountedData<std::vector<uint8_t>>>(
       std::move(data));
+
   UMA_HISTOGRAM_CUSTOM_MICROSECONDS_TIMES(
       "Tab.Preview.TimeToNotifyObserversAfterCaptureReceived",
       base::TimeTicks::Now() - assign_sk_bitmap_time,
       base::TimeDelta::FromMicroseconds(100),
       base::TimeDelta::FromMilliseconds(100), 50);
-  NotifyCompressedDataObservers(data_);
-  ConvertJPEGDataToImageSkiaAndNotifyObservers();
+
+  // We select a TRACE_EVENT_* macro based on |frame_id|'s presence.
+  // Since these are scoped traces, the macro invocation must be in the
+  // enclosing scope of these operations. Extract them into a common
+  // function.
+  auto notify = [&]() {
+    NotifyCompressedDataObservers(data_);
+    ConvertJPEGDataToImageSkiaAndNotifyObservers();
+  };
+
+  if (frame_id) {
+    TRACE_EVENT_WITH_FLOW0("ui", "Tab.Preview.JPEGReceivedOnUIThreadWithFlow",
+                           *frame_id, TRACE_EVENT_FLAG_FLOW_IN);
+    notify();
+  } else {
+    TRACE_EVENT0("ui", "Tab.Preview.JPEGReceivedOnUIThread");
+    notify();
+  }
 }
 
 bool ThumbnailImage::ConvertJPEGDataToImageSkiaAndNotifyObservers() {
@@ -153,12 +175,30 @@ void ThumbnailImage::NotifyCompressedDataObservers(
 }
 
 // static
-std::vector<uint8_t> ThumbnailImage::CompressBitmap(SkBitmap bitmap) {
+std::vector<uint8_t> ThumbnailImage::CompressBitmap(
+    SkBitmap bitmap,
+    base::Optional<uint64_t> frame_id) {
   constexpr int kCompressionQuality = 97;
   std::vector<uint8_t> data;
-  const bool result =
-      gfx::JPEGCodec::Encode(bitmap, kCompressionQuality, &data);
-  DCHECK(result);
+
+  // Similar to above, extract logic into function so we can select a
+  // TRACE_EVENT_* macro.
+  auto compress = [&]() {
+    const bool result =
+        gfx::JPEGCodec::Encode(bitmap, kCompressionQuality, &data);
+    DCHECK(result);
+  };
+
+  if (frame_id) {
+    TRACE_EVENT_WITH_FLOW0(
+        "ui", "Tab.Preview.CompressJPEGWithFlow", *frame_id,
+        TRACE_EVENT_FLAG_FLOW_IN | TRACE_EVENT_FLAG_FLOW_OUT);
+    compress();
+  } else {
+    TRACE_EVENT0("ui", "Tab.Preview.CompressJPEG");
+    compress();
+  }
+
   return data;
 }
 

chrome/browser/ui/thumbnails/thumbnail_image.h

@@ -5,6 +5,7 @@
 #ifndef CHROME_BROWSER_UI_THUMBNAILS_THUMBNAIL_IMAGE_H_
 #define CHROME_BROWSER_UI_THUMBNAILS_THUMBNAIL_IMAGE_H_
 
+#include <stdint.h>
 #include <memory>
 #include <utility>
 #include <vector>
@@ -113,7 +114,8 @@ class ThumbnailImage : public base::RefCounted<ThumbnailImage> {
   std::unique_ptr<Subscription> Subscribe();
 
   // Sets the SkBitmap data and notifies observers with the resulting image.
-  void AssignSkBitmap(SkBitmap bitmap);
+  void AssignSkBitmap(SkBitmap bitmap,
+                      base::Optional<uint64_t> frame_id = base::nullopt);
 
   // Clears the currently set |data_|, for when the current thumbnail is no
   // longer valid to display.
@@ -148,12 +150,14 @@ class ThumbnailImage : public base::RefCounted<ThumbnailImage> {
   virtual ~ThumbnailImage();
 
   void AssignJPEGData(base::TimeTicks assign_sk_bitmap_time,
+                      base::Optional<uint64_t> frame_id,
                       std::vector<uint8_t> data);
   bool ConvertJPEGDataToImageSkiaAndNotifyObservers();
   void NotifyUncompressedDataObservers(gfx::ImageSkia image);
   void NotifyCompressedDataObservers(CompressedThumbnailData data);
 
-  static std::vector<uint8_t> CompressBitmap(SkBitmap bitmap);
+  static std::vector<uint8_t> CompressBitmap(SkBitmap bitmap,
+                                             base::Optional<uint64_t> frame_id);
   static gfx::ImageSkia UncompressImage(CompressedThumbnailData compressed);
 
   // Crops and returns a preview from a thumbnail of an entire web page. Uses

chrome/browser/ui/thumbnails/thumbnail_image_unittest.cc

@@ -10,6 +10,7 @@
 #include "base/bind.h"
 #include "base/macros.h"
 #include "base/memory/weak_ptr.h"
+#include "base/optional.h"
 #include "base/run_loop.h"
 #include "base/scoped_observer.h"
 #include "base/test/task_environment.h"
@@ -89,7 +90,7 @@ class ThumbnailImageTest : public testing::Test,
   }
 
   std::vector<uint8_t> Compress(SkBitmap bitmap) const {
-    return ThumbnailImage::CompressBitmap(bitmap);
+    return ThumbnailImage::CompressBitmap(bitmap, base::nullopt);
   }
 
   bool is_being_observed() const { return is_being_observed_; }
@@ -149,7 +150,7 @@ TEST_F(ThumbnailImageTest, AssignSkBitmapNotifiesObservers) {
       IgnoreArgs<gfx::ImageSkia>(waiter2.callback()));
 
   SkBitmap bitmap = CreateBitmap(kTestBitmapWidth, kTestBitmapHeight);
-  image->AssignSkBitmap(bitmap);
+  image->AssignSkBitmap(bitmap, base::nullopt);
 
   waiter1.Wait();
   waiter2.Wait();
@@ -172,7 +173,7 @@ TEST_F(ThumbnailImageTest, AssignSkBitmap_NotifiesObserversAgain) {
       IgnoreArgs<gfx::ImageSkia>(waiter2.callback()));
 
   SkBitmap bitmap = CreateBitmap(kTestBitmapWidth, kTestBitmapHeight);
-  image->AssignSkBitmap(bitmap);
+  image->AssignSkBitmap(bitmap, base::nullopt);
 
   waiter1.Wait();
   waiter2.Wait();
@@ -182,7 +183,7 @@ TEST_F(ThumbnailImageTest, AssignSkBitmap_NotifiesObserversAgain) {
   waiter1.Reset();
   waiter2.Reset();
 
-  image->AssignSkBitmap(bitmap);
+  image->AssignSkBitmap(bitmap, base::nullopt);
 
   waiter1.Wait();
   waiter2.Wait();
@@ -205,7 +206,7 @@ TEST_F(ThumbnailImageTest, AssignSkBitmap_NotifiesCompressedObservers) {
       IgnoreArgs<ThumbnailImage::CompressedThumbnailData>(waiter2.callback()));
 
   SkBitmap bitmap = CreateBitmap(kTestBitmapWidth, kTestBitmapHeight);
-  image->AssignSkBitmap(bitmap);
+  image->AssignSkBitmap(bitmap, base::nullopt);
 
   waiter1.Wait();
   waiter2.Wait();
@@ -228,7 +229,7 @@ TEST_F(ThumbnailImageTest, AssignSkBitmap_NotifiesCompressedObserversAgain) {
       IgnoreArgs<ThumbnailImage::CompressedThumbnailData>(waiter2.callback()));
 
   SkBitmap bitmap = CreateBitmap(kTestBitmapWidth, kTestBitmapHeight);
-  image->AssignSkBitmap(bitmap);
+  image->AssignSkBitmap(bitmap, base::nullopt);
 
   waiter1.Wait();
   waiter2.Wait();
@@ -238,7 +239,7 @@ TEST_F(ThumbnailImageTest, AssignSkBitmap_NotifiesCompressedObserversAgain) {
   waiter1.Reset();
   waiter2.Reset();
 
-  image->AssignSkBitmap(bitmap);
+  image->AssignSkBitmap(bitmap, base::nullopt);
 
   waiter1.Wait();
   waiter2.Wait();
@@ -256,7 +257,7 @@ TEST_F(ThumbnailImageTest, RequestThumbnailImage) {
       IgnoreArgs<gfx::ImageSkia>(waiter1.callback()));
 
   SkBitmap bitmap = CreateBitmap(kTestBitmapWidth, kTestBitmapHeight);
-  image->AssignSkBitmap(bitmap);
+  image->AssignSkBitmap(bitmap, base::nullopt);
   waiter1.Wait();
   EXPECT_TRUE(waiter1.called());
   waiter1.Reset();
@@ -284,7 +285,7 @@ TEST_F(ThumbnailImageTest, RequestCompressedThumbnailData) {
       IgnoreArgs<ThumbnailImage::CompressedThumbnailData>(waiter.callback()));
 
   SkBitmap bitmap = CreateBitmap(kTestBitmapWidth, kTestBitmapHeight);
-  image->AssignSkBitmap(bitmap);
+  image->AssignSkBitmap(bitmap, base::nullopt);
   waiter.Wait();
   EXPECT_TRUE(waiter.called());
   waiter.Reset();
@@ -304,7 +305,7 @@ TEST_F(ThumbnailImageTest, ClearThumbnailWhileNotifyingObservers) {
       IgnoreArgs<gfx::ImageSkia>(waiter.callback()));
 
   SkBitmap bitmap = CreateBitmap(kTestBitmapWidth, kTestBitmapHeight);
-  image->AssignSkBitmap(bitmap);
+  image->AssignSkBitmap(bitmap, base::nullopt);
   waiter.Wait();
   EXPECT_TRUE(waiter.called());
   waiter.Reset();

chrome/browser/ui/thumbnails/thumbnail_tab_helper.cc

@@ -4,6 +4,7 @@
 
 #include "chrome/browser/ui/thumbnails/thumbnail_tab_helper.h"
 
+#include <stdint.h>
 #include <algorithm>
 #include <set>
 #include <utility>
@@ -12,6 +13,7 @@
 #include "base/check_op.h"
 #include "base/metrics/histogram_macros.h"
 #include "base/no_destructor.h"
+#include "base/optional.h"
 #include "base/task/post_task.h"
 #include "base/task/task_traits.h"
 #include "base/task/thread_pool.h"
@@ -217,9 +219,9 @@ ThumbnailTabHelper::ThumbnailTabHelper(content::WebContents* contents)
     : state_(std::make_unique<TabStateTracker>(this, contents)),
       background_capturer_(std::make_unique<BackgroundThumbnailVideoCapturer>(
           contents,
-          base::BindRepeating(&ThumbnailTabHelper::StoreThumbnail,
-                              base::Unretained(this),
-                              CaptureType::kVideoFrame))),
+          base::BindRepeating(
+              &ThumbnailTabHelper::StoreThumbnailForBackgroundCapture,
+              base::Unretained(this)))),
       thumbnail_(base::MakeRefCounted<ThumbnailImage>(state_.get())) {}
 
 ThumbnailTabHelper::~ThumbnailTabHelper() {
@@ -274,11 +276,18 @@ void ThumbnailTabHelper::StoreThumbnailForTabSwitch(base::TimeTicks start_time,
                              base::TimeTicks::Now() - start_time,
                              base::TimeDelta::FromMilliseconds(1),
                              base::TimeDelta::FromSeconds(1), 50);
-  StoreThumbnail(CaptureType::kCopyFromView, bitmap);
+  StoreThumbnail(CaptureType::kCopyFromView, bitmap, base::nullopt);
+}
+
+void ThumbnailTabHelper::StoreThumbnailForBackgroundCapture(
+    const SkBitmap& bitmap,
+    uint64_t frame_id) {
+  StoreThumbnail(CaptureType::kVideoFrame, bitmap, frame_id);
 }
 
 void ThumbnailTabHelper::StoreThumbnail(CaptureType type,
-                                        const SkBitmap& bitmap) {
+                                        const SkBitmap& bitmap,
+                                        base::Optional<uint64_t> frame_id) {
   // Failed requests will return an empty bitmap. In tests this can be triggered
   // on threads other than the UI thread.
   if (bitmap.drawsNothing())
@@ -288,7 +297,7 @@ void ThumbnailTabHelper::StoreThumbnail(CaptureType type,
 
   RecordCaptureType(type);
   state_->OnFrameCaptured(type);
-  thumbnail_->AssignSkBitmap(bitmap);
+  thumbnail_->AssignSkBitmap(bitmap, frame_id);
 }
 
 void ThumbnailTabHelper::ClearData() {

chrome/browser/ui/thumbnails/thumbnail_tab_helper.h

@@ -9,6 +9,7 @@
 
 #include "base/macros.h"
 #include "base/memory/weak_ptr.h"
+#include "base/optional.h"
 #include "base/scoped_observer.h"
 #include "base/time/time.h"
 #include "chrome/browser/ui/thumbnails/thumbnail_capture_info.h"
@@ -48,9 +49,15 @@ class ThumbnailTabHelper
   void StartVideoCapture();
   void StopVideoCapture();
   void CaptureThumbnailOnTabHidden();
+
   void StoreThumbnailForTabSwitch(base::TimeTicks start_time,
                                   const SkBitmap& bitmap);
-  void StoreThumbnail(CaptureType type, const SkBitmap& bitmap);
+  void StoreThumbnailForBackgroundCapture(const SkBitmap& bitmap,
+                                          uint64_t frame_id);
+  void StoreThumbnail(CaptureType type,
+                      const SkBitmap& bitmap,
+                      base::Optional<uint64_t> frame_id);
+
   // Clears the data associated to the currently set thumbnail. For when the
   // thumbnail is no longer valid.
   void ClearData();