scheduler: Add support for tracing scheduler state

content/renderer/scheduler/renderer_scheduler_selector.cc

Index: content/renderer/scheduler/renderer_scheduler_selector.cc
diff --git a/content/renderer/scheduler/renderer_scheduler_selector.cc b/content/renderer/scheduler/renderer_scheduler_selector.cc
index 4741b705c7f6f6d1114ec68ebfcec4738d236ba0..02c8144cd15fa75e2a7d6d626afe0fa26e1e1fe5 100644
--- a/content/renderer/scheduler/renderer_scheduler_selector.cc
+++ b/content/renderer/scheduler/renderer_scheduler_selector.cc
@@ -4,21 +4,38 @@
 
 #include "content/renderer/scheduler/renderer_scheduler_selector.h"
 
+#include "base/debug/trace_event_argument.h"
 #include "base/logging.h"
 #include "base/pending_task.h"
+#include "base/strings/string_number_conversions.h"
+#include "content/renderer/scheduler/task_queue_manager.h"
 
 namespace content {
 
+RendererSchedulerSelector::Queue::Queue() : work_queue(nullptr), name(nullptr) {
+}
+
 RendererSchedulerSelector::RendererSchedulerSelector() : starvation_count_(0) {
+  TRACE_EVENT_OBJECT_CREATED_WITH_ID(
+      TRACE_DISABLED_BY_DEFAULT("blink.scheduler"),
+      "RendererSchedulerSelector",
+      this);
 }
 
 RendererSchedulerSelector::~RendererSchedulerSelector() {
+  TRACE_EVENT_OBJECT_DELETED_WITH_ID(
+      TRACE_DISABLED_BY_DEFAULT("blink.scheduler"),
+      "RendererSchedulerSelector",
+      this);
 }
 
 void RendererSchedulerSelector::RegisterWorkQueues(
     const std::vector<const base::TaskQueue*>& work_queues) {
   main_thread_checker_.CalledOnValidThread();
-  work_queues_ = work_queues;
+  queues_.clear();
+  queues_.resize(work_queues.size());
+  for (size_t i = 0; i < work_queues.size(); i++)
+    queues_[i].work_queue = work_queues[i];

[rmcilroy, 2014/10/27 17:51:28]

Maybe set a default "unknown" name to avoid segfaults if you forget to set the
names (or do the trace functions handle this already)?

[Sami, 2014/10/28 12:57:47]

I'm only tracing the counter value if the queue has a valid name.

   for (QueuePriority priority = kFirstQueuePriority;
        priority < kQueuePriorityCount;
        priority = NextPriority(priority)) {
@@ -33,7 +50,7 @@ void RendererSchedulerSelector::RegisterWorkQueues(
 void RendererSchedulerSelector::SetQueuePriority(size_t queue_index,
                                                  QueuePriority priority) {
   main_thread_checker_.CalledOnValidThread();
-  DCHECK_LT(queue_index, work_queues_.size());
+  DCHECK_LT(queue_index, queues_.size());
   DCHECK_LT(priority, kQueuePriorityCount);
   DisableQueue(queue_index);
   queue_priorities_[priority].insert(queue_index);
@@ -46,7 +63,7 @@ void RendererSchedulerSelector::EnableQueue(size_t queue_index,
 
 void RendererSchedulerSelector::DisableQueue(size_t queue_index) {
   main_thread_checker_.CalledOnValidThread();
-  DCHECK_LT(queue_index, work_queues_.size());
+  DCHECK_LT(queue_index, queues_.size());
   for (QueuePriority priority = kFirstQueuePriority;
        priority < kQueuePriorityCount;
        priority = NextPriority(priority)) {
@@ -54,6 +71,13 @@ void RendererSchedulerSelector::DisableQueue(size_t queue_index) {
   }
 }
 
+void RendererSchedulerSelector::SetQueueName(size_t queue_index,
+                                             const char* name) {
+  main_thread_checker_.CalledOnValidThread();
+  DCHECK_LT(queue_index, queues_.size());
+  queues_[queue_index].name = name;
+}
+
 bool RendererSchedulerSelector::IsOlder(const base::TaskQueue* queueA,
                                         const base::TaskQueue* queueB) {
   // Note: the comparison is correct due to the fact that the PendingTask
@@ -74,11 +98,11 @@ bool RendererSchedulerSelector::ChooseOldestWithPriority(
   bool found_non_empty_queue = false;
   size_t chosen_queue = 0;
   for (int queue_index : queue_priorities_[priority]) {
-    if (work_queues_[queue_index]->empty()) {
+    if (queues_[queue_index].work_queue->empty()) {
       continue;
     }
-    if (!found_non_empty_queue ||
-        IsOlder(work_queues_[queue_index], work_queues_[chosen_queue])) {
+    if (!found_non_empty_queue || IsOlder(queues_[queue_index].work_queue,
+                                          queues_[chosen_queue].work_queue)) {
       found_non_empty_queue = true;
       chosen_queue = queue_index;
     }
@@ -93,30 +117,97 @@ bool RendererSchedulerSelector::ChooseOldestWithPriority(
 bool RendererSchedulerSelector::SelectWorkQueueToService(
     size_t* out_queue_index) {
   main_thread_checker_.CalledOnValidThread();
-  DCHECK(work_queues_.size());
+  DCHECK(queues_.size());
+
   // Always service the control queue if it has any work.
   if (ChooseOldestWithPriority(kControlPriority, out_queue_index)) {
+    DidSelectQueue(*out_queue_index, kControlPriority);
     return true;
   }
   // Select from the normal priority queue if we are starving it.
   if (starvation_count_ >= kMaxStarvationTasks &&
       ChooseOldestWithPriority(kNormalPriority, out_queue_index)) {
-    starvation_count_ = 0;
+    DidSelectQueue(*out_queue_index, kNormalPriority);
     return true;
   }
   // Otherwise choose in priority order.
   for (QueuePriority priority = kHighPriority; priority < kQueuePriorityCount;
        priority = NextPriority(priority)) {
     if (ChooseOldestWithPriority(priority, out_queue_index)) {
-      if (priority == kHighPriority) {
-        starvation_count_++;
-      } else {
-        starvation_count_ = 0;
-      }
+      DidSelectQueue(*out_queue_index, priority);
       return true;
     }
   }
   return false;
 }
 
+void RendererSchedulerSelector::DidSelectQueue(size_t selected_queue,
+                                               QueuePriority priority) {
+  TRACE_EVENT_OBJECT_SNAPSHOT_WITH_ID(
+      TRACE_DISABLED_BY_DEFAULT("blink.scheduler"),
+      "RendererSchedulerSelector",
+      this,
+      AsValueWithSelectedQueue(selected_queue));
+  for (size_t i = 0; i < queues_.size(); i++) {
+    if (queues_[i].name)
+      TRACE_COUNTER1(TRACE_DISABLED_BY_DEFAULT("blink.scheduler"),
+                     queues_[i].name,
+                     queues_[i].work_queue->size());
+  }

[rmcilroy, 2014/10/27 17:51:28]

Could we encapsulate this tracing code in a function call?

[picksi1, 2014/10/28 11:01:40]

Does this all boil away in release builds? I worry about impacting
performance...

[Sami, 2014/10/28 12:57:47]

Tracing is always compiled in -- having separate builds would just be too
cumbersome. It is very efficient when it is disabled at run time -- the only
cost you pay is a non-atomic read per trace event.

With the new patch this is more efficient since we don't iterate over the task
queues until we actually know we're tracing.

[Sami, 2014/10/28 12:57:47]

I've now moved this to TQM and it's much cleaner there. Thanks for the
suggestion!

+
+  if (priority == kHighPriority) {
+    starvation_count_++;
+  } else if (priority >= kNormalPriority) {

[rmcilroy, 2014/10/27 17:51:28]

This is a bit confusing since ">= normal" sounds like higher or above priority. 
Maybe just "else if (priority != kControlPriority)?

[picksi1, 2014/10/28 11:01:40]

Or should this be a case statement (following the pattern used by
RendererSchedulerSelector() below?)

[Sami, 2014/10/28 12:57:47]

I suppose a switch case would be more future proof. Done.

[Sami, 2014/10/28 12:57:47]

Agreed, done.

+    starvation_count_ = 0;
+  }
+}
+
+scoped_refptr<base::debug::ConvertableToTraceFormat>
+RendererSchedulerSelector::AsValueWithSelectedQueue(
+    size_t selected_queue) const {
+  main_thread_checker_.CalledOnValidThread();
+  scoped_refptr<base::debug::TracedValue> state =
+      new base::debug::TracedValue();
+  state->BeginArray("work_queues");
+  for (const auto& queue : queues_)
+    TaskQueueManager::QueueAsValueInto(*queue.work_queue, state.get());

[rmcilroy, 2014/10/27 17:51:28]

I'm not sure we should be serializing the taskQueueManager queues here.  It
doesn't capture the incoming tasks so I'm not sure if it would be completely
clear.  Would it be better to do this tracing in TaskQueueManager, and have that
class keep the names of the queues instead of the selector?  I think this would
be a clearer separation (you could add AsValueInto(...) to the TaskQueueSelector
interface and have the TaskQueueManager call that to serialize the priority
state when building a Trace Event after calling SelectWorkQueueToService.  WDYT?

[Sami, 2014/10/28 12:57:47]

Yeah, I think I agree with you. Doing it this way is a little backwards. I've
now moved everything to the TQM. The only downside is that we can't easily
parameterize the category used by TQM for tracing, which will complicate things
a little if we ever want to move TQM to base.

+  state->EndArray();
+  state->SetInteger("selected_queue", selected_queue);
+  AsValueInto(state.get());
+  return state;
+}
+
+// static
+const char* RendererSchedulerSelector::PriorityToString(
+    QueuePriority priority) {
+  switch (priority) {
+    case kControlPriority:
+      return "control";
+    case kHighPriority:
+      return "high";
+    case kNormalPriority:
+      return "normal";
+    case kBestEffortPriority:
+      return "best_effort";
+    default:
+      NOTREACHED();
+      return nullptr;
+  }
+}
+
+void RendererSchedulerSelector::AsValueInto(
+    base::debug::TracedValue* state) const {
+  main_thread_checker_.CalledOnValidThread();
+  state->BeginDictionary("priorities");
+  for (QueuePriority priority = kHighPriority; priority < kQueuePriorityCount;

[rmcilroy, 2014/10/27 17:51:28]

Should we not expose the control priority here?

[Sami, 2014/10/28 12:57:47]

Ack, bad copy & paste. Thanks.

+       priority = NextPriority(priority)) {
+    state->BeginArray(PriorityToString(priority));
+    for (size_t queue_index : queue_priorities_[priority])
+      state->AppendInteger(queue_index);
+    state->EndArray();
+  }
+  state->EndDictionary();
+  state->SetInteger("starvation_count", starvation_count_);
+}
+
 }  // namespace content