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

base/message_loop/message_pump_mac.mm

 // Copyright (c) 2012 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.
 
 #import "base/message_loop/message_pump_mac.h"
 
 #include <dlfcn.h>
 #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)
 #import <AppKit/AppKit.h>
 #endif  // !defined(OS_IOS)
 
 namespace base {
 
 namespace {
 
@@ skipping 86 matching lines @@
   }
    ~MessagePumpScopedAutoreleasePool() {
     [pool_ drain];
   }
 
  private:
   NSAutoreleasePool* pool_;
   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),
       delayed_work_fire_time_(kCFTimeIntervalMax),
       timer_slack_(base::TIMER_SLACK_NONE),
       nesting_level_(0),
       run_nesting_level_(0),
       deepest_nesting_level_(0),
       delegateless_work_(false),
       delegateless_idle_work_(false) {
@@ skipping 30 matching lines @@
 
   source_context.perform = RunNestingDeferredWorkSource;
   nesting_deferred_work_source_ = CFRunLoopSourceCreate(NULL,  // allocator
                                                         0,     // priority
                                                         &source_context);
   CFRunLoopAddSourceToAllModes(run_loop_, nesting_deferred_work_source_);
 
   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_);
 
   pre_source_observer_ = CFRunLoopObserverCreate(NULL,  // allocator
                                                  kCFRunLoopBeforeSources,
                                                  true,  // repeat
                                                  0,     // priority
                                                  PreSourceObserver,
                                                  &observer_context);
   CFRunLoopAddObserverToAllModes(run_loop_, pre_source_observer_);
@@ skipping 64 matching lines @@
       CFRunLoopSourceSignal(work_source_);
       delegateless_work_ = false;
     }
     if (delegateless_idle_work_) {
       CFRunLoopSourceSignal(idle_work_source_);
       delegateless_idle_work_ = false;
     }
   }
 }
 
-void MessagePumpCFRunLoopBase::EnableInstrumentation() {
-  instrumentation_ = MessagePumpInstrumentation::Create(
-      TimeDelta::FromSeconds(1), TimeDelta::FromSeconds(15));
-}
-
 // May be called on any thread.
 void MessagePumpCFRunLoopBase::ScheduleWork() {
   CFRunLoopSourceSignal(work_source_);
   CFRunLoopWakeUp(run_loop_);
 }
 
 // Must be called on the run loop thread.
 void MessagePumpCFRunLoopBase::ScheduleDelayedWork(
     const TimeTicks& delayed_work_time) {
   TimeDelta delta = delayed_work_time - TimeTicks::Now();
@@ skipping 36 matching lines @@
 // Called by MessagePumpCFRunLoopBase::RunWorkSource.
 bool MessagePumpCFRunLoopBase::RunWork() {
   if (!delegate_) {
     // This point can be reached with a NULL delegate_ if Run is not on the
     // stack but foreign code is spinning the CFRunLoop.  Arrange to come back
     // here when a delegate is available.
     delegateless_work_ = true;
     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
   // objects if the app is not currently handling a UI event to ensure they're
   // released promptly even in the absence of UI events.
   MessagePumpScopedAutoreleasePool autorelease_pool(this);
 
   // Call DoWork and DoDelayedWork once, and if something was done, arrange to
   // come back here again as long as the loop is still running.
   bool did_work = delegate_->DoWork();
@@ skipping 19 matching lines @@
         // running.
         resignal_work_source = true;
       }
     }
   }
 
   if (resignal_work_source) {
     CFRunLoopSourceSignal(work_source_);
   }
 
-  if (instrumentation_)
-    instrumentation_->WorkSourceExited();
-
   return resignal_work_source;
 }
 
 // Called from the run loop.
 // static
 void MessagePumpCFRunLoopBase::RunIdleWorkSource(void* info) {
   MessagePumpCFRunLoopBase* self = static_cast<MessagePumpCFRunLoopBase*>(info);
   self->RunIdleWork();
 }
 
@@ skipping 64 matching lines @@
   // nesting-deferred work in case any work was deferred because nested work
   // was disallowed.
   if (deepest_nesting_level_ > nesting_level_) {
     deepest_nesting_level_ = nesting_level_;
     CFRunLoopSourceSignal(nesting_deferred_work_source_);
   }
 }
 
 // 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();
 
   // The run loop is about to go to sleep.  If any of the work done since it
   // started or woke up resulted in a nested run loop running,
   // 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.
 // static
 void MessagePumpCFRunLoopBase::PreSourceObserver(CFRunLoopObserverRef observer,
                                                  CFRunLoopActivity activity,
                                                  void* info) {
   MessagePumpCFRunLoopBase* self = static_cast<MessagePumpCFRunLoopBase*>(info);
 
   // The run loop has reached the top of the loop and is about to begin
   // processing sources.  If the last iteration of the loop at this nesting
   // level did not sleep or exit, nesting-deferred work may have accumulated
   // if a nested loop ran.  Schedule nesting-deferred work for processing if
   // appropriate.
   self->MaybeScheduleNestingDeferredWork();
 }
 
 // Called from the run loop.
 // static
 void MessagePumpCFRunLoopBase::EnterExitObserver(CFRunLoopObserverRef observer,
                                                  CFRunLoopActivity activity,
                                                  void* info) {
   MessagePumpCFRunLoopBase* self = static_cast<MessagePumpCFRunLoopBase*>(info);
 
   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_;
       }
       break;
 
     case kCFRunLoopExit:
       // Not all run loops go to sleep.  If a run loop is stopped before it
       // goes to sleep due to a CFRunLoopStop call, or if the timeout passed
       // to CFRunLoopRunInMode expires, the run loop may proceed directly from
       // 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
       // the nesting level to be set to the depth of the loop that is going
       // to sleep or exiting.  It must be called before decrementing the
       // value so that the value still corresponds to the level of the exiting
       // loop.
       self->MaybeScheduleNestingDeferredWork();
       --self->nesting_level_;
-
-      if (self->instrumentation_)
-        self->instrumentation_->LoopExited();
       break;
 
     default:
       break;
   }
 
   self->EnterExitRunLoop(activity);
 }
 
 // Called by MessagePumpCFRunLoopBase::EnterExitRunLoop.  The default
@@ skipping 109 matching lines @@
   run_loop_ = new RunLoop();
   CHECK(run_loop_->BeforeRun());
   SetDelegate(delegate);
 }
 
 #else
 
 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:
   // [{some class which implements CrAppProtocol} sharedApplication]
   // Most likely candidates are CrApplication or BrowserCrApplication.
   // These can be initialized from C++ code by calling
   // RegisterCrApp() or RegisterBrowserCrApp().
   CHECK(NSApp);
 
   if (![NSApp isRunning]) {
@@ skipping 121 matching lines @@
     [NSApplication sharedApplication];
     g_not_using_cr_app = true;
     return new MessagePumpNSApplication;
 #endif
   }
 
   return new MessagePumpNSRunLoop;
 }
 
 }  // namespace base