Revert 221427 "Add instrumentation to the MessagePumpMac family ..."

This code is no longer needed, since the experiment is not viable.

> Add instrumentation to the MessagePumpMac family of classes.
>
> This adds UMA-uploaded histograms of sampling intervals for key points of data:
> * Total time spent in a CFRunLoop
> * Total time waiting in CFRunLoop
> * Total time servicing MessagePump::Delegate (the MessageLoop)
> * The MessageLoop queue size and queueing delay before servicing
>
> It adds 1 second sampling for 15 seconds at startup, only for the main thread
> (NSApplication-based) run loops.
>
> The data will be used to determine if adding scheduling-like behavior to the
> MessagePump will result in more efficient processing of the MessageLoop work.
>
> An unforunate side effect of this change is exposing another method on the
> MessagePump::Delegate interface, but there does not appear to be a better way
> to do this.
>
> BUG=264886
> R=jar@chromium.org, mark@chromium.org
>
> Review URL: https://codereview.chromium.org/22911026

TBR=rsesek@chromium.org

Review URL: https://codereview.chromium.org/360373004

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@280939 0039d316-1c4b-4281-b951-d872f2087c98

5 files changed, 15 insertions, 307 deletions

diff --git a/base/message_loop/message_loop.cc b/base/message_loop/message_loop.cc
index ccece4d..8e817dab 100644
--- a/base/message_loop/message_loop.cc
+++ b/base/message_loop/message_loop.cc
@@ -632,20 +632,6 @@ bool MessageLoop::DoIdleWork() {
   return false;
 }
 
-void MessageLoop::GetQueueingInformation(size_t* queue_size,
-                                         TimeDelta* queueing_delay) {
-  *queue_size = work_queue_.size();
-  if (*queue_size == 0) {
-    *queueing_delay = TimeDelta();
-    return;
-  }
-
-  const PendingTask& next_to_run = work_queue_.front();
-  tracked_objects::Duration duration =
-      tracked_objects::TrackedTime::Now() - next_to_run.EffectiveTimePosted();
-  *queueing_delay = TimeDelta::FromMilliseconds(duration.InMilliseconds());
-}
-
 void MessageLoop::DeleteSoonInternal(const tracked_objects::Location& from_here,
                                      void(*deleter)(const void*),
                                      const void* object) {
diff --git a/base/message_loop/message_loop.h b/base/message_loop/message_loop.h
index 22d4f73..a65fbf5 100644
--- a/base/message_loop/message_loop.h
+++ b/base/message_loop/message_loop.h
@@ -446,8 +446,6 @@ class BASE_EXPORT MessageLoop : public MessagePump::Delegate {
   virtual bool DoWork() OVERRIDE;
   virtual bool DoDelayedWork(TimeTicks* next_delayed_work_time) OVERRIDE;
   virtual bool DoIdleWork() OVERRIDE;
-  virtual void GetQueueingInformation(size_t* queue_size,
-                                      TimeDelta* queueing_delay) OVERRIDE;
 
   const Type type_;
 
diff --git a/base/message_loop/message_pump.h b/base/message_loop/message_pump.h
index a795f31..4dc501b6 100644
--- a/base/message_loop/message_pump.h
+++ b/base/message_loop/message_pump.h
@@ -12,7 +12,6 @@
 
 namespace base {
 
-class TimeDelta;
 class TimeTicks;
 
 class BASE_EXPORT MessagePump : public NonThreadSafe {
@@ -42,19 +41,6 @@ class BASE_EXPORT MessagePump : public NonThreadSafe {
     // Called from within Run just before the message pump goes to sleep.
     // Returns true to indicate that idle work was done.
     virtual bool DoIdleWork() = 0;
-
-    // Via the two required out pointers, returns the length of the Delegate's
-    // work queue and the length of time that the first item in the queue has
-    // been waiting to run. If the work queue is empty, the count and delay
-    // will both be zero.
-    // Note that this only counts the tasks in the ready-to-run queue and not
-    // the incoming queue that is used by other threads to post tasks. The
-    // latter queue requires holding a lock, which is deemed too expensive for
-    // instrumentation code. Under normal conditions, the incoming queue should
-    // be small or zero, but under heavy loads it may be much larger and
-    // |queue_count| may be up to 1/4 the size of the incoming queue.
-    virtual void GetQueueingInformation(size_t* queue_count,
-                                        TimeDelta* queueing_delay) {}
   };
 
   MessagePump();
diff --git a/base/message_loop/message_pump_mac.h b/base/message_loop/message_pump_mac.h
index 6e63d2b..f52bd76 100644
--- a/base/message_loop/message_pump_mac.h
+++ b/base/message_loop/message_pump_mac.h
@@ -58,7 +58,6 @@
 
 namespace base {
 
-class MessagePumpInstrumentation;
 class RunLoop;
 class TimeTicks;
 
@@ -112,11 +111,6 @@ class MessagePumpCFRunLoopBase : public MessagePump {
   // objects autoreleased by work to fall into the current autorelease pool.
   virtual AutoreleasePoolType* CreateAutoreleasePool();
 
-  // Enables instrumentation of the MessagePump. See MessagePumpInstrumentation
-  // in the implementation for details.
-  void EnableInstrumentation();
-  WeakPtr<MessagePumpInstrumentation> instrumentation_;
-
  private:
   // Timer callback scheduled by ScheduleDelayedWork.  This does not do any
   // work, but it signals work_source_ so that delayed work can be performed
@@ -130,11 +124,11 @@ class MessagePumpCFRunLoopBase : public MessagePump {
   static void RunWorkSource(void* info);
   bool RunWork();
 
-  // Perform idle-priority work.  This is normally called by
-  // StartOrEndWaitObserver, but is also associated with idle_work_source_. When
-  // this function actually does perform idle work, it will resignal that
-  // source.  The static method calls the instance method; the instance method
-  // returns true if idle work was done.
+  // Perform idle-priority work.  This is normally called by PreWaitObserver,
+  // but is also associated with idle_work_source_.  When this function
+  // actually does perform idle work, it will resignal that source.  The
+  // static method calls the instance method; the instance method returns
+  // true if idle work was done.
   static void RunIdleWorkSource(void* info);
   bool RunIdleWork();
 
@@ -156,8 +150,8 @@ class MessagePumpCFRunLoopBase : public MessagePump {
 
   // Observer callback responsible for performing idle-priority work, before
   // the run loop goes to sleep.  Associated with idle_work_observer_.
-  static void StartOrEndWaitObserver(CFRunLoopObserverRef observer,
-                                     CFRunLoopActivity activity, void* info);
+  static void PreWaitObserver(CFRunLoopObserverRef observer,
+                              CFRunLoopActivity activity, void* info);
 
   // Observer callback called before the run loop processes any sources.
   // Associated with pre_source_observer_.
diff --git a/base/message_loop/message_pump_mac.mm b/base/message_loop/message_pump_mac.mm
index 0ab9ab7..914977b 100644
--- a/base/message_loop/message_pump_mac.mm
+++ b/base/message_loop/message_pump_mac.mm
@@ -8,15 +8,11 @@
 #import <Foundation/Foundation.h>
 
 #include <limits>
-#include <stack>
 
-#include "base/format_macros.h"
 #include "base/logging.h"
 #include "base/mac/scoped_cftyperef.h"
 #include "base/message_loop/timer_slack.h"
-#include "base/metrics/histogram.h"
 #include "base/run_loop.h"
-#include "base/strings/stringprintf.h"
 #include "base/time/time.h"
 
 #if !defined(OS_IOS)
@@ -123,226 +119,6 @@ class MessagePumpScopedAutoreleasePool {
   DISALLOW_COPY_AND_ASSIGN(MessagePumpScopedAutoreleasePool);
 };
 
-// This class is used to instrument the MessagePump to gather various timing
-// data about when the underlying run loop is entered, when it is waiting, and
-// when it is servicing its delegate.
-//
-// The metrics are gathered as UMA-tracked histograms. To gather the data over
-// time, sampling is used, such that a new histogram is created for each metric
-// every |sampling_interval| for |sampling_duration|. After sampling is
-// complete, this class deletes itself.
-class MessagePumpInstrumentation {
- public:
-  // Creates an instrument for the MessagePump on the current thread. Every
-  // |sampling_interval|, a new histogram will be created to track the metrics
-  // over time. After |sampling_duration|, this will delete itself, causing the
-  // WeakPtr to go NULL.
-  static WeakPtr<MessagePumpInstrumentation> Create(
-      const TimeDelta& sampling_interval,
-      const TimeDelta& sampling_duration) {
-    MessagePumpInstrumentation* instrument =
-        new MessagePumpInstrumentation(sampling_interval, sampling_duration);
-    return instrument->weak_ptr_factory_.GetWeakPtr();
-  }
-
-  // Starts the timer that runs the sampling instrumentation. Can be called
-  // multiple times as a noop.
-  void StartIfNeeded() {
-    if (timer_)
-      return;
-
-    sampling_start_time_ = generation_start_time_ = TimeTicks::Now();
-
-    CFRunLoopTimerContext timer_context = { .info = this };
-    timer_.reset(CFRunLoopTimerCreate(
-        NULL,  // allocator
-        (Time::Now() + sampling_interval_).ToCFAbsoluteTime(),
-        sampling_interval_.InSecondsF(),
-        0,  // flags
-        0,  // order
-        &MessagePumpInstrumentation::TimerFired,
-        &timer_context));
-    CFRunLoopAddTimerToAllModes(CFRunLoopGetCurrent(), timer_);
-  }
-
-  // Used to track kCFRunLoopEntry.
-  void LoopEntered() {
-    loop_run_times_.push(TimeTicks::Now());
-  }
-
-  // Used to track kCFRunLoopExit.
-  void LoopExited() {
-    TimeDelta duration = TimeTicks::Now() - loop_run_times_.top();
-    loop_run_times_.pop();
-    GetHistogram(LOOP_CYCLE)->AddTime(duration);
-  }
-
-  // Used to track kCFRunLoopBeforeWaiting.
-  void WaitingStarted() {
-    loop_wait_times_.push(TimeTicks::Now());
-  }
-
-  // Used to track kCFRunLoopAfterWaiting.
-  void WaitingFinished() {
-    TimeDelta duration = TimeTicks::Now() - loop_wait_times_.top();
-    loop_wait_times_.pop();
-    GetHistogram(LOOP_WAIT)->AddTime(duration);
-  }
-
-  // Used to track when the MessagePump will invoke its |delegate|.
-  void WorkSourceEntered(MessagePump::Delegate* delegate) {
-    work_source_times_.push(TimeTicks::Now());
-    if (delegate) {
-      size_t queue_size;
-      TimeDelta queuing_delay;
-      delegate->GetQueueingInformation(&queue_size, &queuing_delay);
-      GetHistogram(QUEUE_SIZE)->Add(queue_size);
-      GetHistogram(QUEUE_DELAY)->AddTime(queuing_delay);
-    }
-  }
-
-  // Used to track the completion of servicing the MessagePump::Delegate.
-  void WorkSourceExited() {
-    TimeDelta duration = TimeTicks::Now() - work_source_times_.top();
-    work_source_times_.pop();
-    GetHistogram(WORK_SOURCE)->AddTime(duration);
-  }
-
- private:
-  enum HistogramEvent {
-    // Time-based histograms:
-    LOOP_CYCLE,  // LoopEntered/LoopExited
-    LOOP_WAIT,  // WaitingStarted/WaitingEnded
-    WORK_SOURCE,  // WorkSourceExited
-    QUEUE_DELAY,  // WorkSourceEntered
-
-    // Value-based histograms:
-    // NOTE: Do not add value-based histograms before this event, only after.
-    QUEUE_SIZE,  // WorkSourceEntered
-
-    HISTOGRAM_EVENT_MAX,
-  };
-
-  MessagePumpInstrumentation(const TimeDelta& sampling_interval,
-                             const TimeDelta& sampling_duration)
-      : weak_ptr_factory_(this),
-        sampling_interval_(sampling_interval),
-        sampling_duration_(sampling_duration),
-        sample_generation_(0) {
-    // Create all the histogram objects that will be used for sampling.
-    const char kHistogramName[] = "MessagePumpMac.%s.SampleMs.%" PRId64;
-    for (TimeDelta i; i < sampling_duration_; i += sampling_interval_) {
-      int64 sample = i.InMilliseconds();
-
-      // Generate the time-based histograms.
-      for (int j = LOOP_CYCLE; j < QUEUE_SIZE; ++j) {
-        std::string name = StringPrintf(kHistogramName,
-            NameForEnum(static_cast<HistogramEvent>(j)), sample);
-        histograms_[j].push_back(
-            Histogram::FactoryTimeGet(name, TimeDelta::FromMilliseconds(1),
-                sampling_interval_, 50,
-                HistogramBase::kUmaTargetedHistogramFlag));
-      }
-
-      // Generate the value-based histograms.
-      for (int j = QUEUE_SIZE; j < HISTOGRAM_EVENT_MAX; ++j) {
-        std::string name = StringPrintf(kHistogramName,
-            NameForEnum(static_cast<HistogramEvent>(j)), sample);
-        histograms_[j].push_back(
-            Histogram::FactoryGet(name, 1, 10000, 50,
-                HistogramBase::kUmaTargetedHistogramFlag));
-      }
-    }
-  }
-
-  ~MessagePumpInstrumentation() {
-    if (timer_)
-      CFRunLoopTimerInvalidate(timer_);
-  }
-
-  const char* NameForEnum(HistogramEvent event) {
-    switch (event) {
-      case LOOP_CYCLE: return "LoopCycle";
-      case LOOP_WAIT: return "Waiting";
-      case WORK_SOURCE: return "WorkSource";
-      case QUEUE_DELAY: return "QueueingDelay";
-      case QUEUE_SIZE: return "QueueSize";
-      default:
-        NOTREACHED();
-        return NULL;
-    }
-  }
-
-  static void TimerFired(CFRunLoopTimerRef timer, void* context) {
-    static_cast<MessagePumpInstrumentation*>(context)->TimerFired();
-  }
-
-  // Called by the run loop when the sampling_interval_ has elapsed. Advances
-  // the sample_generation_, which controls into which histogram data is
-  // recorded, while recording and accounting for timer skew. Will delete this
-  // object after |sampling_duration_| has elapsed.
-  void TimerFired() {
-    TimeTicks now = TimeTicks::Now();
-    TimeDelta delta = now - generation_start_time_;
-
-    // The timer fired, so advance the generation by at least one.
-    ++sample_generation_;
-
-    // To account for large timer skew/drift, advance the generation by any
-    // more completed intervals.
-    for (TimeDelta skew_advance = delta - sampling_interval_;
-         skew_advance >= sampling_interval_;
-         skew_advance -= sampling_interval_) {
-      ++sample_generation_;
-    }
-
-    generation_start_time_ = now;
-    if (now >= sampling_start_time_ + sampling_duration_)
-      delete this;
-  }
-
-  HistogramBase* GetHistogram(HistogramEvent event) {
-    DCHECK_LT(sample_generation_, histograms_[event].size());
-    return histograms_[event][sample_generation_];
-  }
-
-  // Vends the pointer to the Create()or.
-  WeakPtrFactory<MessagePumpInstrumentation> weak_ptr_factory_;
-
-  // The interval and duration of the sampling.
-  TimeDelta sampling_interval_;
-  TimeDelta sampling_duration_;
-
-  // The time at which sampling started.
-  TimeTicks sampling_start_time_;
-
-  // The timer that advances the sample_generation_ and sets the
-  // generation_start_time_ for the current sample interval.
-  base::ScopedCFTypeRef<CFRunLoopTimerRef> timer_;
-
-  // The two-dimensional array of histograms. The first dimension is the
-  // HistogramEvent type. The second is for the sampling intervals.
-  std::vector<HistogramBase*> histograms_[HISTOGRAM_EVENT_MAX];
-
-  // The index in the second dimension of histograms_, which controls in which
-  // sampled histogram events are recorded.
-  size_t sample_generation_;
-
-  // The last time at which the timer fired. This is used to track timer skew
-  // (i.e. it did not fire on time) and properly account for it when advancing
-  // samle_generation_.
-  TimeTicks generation_start_time_;
-
-  // MessagePump activations can be nested. Use a stack for each of the
-  // possibly reentrant HistogramEvent types to properly balance and calculate
-  // the timing information.
-  std::stack<TimeTicks> loop_run_times_;
-  std::stack<TimeTicks> loop_wait_times_;
-  std::stack<TimeTicks> work_source_times_;
-
-  DISALLOW_COPY_AND_ASSIGN(MessagePumpInstrumentation);
-};
-
 // Must be called on the run loop thread.
 MessagePumpCFRunLoopBase::MessagePumpCFRunLoopBase()
     : delegate_(NULL),
@@ -393,11 +169,10 @@ MessagePumpCFRunLoopBase::MessagePumpCFRunLoopBase()
   CFRunLoopObserverContext observer_context = CFRunLoopObserverContext();
   observer_context.info = this;
   pre_wait_observer_ = CFRunLoopObserverCreate(NULL,  // allocator
-                                               kCFRunLoopBeforeWaiting |
-                                                  kCFRunLoopAfterWaiting,
+                                               kCFRunLoopBeforeWaiting,
                                                true,  // repeat
                                                0,     // priority
-                                               StartOrEndWaitObserver,
+                                               PreWaitObserver,
                                                &observer_context);
   CFRunLoopAddObserverToAllModes(run_loop_, pre_wait_observer_);
 
@@ -482,11 +257,6 @@ void MessagePumpCFRunLoopBase::SetDelegate(Delegate* delegate) {
   }
 }
 
-void MessagePumpCFRunLoopBase::EnableInstrumentation() {
-  instrumentation_ = MessagePumpInstrumentation::Create(
-      TimeDelta::FromSeconds(1), TimeDelta::FromSeconds(15));
-}
-
 // May be called on any thread.
 void MessagePumpCFRunLoopBase::ScheduleWork() {
   CFRunLoopSourceSignal(work_source_);
@@ -543,9 +313,6 @@ bool MessagePumpCFRunLoopBase::RunWork() {
     return false;
   }
 
-  if (instrumentation_)
-    instrumentation_->WorkSourceEntered(delegate_);
-
   // The NSApplication-based run loop only drains the autorelease pool at each
   // UI event (NSEvent).  The autorelease pool is not drained for each
   // CFRunLoopSource target that's run.  Use a local pool for any autoreleased
@@ -585,9 +352,6 @@ bool MessagePumpCFRunLoopBase::RunWork() {
     CFRunLoopSourceSignal(work_source_);
   }
 
-  if (instrumentation_)
-    instrumentation_->WorkSourceExited();
-
   return resignal_work_source;
 }
 
@@ -672,18 +436,11 @@ void MessagePumpCFRunLoopBase::MaybeScheduleNestingDeferredWork() {
 
 // Called from the run loop.
 // static
-void MessagePumpCFRunLoopBase::StartOrEndWaitObserver(
-    CFRunLoopObserverRef observer,
-    CFRunLoopActivity activity,
-    void* info) {
+void MessagePumpCFRunLoopBase::PreWaitObserver(CFRunLoopObserverRef observer,
+                                               CFRunLoopActivity activity,
+                                               void* info) {
   MessagePumpCFRunLoopBase* self = static_cast<MessagePumpCFRunLoopBase*>(info);
 
-  if (activity == kCFRunLoopAfterWaiting) {
-    if (self->instrumentation_)
-      self->instrumentation_->WaitingFinished();
-    return;
-  }
-
   // Attempt to do some idle work before going to sleep.
   self->RunIdleWork();
 
@@ -692,9 +449,6 @@ void MessagePumpCFRunLoopBase::StartOrEndWaitObserver(
   // nesting-deferred work may have accumulated.  Schedule it for processing
   // if appropriate.
   self->MaybeScheduleNestingDeferredWork();
-
-  if (self->instrumentation_)
-    self->instrumentation_->WaitingStarted();
 }
 
 // Called from the run loop.
@@ -721,9 +475,6 @@ void MessagePumpCFRunLoopBase::EnterExitObserver(CFRunLoopObserverRef observer,
 
   switch (activity) {
     case kCFRunLoopEntry:
-      if (self->instrumentation_)
-        self->instrumentation_->LoopEntered();
-
       ++self->nesting_level_;
       if (self->nesting_level_ > self->deepest_nesting_level_) {
         self->deepest_nesting_level_ = self->nesting_level_;
@@ -737,9 +488,9 @@ void MessagePumpCFRunLoopBase::EnterExitObserver(CFRunLoopObserverRef observer,
       // handling sources to exiting without any sleep.  This most commonly
       // occurs when CFRunLoopRunInMode is passed a timeout of 0, causing it
       // to make a single pass through the loop and exit without sleep.  Some
-      // native loops use CFRunLoop in this way.  Because StartOrEndWaitObserver
-      // will not be called in these case, MaybeScheduleNestingDeferredWork
-      // needs to be called here, as the run loop exits.
+      // native loops use CFRunLoop in this way.  Because PreWaitObserver will
+      // not be called in these case, MaybeScheduleNestingDeferredWork needs
+      // to be called here, as the run loop exits.
       //
       // MaybeScheduleNestingDeferredWork consults self->nesting_level_
       // to determine whether to schedule nesting-deferred work.  It expects
@@ -749,9 +500,6 @@ void MessagePumpCFRunLoopBase::EnterExitObserver(CFRunLoopObserverRef observer,
       // loop.
       self->MaybeScheduleNestingDeferredWork();
       --self->nesting_level_;
-
-      if (self->instrumentation_)
-        self->instrumentation_->LoopExited();
       break;
 
     default:
@@ -881,15 +629,11 @@ void MessagePumpUIApplication::Attach(Delegate* delegate) {
 MessagePumpNSApplication::MessagePumpNSApplication()
     : keep_running_(true),
       running_own_loop_(false) {
-  EnableInstrumentation();
 }
 
 MessagePumpNSApplication::~MessagePumpNSApplication() {}
 
 void MessagePumpNSApplication::DoRun(Delegate* delegate) {
-  if (instrumentation_)
-    instrumentation_->StartIfNeeded();
-
   bool last_running_own_loop_ = running_own_loop_;
 
   // NSApp must be initialized by calling: