diff options
author | willchan@chromium.org <willchan@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98> | 2010-06-08 20:53:41 +0000 |
---|---|---|
committer | willchan@chromium.org <willchan@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98> | 2010-06-08 20:53:41 +0000 |
commit | e81ed0577b287a1346c06fc5bbd565e429f3059e (patch) | |
tree | 23fabc108bbdea823d45de860ed48f077e2a9436 | |
parent | 5849ebff0fb2bd52d9f5667fc7dd15453c11be0a (diff) | |
download | chromium_src-e81ed0577b287a1346c06fc5bbd565e429f3059e.zip chromium_src-e81ed0577b287a1346c06fc5bbd565e429f3059e.tar.gz chromium_src-e81ed0577b287a1346c06fc5bbd565e429f3059e.tar.bz2 |
Jankometer: Generalize the code more. Add better support for monitoring IO thread.
Previously, the Jankometer only monitored windows messages on the UI thread (or gtk events).
I've added observers for tasks and IO events. This lets us monitor all events on UI & IO threads (UI messages, all Tasks, and IO events).
Replaces the JankObserver with a UIJankObserver and an IOJankObserver.
Shares common code in JankObserverHelper. The JankObserverHelper and JankWatchdog are generic enough that they can probably move out to chrome/common and be reused by the renderer.
Review URL: http://codereview.chromium.org/2098020
git-svn-id: svn://svn.chromium.org/chrome/trunk/src@49188 0039d316-1c4b-4281-b951-d872f2087c98
-rw-r--r-- | base/message_loop.cc | 20 | ||||
-rw-r--r-- | base/message_loop.h | 78 | ||||
-rw-r--r-- | base/message_loop_unittest.cc | 81 | ||||
-rw-r--r-- | base/message_pump_libevent.cc | 59 | ||||
-rw-r--r-- | base/message_pump_libevent.h | 86 | ||||
-rw-r--r-- | base/message_pump_win.cc | 20 | ||||
-rw-r--r-- | base/message_pump_win.h | 25 | ||||
-rw-r--r-- | base/tracked.h | 10 | ||||
-rw-r--r-- | chrome/browser/jankometer.cc | 285 |
9 files changed, 496 insertions, 168 deletions
diff --git a/base/message_loop.cc b/base/message_loop.cc index 7a09f38..3b13617 100644 --- a/base/message_loop.cc +++ b/base/message_loop.cc @@ -149,6 +149,16 @@ void MessageLoop::RemoveDestructionObserver(DestructionObserver *obs) { destruction_observers_.RemoveObserver(obs); } +void MessageLoop::AddTaskObserver(TaskObserver *obs) { + DCHECK_EQ(this, current()); + task_observers_.AddObserver(obs); +} + +void MessageLoop::RemoveTaskObserver(TaskObserver *obs) { + DCHECK_EQ(this, current()); + task_observers_.RemoveObserver(obs); +} + void MessageLoop::Run() { AutoRunState save_state(this); RunHandler(); @@ -325,7 +335,10 @@ void MessageLoop::RunTask(Task* task) { nestable_tasks_allowed_ = false; HistogramEvent(kTaskRunEvent); + FOR_EACH_OBSERVER(TaskObserver, task_observers_, + WillProcessTask(task->tracked_birth_time())); task->Run(); + FOR_EACH_OBSERVER(TaskObserver, task_observers_, DidProcessTask()); delete task; nestable_tasks_allowed_ = true; @@ -584,16 +597,9 @@ const LinearHistogram::DescriptionPair MessageLoop::event_descriptions_[] = { // MessageLoopForUI #if defined(OS_WIN) -void MessageLoopForUI::WillProcessMessage(const MSG& message) { - pump_win()->WillProcessMessage(message); -} void MessageLoopForUI::DidProcessMessage(const MSG& message) { pump_win()->DidProcessMessage(message); } -void MessageLoopForUI::PumpOutPendingPaintMessages() { - pump_ui()->PumpOutPendingPaintMessages(); -} - #endif // defined(OS_WIN) #if !defined(OS_MACOSX) diff --git a/base/message_loop.h b/base/message_loop.h index 1a04323..8b4be7c 100644 --- a/base/message_loop.h +++ b/base/message_loop.h @@ -8,6 +8,7 @@ #include <queue> #include <string> +#include "base/basictypes.h" #include "base/histogram.h" #include "base/message_pump.h" #include "base/observer_list.h" @@ -58,6 +59,24 @@ // class MessageLoop : public base::MessagePump::Delegate { public: + // A TaskObserver is an object that receives task notifications from the + // MessageLoop. + // + // NOTE: A TaskObserver implementation should be extremely fast! + class TaskObserver { + public: + TaskObserver() {} + + // This method is called before processing a task. + virtual void WillProcessTask(base::TimeTicks birth_time) = 0; + + // This method is called after processing a task. + virtual void DidProcessTask() = 0; + + protected: + virtual ~TaskObserver() {} + }; + static void EnableHistogrammer(bool enable_histogrammer); // A DestructionObserver is notified when the current MessageLoop is being @@ -255,9 +274,14 @@ class MessageLoop : public base::MessagePump::Delegate { // Returns true if we are currently running a nested message loop. bool IsNested(); + // These functions can only be called on the same thread that |this| is + // running on. + void AddTaskObserver(TaskObserver* task_observer); + void RemoveTaskObserver(TaskObserver* task_observer); + #if defined(OS_WIN) typedef base::MessagePumpWin::Dispatcher Dispatcher; - typedef base::MessagePumpWin::Observer Observer; + typedef base::MessagePumpForUI::Observer Observer; #elif !defined(OS_MACOSX) typedef base::MessagePumpForUI::Dispatcher Dispatcher; typedef base::MessagePumpForUI::Observer Observer; @@ -433,6 +457,8 @@ class MessageLoop : public base::MessagePump::Delegate { // The next sequence number to use for delayed tasks. int next_sequence_num_; + ObserverList<TaskObserver> task_observers_; + DISALLOW_COPY_AND_ASSIGN(MessageLoop); }; @@ -456,10 +482,8 @@ class MessageLoopForUI : public MessageLoop { } #if defined(OS_WIN) - void WillProcessMessage(const MSG& message); void DidProcessMessage(const MSG& message); - void PumpOutPendingPaintMessages(); -#endif +#endif // defined(OS_WIN) #if !defined(OS_MACOSX) // Please see message_pump_win/message_pump_glib for definitions of these @@ -473,7 +497,7 @@ class MessageLoopForUI : public MessageLoop { base::MessagePumpForUI* pump_ui() { return static_cast<base::MessagePumpForUI*>(pump_.get()); } -#endif // defined(OS_MACOSX) +#endif // !defined(OS_MACOSX) }; // Do not add any member variables to MessageLoopForUI! This is important b/c @@ -491,6 +515,24 @@ COMPILE_ASSERT(sizeof(MessageLoop) == sizeof(MessageLoopForUI), // class MessageLoopForIO : public MessageLoop { public: +#if defined(OS_WIN) + typedef base::MessagePumpForIO::IOHandler IOHandler; + typedef base::MessagePumpForIO::IOContext IOContext; + typedef base::MessagePumpForIO::IOObserver IOObserver; +#elif defined(OS_POSIX) + typedef base::MessagePumpLibevent::Watcher Watcher; + typedef base::MessagePumpLibevent::FileDescriptorWatcher + FileDescriptorWatcher; + typedef base::MessagePumpLibevent::IOObserver IOObserver; + + enum Mode { + WATCH_READ = base::MessagePumpLibevent::WATCH_READ, + WATCH_WRITE = base::MessagePumpLibevent::WATCH_WRITE, + WATCH_READ_WRITE = base::MessagePumpLibevent::WATCH_READ_WRITE + }; + +#endif + MessageLoopForIO() : MessageLoop(TYPE_IO) { } @@ -501,10 +543,15 @@ class MessageLoopForIO : public MessageLoop { return static_cast<MessageLoopForIO*>(loop); } -#if defined(OS_WIN) - typedef base::MessagePumpForIO::IOHandler IOHandler; - typedef base::MessagePumpForIO::IOContext IOContext; + void AddIOObserver(IOObserver* io_observer) { + pump_io()->AddIOObserver(io_observer); + } + + void RemoveIOObserver(IOObserver* io_observer) { + pump_io()->RemoveIOObserver(io_observer); + } +#if defined(OS_WIN) // Please see MessagePumpWin for definitions of these methods. void RegisterIOHandler(HANDLE file_handle, IOHandler* handler); bool WaitForIOCompletion(DWORD timeout, IOHandler* filter); @@ -516,22 +563,17 @@ class MessageLoopForIO : public MessageLoop { } #elif defined(OS_POSIX) - typedef base::MessagePumpLibevent::Watcher Watcher; - typedef base::MessagePumpLibevent::FileDescriptorWatcher - FileDescriptorWatcher; - - enum Mode { - WATCH_READ = base::MessagePumpLibevent::WATCH_READ, - WATCH_WRITE = base::MessagePumpLibevent::WATCH_WRITE, - WATCH_READ_WRITE = base::MessagePumpLibevent::WATCH_READ_WRITE - }; - // Please see MessagePumpLibevent for definition. bool WatchFileDescriptor(int fd, bool persistent, Mode mode, FileDescriptorWatcher *controller, Watcher *delegate); + + private: + base::MessagePumpLibevent* pump_io() { + return static_cast<base::MessagePumpLibevent*>(pump_.get()); + } #endif // defined(OS_POSIX) }; diff --git a/base/message_loop_unittest.cc b/base/message_loop_unittest.cc index 44d545f..0fa35f3 100644 --- a/base/message_loop_unittest.cc +++ b/base/message_loop_unittest.cc @@ -2,10 +2,12 @@ // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. +#include "base/eintr_wrapper.h" #include "base/logging.h" #include "base/message_loop.h" #include "base/platform_thread.h" #include "base/ref_counted.h" +#include "base/task.h" #include "base/thread.h" #include "testing/gtest/include/gtest/gtest.h" @@ -1455,6 +1457,70 @@ TEST(MessageLoopTest, NonNestableDelayedInNestedLoop) { RunTest_NonNestableInNestedLoop(MessageLoop::TYPE_IO, true); } +class DummyTask : public Task { + public: + DummyTask(int num_tasks) : num_tasks_(num_tasks) {} + + virtual void Run() { + if (num_tasks_ > 1) { + MessageLoop::current()->PostTask( + FROM_HERE, + new DummyTask(num_tasks_ - 1)); + } else { + MessageLoop::current()->Quit(); + } + } + + private: + const int num_tasks_; +}; + +class DummyTaskObserver : public MessageLoop::TaskObserver { + public: + DummyTaskObserver(int num_tasks) + : num_tasks_started_(0), + num_tasks_processed_(0), + num_tasks_(num_tasks) {} + + virtual ~DummyTaskObserver() {} + + virtual void WillProcessTask(base::TimeTicks /* birth_time */) { + num_tasks_started_++; + EXPECT_LE(num_tasks_started_, num_tasks_); + EXPECT_EQ(num_tasks_started_, num_tasks_processed_ + 1); + } + + virtual void DidProcessTask() { + num_tasks_processed_++; + EXPECT_LE(num_tasks_started_, num_tasks_); + EXPECT_EQ(num_tasks_started_, num_tasks_processed_); + } + + int num_tasks_started() const { return num_tasks_started_; } + int num_tasks_processed() const { return num_tasks_processed_; } + + private: + int num_tasks_started_; + int num_tasks_processed_; + const int num_tasks_; + + DISALLOW_COPY_AND_ASSIGN(DummyTaskObserver); +}; + +TEST(MessageLoopTest, TaskObserver) { + const int kNumTasks = 6; + DummyTaskObserver observer(kNumTasks); + + MessageLoop loop; + loop.AddTaskObserver(&observer); + loop.PostTask(FROM_HERE, new DummyTask(kNumTasks)); + loop.Run(); + loop.RemoveTaskObserver(&observer); + + EXPECT_EQ(kNumTasks, observer.num_tasks_started()); + EXPECT_EQ(kNumTasks, observer.num_tasks_processed()); +} + #if defined(OS_WIN) TEST(MessageLoopTest, Dispatcher) { // This test requires a UI loop @@ -1479,8 +1545,7 @@ TEST(MessageLoopTest, WaitForIO) { namespace { -class QuitDelegate : public - base::MessagePumpLibevent::Watcher { +class QuitDelegate : public base::MessagePumpLibevent::Watcher { public: virtual void OnFileCanWriteWithoutBlocking(int fd) { MessageLoop::current()->Quit(); @@ -1490,8 +1555,6 @@ class QuitDelegate : public } }; -} // namespace - TEST(MessageLoopTest, FileDescriptorWatcherOutlivesMessageLoop) { // Simulate a MessageLoop that dies before an FileDescriptorWatcher. // This could happen when people use the Singleton pattern or atexit. @@ -1517,8 +1580,8 @@ TEST(MessageLoopTest, FileDescriptorWatcherOutlivesMessageLoop) { // and don't run the message loop, just destroy it. } } - close(pipefds[0]); - close(pipefds[1]); + HANDLE_EINTR(close(pipefds[0])); + HANDLE_EINTR(close(pipefds[1])); } TEST(MessageLoopTest, FileDescriptorWatcherDoubleStop) { @@ -1540,8 +1603,10 @@ TEST(MessageLoopTest, FileDescriptorWatcherDoubleStop) { controller.StopWatchingFileDescriptor(); } } - close(pipefds[0]); - close(pipefds[1]); + HANDLE_EINTR(close(pipefds[0])); + HANDLE_EINTR(close(pipefds[1])); } +} // namespace + #endif // defined(OS_POSIX) diff --git a/base/message_pump_libevent.cc b/base/message_pump_libevent.cc index 2ad1d97..c2390b4 100644 --- a/base/message_pump_libevent.cc +++ b/base/message_pump_libevent.cc @@ -7,9 +7,10 @@ #include <errno.h> #include <fcntl.h> -#include "eintr_wrapper.h" #include "base/auto_reset.h" +#include "base/eintr_wrapper.h" #include "base/logging.h" +#include "base/observer_list.h" #include "base/scoped_nsautorelease_pool.h" #include "base/scoped_ptr.h" #include "base/time.h" @@ -50,7 +51,9 @@ static int SetNonBlocking(int fd) { MessagePumpLibevent::FileDescriptorWatcher::FileDescriptorWatcher() : is_persistent_(false), - event_(NULL) { + event_(NULL), + pump_(NULL), + watcher_(NULL) { } MessagePumpLibevent::FileDescriptorWatcher::~FileDescriptorWatcher() { @@ -82,9 +85,25 @@ bool MessagePumpLibevent::FileDescriptorWatcher::StopWatchingFileDescriptor() { // event_del() is a no-op if the event isn't active. int rv = event_del(e); delete e; + pump_ = NULL; + watcher_ = NULL; return (rv == 0); } +void MessagePumpLibevent::FileDescriptorWatcher::OnFileCanReadWithoutBlocking( + int fd, MessagePumpLibevent* pump) { + pump->WillProcessIOEvent(); + watcher_->OnFileCanReadWithoutBlocking(fd); + pump->DidProcessIOEvent(); +} + +void MessagePumpLibevent::FileDescriptorWatcher::OnFileCanWriteWithoutBlocking( + int fd, MessagePumpLibevent* pump) { + pump->WillProcessIOEvent(); + watcher_->OnFileCanWriteWithoutBlocking(fd); + pump->DidProcessIOEvent(); +} + // Called if a byte is received on the wakeup pipe. void MessagePumpLibevent::OnWakeup(int socket, short flags, void* context) { base::MessagePumpLibevent* that = @@ -142,9 +161,9 @@ MessagePumpLibevent::~MessagePumpLibevent() { event_del(wakeup_event_); delete wakeup_event_; if (wakeup_pipe_in_ >= 0) - close(wakeup_pipe_in_); + HANDLE_EINTR(close(wakeup_pipe_in_)); if (wakeup_pipe_out_ >= 0) - close(wakeup_pipe_out_); + HANDLE_EINTR(close(wakeup_pipe_out_)); event_base_free(event_base_); } @@ -190,7 +209,7 @@ bool MessagePumpLibevent::WatchFileDescriptor(int fd, } // Set current interest mask and message pump for this event. - event_set(evt.get(), fd, event_mask, OnLibeventNotification, delegate); + event_set(evt.get(), fd, event_mask, OnLibeventNotification, controller); // Tell libevent which message pump this socket will belong to when we add it. if (event_base_set(event_base_, evt.get()) != 0) { @@ -204,19 +223,25 @@ bool MessagePumpLibevent::WatchFileDescriptor(int fd, // Transfer ownership of evt to controller. controller->Init(evt.release(), persistent); + + controller->set_watcher(delegate); + controller->set_pump(this); + return true; } - void MessagePumpLibevent::OnLibeventNotification(int fd, short flags, void* context) { - Watcher* watcher = static_cast<Watcher*>(context); + FileDescriptorWatcher* controller = + static_cast<FileDescriptorWatcher*>(context); + + MessagePumpLibevent* pump = controller->pump(); if (flags & EV_WRITE) { - watcher->OnFileCanWriteWithoutBlocking(fd); + controller->OnFileCanWriteWithoutBlocking(fd, pump); } if (flags & EV_READ) { - watcher->OnFileCanReadWithoutBlocking(fd); + controller->OnFileCanReadWithoutBlocking(fd, pump); } } @@ -304,4 +329,20 @@ void MessagePumpLibevent::ScheduleDelayedWork(const Time& delayed_work_time) { delayed_work_time_ = delayed_work_time; } +void MessagePumpLibevent::AddIOObserver(IOObserver *obs) { + io_observers_.AddObserver(obs); +} + +void MessagePumpLibevent::RemoveIOObserver(IOObserver *obs) { + io_observers_.RemoveObserver(obs); +} + +void MessagePumpLibevent::WillProcessIOEvent() { + FOR_EACH_OBSERVER(IOObserver, io_observers_, WillProcessIOEvent()); +} + +void MessagePumpLibevent::DidProcessIOEvent() { + FOR_EACH_OBSERVER(IOObserver, io_observers_, DidProcessIOEvent()); +} + } // namespace base diff --git a/base/message_pump_libevent.h b/base/message_pump_libevent.h index 8e2f77c..6516128 100644 --- a/base/message_pump_libevent.h +++ b/base/message_pump_libevent.h @@ -5,7 +5,9 @@ #ifndef BASE_MESSAGE_PUMP_LIBEVENT_H_ #define BASE_MESSAGE_PUMP_LIBEVENT_H_ +#include "base/basictypes.h" #include "base/message_pump.h" +#include "base/observer_list.h" #include "base/time.h" // Declare structs we need from libevent.h rather than including it @@ -18,33 +20,19 @@ namespace base { // TODO(dkegel): add support for background file IO somehow class MessagePumpLibevent : public MessagePump { public: + class IOObserver { + public: + IOObserver() {} - // Object returned by WatchFileDescriptor to manage further watching. - class FileDescriptorWatcher { - public: - FileDescriptorWatcher(); - ~FileDescriptorWatcher(); // Implicitly calls StopWatchingFileDescriptor. - - // NOTE: These methods aren't called StartWatching()/StopWatching() to - // avoid confusion with the win32 ObjectWatcher class. - - // Stop watching the FD, always safe to call. No-op if there's nothing - // to do. - bool StopWatchingFileDescriptor(); - - private: - // Called by MessagePumpLibevent, ownership of |e| is transferred to this - // object. - void Init(event* e, bool is_persistent); - - // Used by MessagePumpLibevent to take ownership of event_. - event *ReleaseEvent(); - friend class MessagePumpLibevent; - - private: - bool is_persistent_; // false if this event is one-shot. - event* event_; - DISALLOW_COPY_AND_ASSIGN(FileDescriptorWatcher); + // An IOObserver is an object that receives IO notifications from the + // MessagePump. + // + // NOTE: An IOObserver implementation should be extremely fast! + virtual void WillProcessIOEvent() = 0; + virtual void DidProcessIOEvent() = 0; + + protected: + virtual ~IOObserver() {} }; // Used with WatchFileDescptor to asynchronously monitor the I/O readiness of @@ -58,6 +46,45 @@ class MessagePumpLibevent : public MessagePump { virtual void OnFileCanWriteWithoutBlocking(int fd) = 0; }; + // Object returned by WatchFileDescriptor to manage further watching. + class FileDescriptorWatcher { + public: + FileDescriptorWatcher(); + ~FileDescriptorWatcher(); // Implicitly calls StopWatchingFileDescriptor. + + // NOTE: These methods aren't called StartWatching()/StopWatching() to + // avoid confusion with the win32 ObjectWatcher class. + + // Stop watching the FD, always safe to call. No-op if there's nothing + // to do. + bool StopWatchingFileDescriptor(); + + private: + friend class MessagePumpLibevent; + + // Called by MessagePumpLibevent, ownership of |e| is transferred to this + // object. + void Init(event* e, bool is_persistent); + + // Used by MessagePumpLibevent to take ownership of event_. + event *ReleaseEvent(); + + void set_pump(MessagePumpLibevent* pump) { pump_ = pump; } + MessagePumpLibevent* pump() { return pump_; } + + void set_watcher(Watcher* watcher) { watcher_ = watcher; } + + void OnFileCanReadWithoutBlocking(int fd, MessagePumpLibevent* pump); + void OnFileCanWriteWithoutBlocking(int fd, MessagePumpLibevent* pump); + + bool is_persistent_; // false if this event is one-shot. + event* event_; + MessagePumpLibevent* pump_; + Watcher* watcher_; + + DISALLOW_COPY_AND_ASSIGN(FileDescriptorWatcher); + }; + MessagePumpLibevent(); virtual ~MessagePumpLibevent(); @@ -84,6 +111,9 @@ class MessagePumpLibevent : public MessagePump { FileDescriptorWatcher *controller, Watcher *delegate); + void AddIOObserver(IOObserver* obs); + void RemoveIOObserver(IOObserver* obs); + // MessagePump methods: virtual void Run(Delegate* delegate); virtual void Quit(); @@ -91,6 +121,8 @@ class MessagePumpLibevent : public MessagePump { virtual void ScheduleDelayedWork(const Time& delayed_work_time); private: + void WillProcessIOEvent(); + void DidProcessIOEvent(); // Risky part of constructor. Returns true on success. bool Init(); @@ -122,6 +154,8 @@ class MessagePumpLibevent : public MessagePump { // ... libevent wrapper for read end event* wakeup_event_; + ObserverList<IOObserver> io_observers_; + DISALLOW_COPY_AND_ASSIGN(MessagePumpLibevent); }; diff --git a/base/message_pump_win.cc b/base/message_pump_win.cc index 1bb6cfa..6fa3e7d 100644 --- a/base/message_pump_win.cc +++ b/base/message_pump_win.cc @@ -497,9 +497,11 @@ bool MessagePumpForIO::WaitForIOCompletion(DWORD timeout, IOHandler* filter) { // Save this item for later completed_io_.push_back(item); } else { - DCHECK(item.context->handler == item.handler); + DCHECK_EQ(item.context->handler, item.handler); + WillProcessIOEvent(); item.handler->OnIOCompleted(item.context, item.bytes_transfered, item.error); + DidProcessIOEvent(); } } else { // The handler must be gone by now, just cleanup the mess. @@ -551,4 +553,20 @@ bool MessagePumpForIO::MatchCompletedIOItem(IOHandler* filter, IOItem* item) { return false; } +void MessagePumpForIO::AddIOObserver(IOObserver *obs) { + io_observers_.AddObserver(obs); +} + +void MessagePumpForIO::RemoveIOObserver(IOObserver *obs) { + io_observers_.RemoveObserver(obs); +} + +void MessagePumpForIO::WillProcessIOEvent() { + FOR_EACH_OBSERVER(IOObserver, io_observers_, WillProcessIOEvent()); +} + +void MessagePumpForIO::DidProcessIOEvent() { + FOR_EACH_OBSERVER(IOObserver, io_observers_, DidProcessIOEvent()); +} + } // namespace base diff --git a/base/message_pump_win.h b/base/message_pump_win.h index e6ea233..9608187 100644 --- a/base/message_pump_win.h +++ b/base/message_pump_win.h @@ -9,6 +9,7 @@ #include <list> +#include "base/basictypes.h" #include "base/lock.h" #include "base/message_pump.h" #include "base/observer_list.h" @@ -23,7 +24,7 @@ namespace base { class MessagePumpWin : public MessagePump { public: // An Observer is an object that receives global notifications from the - // MessageLoop. + // UI MessageLoop. // // NOTE: An Observer implementation should be extremely fast! // @@ -283,6 +284,21 @@ class MessagePumpForIO : public MessagePumpWin { DWORD error) = 0; }; + // An IOObserver is an object that receives IO notifications from the + // MessagePump. + // + // NOTE: An IOObserver implementation should be extremely fast! + class IOObserver { + public: + IOObserver() {} + + virtual void WillProcessIOEvent() = 0; + virtual void DidProcessIOEvent() = 0; + + protected: + virtual ~IOObserver() {} + }; + // The extended context that should be used as the base structure on every // overlapped IO operation. |handler| must be set to the registered IOHandler // for the given file when the operation is started, and it can be set to NULL @@ -320,6 +336,9 @@ class MessagePumpForIO : public MessagePumpWin { // caller is willing to allow pausing regular task dispatching on this thread. bool WaitForIOCompletion(DWORD timeout, IOHandler* filter); + void AddIOObserver(IOObserver* obs); + void RemoveIOObserver(IOObserver* obs); + private: struct IOItem { IOHandler* handler; @@ -333,12 +352,16 @@ class MessagePumpForIO : public MessagePumpWin { bool MatchCompletedIOItem(IOHandler* filter, IOItem* item); bool GetIOItem(DWORD timeout, IOItem* item); bool ProcessInternalIOItem(const IOItem& item); + void WillProcessIOEvent(); + void DidProcessIOEvent(); // The completion port associated with this thread. ScopedHandle port_; // This list will be empty almost always. It stores IO completions that have // not been delivered yet because somebody was doing cleanup. std::list<IOItem> completed_io_; + + ObserverList<IOObserver> io_observers_; }; } // namespace base diff --git a/base/tracked.h b/base/tracked.h index b0be729..3622d1c 100644 --- a/base/tracked.h +++ b/base/tracked.h @@ -107,8 +107,14 @@ class Tracked { bool MissingBirthplace() const; +#if defined(TRACK_ALL_TASK_OBJECTS) + base::TimeTicks tracked_birth_time() const { return tracked_birth_time_; } +#else + base::TimeTicks tracked_birth_time() const { return base::TimeTicks::Now(); } +#endif // defined(TRACK_ALL_TASK_OBJECTS) + private: -#ifdef TRACK_ALL_TASK_OBJECTS +#if defined(TRACK_ALL_TASK_OBJECTS) // Pointer to instance were counts of objects with the same birth location // (on the same thread) are stored. @@ -118,7 +124,7 @@ class Tracked { // reset before the object begins it active life. base::TimeTicks tracked_birth_time_; -#endif // TRACK_ALL_TASK_OBJECTS +#endif // defined(TRACK_ALL_TASK_OBJECTS) DISALLOW_COPY_AND_ASSIGN(Tracked); }; diff --git a/chrome/browser/jankometer.cc b/chrome/browser/jankometer.cc index 97816ad..d4a70a2 100644 --- a/chrome/browser/jankometer.cc +++ b/chrome/browser/jankometer.cc @@ -81,80 +81,187 @@ class JankWatchdog : public Watchdog { DISALLOW_COPY_AND_ASSIGN(JankWatchdog); }; +class JankObserverHelper { + public: + JankObserverHelper(const std::string& thread_name, + const TimeDelta& excessive_duration, + bool watchdog_enable); + ~JankObserverHelper(); + + void StartProcessingTimers(const TimeDelta& queueing_time); + void EndProcessingTimers(); + + private: + const TimeDelta max_message_delay_; + + // Time at which the current message processing began. + TimeTicks begin_process_message_; + + // Time the current message spent in the queue -- delta between message + // construction time and message processing time. + TimeDelta queueing_time_; + + // Counters for the two types of jank we measure. + StatsCounter slow_processing_counter_; // Messages with long processing time. + StatsCounter queueing_delay_counter_; // Messages with long queueing delay. + scoped_refptr<Histogram> process_times_; // Time spent processing task. + scoped_refptr<Histogram> total_times_; // Total queueing plus processing. + JankWatchdog total_time_watchdog_; // Watching for excessive total_time. + + DISALLOW_COPY_AND_ASSIGN(JankObserverHelper); +}; + +JankObserverHelper::JankObserverHelper( + const std::string& thread_name, + const TimeDelta& excessive_duration, + bool watchdog_enable) + : max_message_delay_(excessive_duration), + slow_processing_counter_(std::string("Chrome.SlowMsg") + thread_name), + queueing_delay_counter_(std::string("Chrome.DelayMsg") + thread_name), + total_time_watchdog_(excessive_duration, thread_name, watchdog_enable) { + process_times_ = Histogram::FactoryGet( + std::string("Chrome.ProcMsgL ") + thread_name, + 1, 3600000, 50, Histogram::kUmaTargetedHistogramFlag); + total_times_ = Histogram::FactoryGet( + std::string("Chrome.TotalMsgL ") + thread_name, + 1, 3600000, 50, Histogram::kUmaTargetedHistogramFlag); +} + +JankObserverHelper::~JankObserverHelper() {} + +// Called when a message has just begun processing, initializes +// per-message variables and timers. +void JankObserverHelper::StartProcessingTimers(const TimeDelta& queueing_time) { + begin_process_message_ = TimeTicks::Now(); + queueing_time_ = queueing_time; + + // Simulate arming when the message entered the queue. + total_time_watchdog_.ArmSomeTimeDeltaAgo(queueing_time_); + if (queueing_time_ > max_message_delay_) { + // Message is too delayed. + queueing_delay_counter_.Increment(); +#if defined(OS_WIN) + if (kPlaySounds) + MessageBeep(MB_ICONASTERISK); +#endif + } +} + +// Called when a message has just finished processing, finalizes +// per-message variables and timers. +void JankObserverHelper::EndProcessingTimers() { + total_time_watchdog_.Disarm(); + TimeTicks now = TimeTicks::Now(); + if (begin_process_message_ != TimeTicks()) { + TimeDelta processing_time = now - begin_process_message_; + process_times_->AddTime(processing_time); + total_times_->AddTime(queueing_time_ + processing_time); + } + if (now - begin_process_message_ > + TimeDelta::FromMilliseconds(kMaxMessageProcessingMs)) { + // Message took too long to process. + slow_processing_counter_.Increment(); +#if defined(OS_WIN) + if (kPlaySounds) + MessageBeep(MB_ICONHAND); +#endif + } + + // Reset message specific times. + begin_process_message_ = base::TimeTicks(); + queueing_time_ = base::TimeDelta(); +} + //------------------------------------------------------------------------------ -class JankObserver : public base::RefCountedThreadSafe<JankObserver>, - public MessageLoopForUI::Observer { +class IOJankObserver : public base::RefCountedThreadSafe<IOJankObserver>, + public MessageLoopForIO::IOObserver, + public MessageLoop::TaskObserver { public: - JankObserver(const char* thread_name, - const TimeDelta& excessive_duration, - bool watchdog_enable) - : MaxMessageDelay_(excessive_duration), - slow_processing_counter_(std::string("Chrome.SlowMsg") + thread_name), - queueing_delay_counter_(std::string("Chrome.DelayMsg") + thread_name), - total_time_watchdog_(excessive_duration, thread_name, watchdog_enable) { - process_times_ = Histogram::FactoryGet( - std::string("Chrome.ProcMsgL ") + thread_name, - 1, 3600000, 50, Histogram::kUmaTargetedHistogramFlag); - total_times_ = Histogram::FactoryGet( - std::string("Chrome.TotalMsgL ") + thread_name, - 1, 3600000, 50, Histogram::kUmaTargetedHistogramFlag); + IOJankObserver(const char* thread_name, + TimeDelta excessive_duration, + bool watchdog_enable) + : helper_(thread_name, excessive_duration, watchdog_enable) {} + + ~IOJankObserver() {} + + // Attaches the observer to the current thread's message loop. You can only + // attach to the current thread, so this function can be invoked on another + // thread to attach it. + void AttachToCurrentThread() { + MessageLoop::current()->AddTaskObserver(this); + MessageLoopForIO::current()->AddIOObserver(this); + } + + // Detaches the observer to the current thread's message loop. + void DetachFromCurrentThread() { + MessageLoopForIO::current()->RemoveIOObserver(this); + MessageLoop::current()->RemoveTaskObserver(this); } + virtual void WillProcessIOEvent() { + helper_.StartProcessingTimers(base::TimeDelta()); + } + + virtual void DidProcessIOEvent() { + helper_.EndProcessingTimers(); + } + + virtual void WillProcessTask(base::TimeTicks birth_time) { + base::TimeTicks now = base::TimeTicks::Now(); + const base::TimeDelta queueing_time = now - birth_time; + helper_.StartProcessingTimers(queueing_time); + } + + virtual void DidProcessTask() { + helper_.EndProcessingTimers(); + } + + private: + friend class base::RefCountedThreadSafe<IOJankObserver>; + + JankObserverHelper helper_; + + DISALLOW_COPY_AND_ASSIGN(IOJankObserver); +}; + +//------------------------------------------------------------------------------ +class UIJankObserver : public base::RefCountedThreadSafe<UIJankObserver>, + public MessageLoop::TaskObserver, + public MessageLoopForUI::Observer { + public: + UIJankObserver(const char* thread_name, + TimeDelta excessive_duration, + bool watchdog_enable) + : helper_(thread_name, excessive_duration, watchdog_enable) {} + // Attaches the observer to the current thread's message loop. You can only // attach to the current thread, so this function can be invoked on another // thread to attach it. void AttachToCurrentThread() { - // TODO(darin): support monitoring jankiness on non-UI threads! - if (MessageLoop::current()->type() == MessageLoop::TYPE_UI) - MessageLoopForUI::current()->AddObserver(this); + DCHECK_EQ(MessageLoop::current()->type(), MessageLoop::TYPE_UI); + MessageLoopForUI::current()->AddObserver(this); + MessageLoop::current()->AddTaskObserver(this); } // Detaches the observer to the current thread's message loop. void DetachFromCurrentThread() { - if (MessageLoop::current()->type() == MessageLoop::TYPE_UI) - MessageLoopForUI::current()->RemoveObserver(this); + DCHECK_EQ(MessageLoop::current()->type(), MessageLoop::TYPE_UI); + MessageLoop::current()->RemoveTaskObserver(this); + MessageLoopForUI::current()->RemoveObserver(this); } - // Called when a message has just begun processing, initializes - // per-message variables and timers. - void StartProcessingTimers() { - // Simulate arming when the message entered the queue. - total_time_watchdog_.ArmSomeTimeDeltaAgo(queueing_time_); - if (queueing_time_ > MaxMessageDelay_) { - // Message is too delayed. - queueing_delay_counter_.Increment(); -#if defined(OS_WIN) - if (kPlaySounds) - MessageBeep(MB_ICONASTERISK); -#endif - } + virtual void WillProcessTask(base::TimeTicks birth_time) { + base::TimeTicks now = base::TimeTicks::Now(); + const base::TimeDelta queueing_time = now - birth_time; + helper_.StartProcessingTimers(queueing_time); } - // Called when a message has just finished processing, finalizes - // per-message variables and timers. - void EndProcessingTimers() { - total_time_watchdog_.Disarm(); - TimeTicks now = TimeTicks::Now(); - if (begin_process_message_ != TimeTicks()) { - TimeDelta processing_time = now - begin_process_message_; - process_times_->AddTime(processing_time); - total_times_->AddTime(queueing_time_ + processing_time); - } - if (now - begin_process_message_ > - TimeDelta::FromMilliseconds(kMaxMessageProcessingMs)) { - // Message took too long to process. - slow_processing_counter_.Increment(); -#if defined(OS_WIN) - if (kPlaySounds) - MessageBeep(MB_ICONHAND); -#endif - } + virtual void DidProcessTask() { + helper_.EndProcessingTimers(); } #if defined(OS_WIN) virtual void WillProcessMessage(const MSG& msg) { - begin_process_message_ = TimeTicks::Now(); - // GetMessageTime returns a LONG (signed 32-bit) and GetTickCount returns // a DWORD (unsigned 32-bit). They both wrap around when the time is longer // than they can hold. I'm not sure if GetMessageTime wraps around to 0, @@ -166,58 +273,43 @@ class JankObserver : public base::RefCountedThreadSafe<JankObserver>, // to straddle the wraparound point, it will still be OK. DWORD cur_message_issue_time = static_cast<DWORD>(msg.time); DWORD cur_time = GetTickCount(); - queueing_time_ = + base::TimeDelta queueing_time = base::TimeDelta::FromMilliseconds(cur_time - cur_message_issue_time); - StartProcessingTimers(); + helper_.StartProcessingTimers(queueing_time); } virtual void DidProcessMessage(const MSG& msg) { - EndProcessingTimers(); + helper_.EndProcessingTimers(); } #elif defined(TOOLKIT_USES_GTK) virtual void WillProcessEvent(GdkEvent* event) { - begin_process_message_ = TimeTicks::Now(); // TODO(evanm): we want to set queueing_time_ using // gdk_event_get_time, but how do you convert that info // into a delta? // guint event_time = gdk_event_get_time(event); - queueing_time_ = base::TimeDelta::FromMilliseconds(0); - StartProcessingTimers(); + base::TimeDelta queueing_time = base::TimeDelta::FromMilliseconds(0); + helper_.StartProcessingTimers(queueing_time); } virtual void DidProcessEvent(GdkEvent* event) { - EndProcessingTimers(); + helper_.EndProcessingTimers(); } #endif private: - friend class base::RefCountedThreadSafe<JankObserver>; - - ~JankObserver() {} - - const TimeDelta MaxMessageDelay_; - - // Time at which the current message processing began. - TimeTicks begin_process_message_; + friend class base::RefCountedThreadSafe<UIJankObserver>; - // Time the current message spent in the queue -- delta between message - // construction time and message processing time. - TimeDelta queueing_time_; + ~UIJankObserver() {} - // Counters for the two types of jank we measure. - StatsCounter slow_processing_counter_; // Messages with long processing time. - StatsCounter queueing_delay_counter_; // Messages with long queueing delay. - scoped_refptr<Histogram> process_times_; // Time spent processing task. - scoped_refptr<Histogram> total_times_; // Total queueing plus processing. - JankWatchdog total_time_watchdog_; // Watching for excessive total_time. + JankObserverHelper helper_; - DISALLOW_COPY_AND_ASSIGN(JankObserver); + DISALLOW_COPY_AND_ASSIGN(UIJankObserver); }; // These objects are created by InstallJankometer and leaked. -JankObserver* ui_observer = NULL; -JankObserver* io_observer = NULL; +const scoped_refptr<UIJankObserver>* ui_observer = NULL; +const scoped_refptr<IOJankObserver>* io_observer = NULL; } // namespace @@ -239,36 +331,37 @@ void InstallJankometer(const CommandLine& parsed_command_line) { } // Install on the UI thread. - ui_observer = new JankObserver( - "UI", - TimeDelta::FromMilliseconds(kMaxUIMessageDelayMs), - ui_watchdog_enabled); - ui_observer->AddRef(); - ui_observer->AttachToCurrentThread(); + ui_observer = new scoped_refptr<UIJankObserver>( + new UIJankObserver( + "UI", + TimeDelta::FromMilliseconds(kMaxUIMessageDelayMs), + ui_watchdog_enabled)); + (*ui_observer)->AttachToCurrentThread(); // Now install on the I/O thread. Hiccups on that thread will block // interaction with web pages. We must proxy to that thread before we can // add our observer. - io_observer = new JankObserver( - "IO", - TimeDelta::FromMilliseconds(kMaxIOMessageDelayMs), - io_watchdog_enabled); - io_observer->AddRef(); + io_observer = new scoped_refptr<IOJankObserver>( + new IOJankObserver( + "IO", + TimeDelta::FromMilliseconds(kMaxIOMessageDelayMs), + io_watchdog_enabled)); ChromeThread::PostTask( ChromeThread::IO, FROM_HERE, - NewRunnableMethod(io_observer, &JankObserver::AttachToCurrentThread)); + NewRunnableMethod(io_observer->get(), + &IOJankObserver::AttachToCurrentThread)); } void UninstallJankometer() { if (ui_observer) { - ui_observer->DetachFromCurrentThread(); - ui_observer->Release(); + (*ui_observer)->DetachFromCurrentThread(); + delete ui_observer; ui_observer = NULL; } if (io_observer) { // IO thread can't be running when we remove observers. DCHECK((!g_browser_process) || !(g_browser_process->io_thread())); - io_observer->Release(); + delete io_observer; io_observer = NULL; } } |