[scheduler] Add RendererScheduler.TaskDurationPerQueueType.

third_party/WebKit/Source/platform/scheduler/renderer/renderer_scheduler_impl.cc

 // Copyright 2014 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 "platform/scheduler/renderer/renderer_scheduler_impl.h"
 
 #include "base/bind.h"
 #include "base/debug/stack_trace.h"
 #include "base/logging.h"
 #include "base/memory/ptr_util.h"
+#include "base/metrics/histogram.h"
 #include "base/metrics/histogram_macros.h"
 #include "base/threading/thread_task_runner_handle.h"
 #include "base/trace_event/trace_event.h"
 #include "base/trace_event/trace_event_argument.h"
 #include "cc/output/begin_frame_args.h"
 #include "platform/RuntimeEnabledFeatures.h"
 #include "platform/scheduler/base/real_time_domain.h"
 #include "platform/scheduler/base/task_queue_impl.h"
 #include "platform/scheduler/base/task_queue_selector.h"
 #include "platform/scheduler/base/time_converter.h"
@@ skipping 24 matching lines @@
 const double kFastCompositingIdleTimeThreshold = .2;
 constexpr base::TimeDelta kThreadLoadTrackerReportingInterval =
     base::TimeDelta::FromMinutes(1);
 constexpr base::TimeDelta kThreadLoadTrackerWaitingPeriodBeforeReporting =
     base::TimeDelta::FromMinutes(2);
 // We do not throttle anything while audio is played and shortly after that.
 constexpr base::TimeDelta kThrottlingDelayAfterAudioIsPlayed =
     base::TimeDelta::FromSeconds(5);
 constexpr base::TimeDelta kQueueingTimeWindowDuration =
     base::TimeDelta::FromSeconds(1);
+// Maximal bound on task duration for reporting.
+constexpr base::TimeDelta kMaxTaskDurationForReporting =
+    base::TimeDelta::FromMinutes(1);
 
 void ReportForegroundRendererTaskLoad(base::TimeTicks time, double load) {
   if (!blink::RuntimeEnabledFeatures::timerThrottlingForBackgroundTabsEnabled())
     return;
 
   int load_percentage = static_cast<int>(load * 100);
   DCHECK_LE(load_percentage, 100);
 
   UMA_HISTOGRAM_PERCENTAGE("RendererScheduler.ForegroundRendererMainThreadLoad",
                            load_percentage);
@@ skipping 142 matching lines @@
       touchstart_expected_soon(false),
       have_seen_a_begin_main_frame(false),
       have_reported_blocking_intervention_in_current_policy(false),
       have_reported_blocking_intervention_since_navigation(false),
       has_visible_render_widget_with_touch_handler(false),
       begin_frame_not_expected_soon(false),
       in_idle_period_for_testing(false),
       use_virtual_time(false),
       is_audio_playing(false),
       rail_mode_observer(nullptr),
-      wake_up_budget_pool(nullptr) {
+      wake_up_budget_pool(nullptr),
+      task_duration_per_queue_type_histogram(base::Histogram::FactoryGet(
+          "RendererScheduler.TaskDurationPerQueueType",
+          1,
+          static_cast<int>(TaskQueue::QueueType::COUNT),
+          static_cast<int>(TaskQueue::QueueType::COUNT) + 1,
+          base::HistogramBase::kUmaTargetedHistogramFlag)) {
   foreground_main_thread_load_tracker.Resume(now);
 }
 
 RendererSchedulerImpl::MainThreadOnly::~MainThreadOnly() {}
 
 RendererSchedulerImpl::AnyThread::AnyThread()
     : awaiting_touch_start_response(false),
       in_idle_period(false),
       begin_main_frame_on_critical_path(false),
       last_gesture_was_compositor_driven(false),
@@ skipping 1595 matching lines @@
 
   task_queue_throttler()->OnTaskRunTimeReported(task_queue, start_time_ticks,
                                                 end_time_ticks);
 
   // We want to measure thread time here, but for efficiency reasons
   // we stick with wall time.
   GetMainThreadOnly().foreground_main_thread_load_tracker.RecordTaskTime(
       start_time_ticks, end_time_ticks);
   GetMainThreadOnly().background_main_thread_load_tracker.RecordTaskTime(
       start_time_ticks, end_time_ticks);
+
   // TODO(altimin): Per-page metrics should also be considered.
-  UMA_HISTOGRAM_CUSTOM_COUNTS(
-      "RendererScheduler.TaskTime",
-      (end_time_ticks - start_time_ticks).InMicroseconds(), 1, 1000000, 50);
+  RecordTaskMetrics(task_queue->GetQueueType(),
+                    end_time_ticks - start_time_ticks);
+}
+
+void RendererSchedulerImpl::RecordTaskMetrics(TaskQueue::QueueType queue_type,
+                                              base::TimeDelta duration) {
+  UMA_HISTOGRAM_CUSTOM_COUNTS("RendererScheduler.TaskTime",
+                              duration.InMicroseconds(), 1, 1000 * 1000, 50);
+
   UMA_HISTOGRAM_ENUMERATION("RendererScheduler.NumberOfTasksPerQueueType",
-                            static_cast<int>(task_queue->GetQueueType()),
+                            static_cast<int>(queue_type),
                             static_cast<int>(TaskQueue::QueueType::COUNT));
+
+  RecordTaskDurationPerQueueType(queue_type, duration);
+}
+
+void RendererSchedulerImpl::RecordTaskDurationPerQueueType(
+    TaskQueue::QueueType queue_type,
+    base::TimeDelta duration) {
+  duration = std::min(duration, kMaxTaskDurationForReporting);
+
+  // Report only whole milliseconds to avoid overflow.
+  base::TimeDelta& total_duration =

[Ilya Sherman, 2017/05/15 22:53:22]

Optional nit: Maybe name this something like "unreported_duration" for greater
clarity?

[altimin, 2017/05/16 11:56:14]

Done.

+      GetMainThreadOnly()
+          .task_duration_per_queue_type[static_cast<int>(queue_type)];
+  total_duration += duration;
+  int64_t milliseconds = total_duration.InMilliseconds();
+  if (milliseconds > 0) {
+    total_duration -= base::TimeDelta::FromMilliseconds(milliseconds);
+    GetMainThreadOnly().task_duration_per_queue_type_histogram->AddCount(
+        static_cast<int>(queue_type), static_cast<int>(milliseconds));
+  }
 }
 
 void RendererSchedulerImpl::OnBeginNestedRunLoop() {
   seqlock_queueing_time_estimator_.seqlock.WriteBegin();
   seqlock_queueing_time_estimator_.data.OnBeginNestedRunLoop();
   seqlock_queueing_time_estimator_.seqlock.WriteEnd();
 }
 
 void RendererSchedulerImpl::AddTaskTimeObserver(
     TaskTimeObserver* task_time_observer) {
@@ skipping 158 matching lines @@
     case TimeDomainType::VIRTUAL:
       return "virtual";
     default:
       NOTREACHED();
       return nullptr;
   }
 }
 
 }  // namespace scheduler
 }  // namespace blink