Long tasks: add a trace event for long tasks

third_party/WebKit/Source/platform/scheduler/base/task_queue_manager.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/base/task_queue_manager.h"
 
 #include <queue>
 #include <set>
 
 #include "base/bind.h"
 #include "base/metrics/histogram_macros.h"
 #include "base/trace_event/trace_event.h"
 #include "platform/scheduler/base/real_time_domain.h"
 #include "platform/scheduler/base/task_queue_impl.h"
 #include "platform/scheduler/base/task_queue_manager_delegate.h"
 #include "platform/scheduler/base/task_queue_selector.h"
 #include "platform/scheduler/base/task_time_observer.h"
 #include "platform/scheduler/base/work_queue.h"
 #include "platform/scheduler/base/work_queue_sets.h"
 #include "platform/wtf/PtrUtil.h"
 
+static const double kLongTaskTraceEventThreshold = 0.05;
+
 namespace blink {
 namespace scheduler {
 
 namespace {
 const size_t kRecordRecordTaskDelayHistogramsEveryNTasks = 10;
 
 void RecordDelayedTaskLateness(base::TimeDelta lateness) {
   UMA_HISTOGRAM_TIMES("RendererScheduler.TaskQueueManager.DelayedTaskLateness",
                       lateness);
 }
@@ skipping 496 matching lines @@
       currently_executing_task_queue_;
   currently_executing_task_queue_ = queue;
   task_annotator_.RunTask("TaskQueueManager::PostTask", &pending_task);
   // Detect if the TaskQueueManager just got deleted.  If this happens we must
   // not access any member variables after this point.
   if (protect->HasOneRef())
     return ProcessTaskResult::TASK_QUEUE_MANAGER_DELETED;
 
   currently_executing_task_queue_ = prev_executing_task_queue;
 
-
+  double task_end_time = 0;
   if (queue->GetShouldNotifyObservers()) {
     if (task_start_time) {
       *time_after_task = real_time_domain()->Now();
-      double task_end_time = MonotonicTimeInSeconds(*time_after_task);
+      task_end_time = MonotonicTimeInSeconds(*time_after_task);
 
       queue->OnTaskCompleted(
           base::TimeTicks() + base::TimeDelta::FromSecondsD(task_start_time),
           base::TimeTicks() + base::TimeDelta::FromSecondsD(task_end_time));
 
       for (auto& observer : task_time_observers_)
         observer.DidProcessTask(task_start_time, task_end_time);
     }
 
     for (auto& observer : task_observers_)
       observer.DidProcessTask(pending_task);
     queue->NotifyDidProcessTask(pending_task);
   }
 
+  if (task_start_time && task_end_time &&
+      task_end_time - task_start_time > kLongTaskTraceEventThreshold) {
+    TRACE_EVENT_INSTANT1("blink", "LongTask", TRACE_EVENT_SCOPE_THREAD,
+                         "duration", task_end_time - task_start_time);
+  }
+
   return ProcessTaskResult::EXECUTED;
 }
 
 void TaskQueueManager::MaybeRecordTaskDelayHistograms(
     const internal::TaskQueueImpl::Task& pending_task,
     const internal::TaskQueueImpl* queue) {
   if ((task_count_++ % kRecordRecordTaskDelayHistogramsEveryNTasks) != 0)
     return;
 
   // Record delayed task lateness and immediate task queuing durations.
@@ skipping 140 matching lines @@
     TimeDomain* time_domain = queue->GetTimeDomain();
     if (time_domain_now.find(time_domain) == time_domain_now.end())
       time_domain_now.insert(std::make_pair(time_domain, time_domain->Now()));
     queue->GetTaskQueueImpl()->SweepCanceledDelayedTasks(
         time_domain_now[time_domain]);
   }
 }
 
 }  // namespace scheduler
 }  // namespace blink