diff options
author | wangxianzhu@chromium.org <wangxianzhu@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98> | 2013-12-03 17:31:35 +0000 |
---|---|---|
committer | wangxianzhu@chromium.org <wangxianzhu@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98> | 2013-12-03 17:31:35 +0000 |
commit | cece099151206e8e1c4d1166dad86c71d3092f1e (patch) | |
tree | c7017f288471d6c0836d7042d1a0046cfdd0859d | |
parent | 02c6ab4dd16ffd395b67f76baac4a2e3ecaa5b52 (diff) | |
download | chromium_src-cece099151206e8e1c4d1166dad86c71d3092f1e.zip chromium_src-cece099151206e8e1c4d1166dad86c71d3092f1e.tar.gz chromium_src-cece099151206e8e1c4d1166dad86c71d3092f1e.tar.bz2 |
Revert of https://codereview.chromium.org/99103004/
Reason for revert: Bug 323749 still unresolved
TBR=
NOTREECHECKS=true
NOTRY=true
Review URL: https://codereview.chromium.org/101543004
git-svn-id: svn://svn.chromium.org/chrome/trunk/src@238424 0039d316-1c4b-4281-b951-d872f2087c98
36 files changed, 1638 insertions, 547 deletions
diff --git a/base/debug/trace_event_impl.cc b/base/debug/trace_event_impl.cc index aebaf10..8375f37 100644 --- a/base/debug/trace_event_impl.cc +++ b/base/debug/trace_event_impl.cc @@ -99,6 +99,11 @@ int g_category_index = g_num_builtin_categories; // Skip default categories. LazyInstance<ThreadLocalPointer<const char> >::Leaky g_current_thread_name = LAZY_INSTANCE_INITIALIZER; +const char kRecordUntilFull[] = "record-until-full"; +const char kRecordContinuously[] = "record-continuously"; +const char kEnableSampling[] = "enable-sampling"; +const char kMonitorSampling[] = "monitor-sampling"; + TimeTicks ThreadNow() { return TimeTicks::IsThreadNowSupported() ? TimeTicks::ThreadNow() : TimeTicks(); @@ -946,10 +951,12 @@ class TraceLog::ThreadLocalEventBuffer ThreadLocalEventBuffer(TraceLog* trace_log); virtual ~ThreadLocalEventBuffer(); - TraceEvent* AddTraceEvent(TraceEventHandle* handle); + TraceEvent* AddTraceEvent(NotificationHelper* notifier, + TraceEventHandle* handle); void ReportOverhead(const TimeTicks& event_timestamp, - const TimeTicks& event_thread_timestamp); + const TimeTicks& event_thread_timestamp, + NotificationHelper* notifier); TraceEvent* GetEventByHandle(TraceEventHandle handle) { if (!chunk_ || handle.chunk_seq != chunk_->seq() || @@ -1006,10 +1013,12 @@ TraceLog::ThreadLocalEventBuffer::~ThreadLocalEventBuffer() { // - the thread has no message loop; // - trace_event_overhead is disabled. if (event_count_) { - InitializeMetadataEvent(AddTraceEvent(NULL), + NotificationHelper notifier(trace_log_); + InitializeMetadataEvent(AddTraceEvent(¬ifier, NULL), static_cast<int>(base::PlatformThread::CurrentId()), "overhead", "average_overhead", overhead_.InMillisecondsF() / event_count_); + notifier.SendNotificationIfAny(); } { @@ -1021,6 +1030,7 @@ TraceLog::ThreadLocalEventBuffer::~ThreadLocalEventBuffer() { } TraceEvent* TraceLog::ThreadLocalEventBuffer::AddTraceEvent( + NotificationHelper* notifier, TraceEventHandle* handle) { CheckThisIsCurrentBuffer(); @@ -1032,7 +1042,7 @@ TraceEvent* TraceLog::ThreadLocalEventBuffer::AddTraceEvent( if (!chunk_) { AutoLock lock(trace_log_->lock_); chunk_ = trace_log_->logged_events_->GetChunk(&chunk_index_); - trace_log_->CheckIfBufferIsFullWhileLocked(); + trace_log_->CheckIfBufferIsFullWhileLocked(notifier); } if (!chunk_) return NULL; @@ -1047,7 +1057,8 @@ TraceEvent* TraceLog::ThreadLocalEventBuffer::AddTraceEvent( void TraceLog::ThreadLocalEventBuffer::ReportOverhead( const TimeTicks& event_timestamp, - const TimeTicks& event_thread_timestamp) { + const TimeTicks& event_thread_timestamp, + NotificationHelper* notifier) { if (!g_category_group_enabled[g_category_trace_event_overhead]) return; @@ -1058,7 +1069,7 @@ void TraceLog::ThreadLocalEventBuffer::ReportOverhead( TimeTicks now = trace_log_->OffsetNow(); TimeDelta overhead = now - event_timestamp; if (overhead.InMicroseconds() >= kOverheadReportThresholdInMicroseconds) { - TraceEvent* trace_event = AddTraceEvent(NULL); + TraceEvent* trace_event = AddTraceEvent(notifier, NULL); if (trace_event) { trace_event->Initialize( static_cast<int>(PlatformThread::CurrentId()), @@ -1089,14 +1100,66 @@ void TraceLog::ThreadLocalEventBuffer::FlushWhileLocked() { // find the generation mismatch and delete this buffer soon. } +TraceLog::NotificationHelper::NotificationHelper(TraceLog* trace_log) + : trace_log_(trace_log), + notification_(0) { +} + +TraceLog::NotificationHelper::~NotificationHelper() { +} + +void TraceLog::NotificationHelper::AddNotificationWhileLocked( + int notification) { + trace_log_->lock_.AssertAcquired(); + if (trace_log_->notification_callback_.is_null()) + return; + if (notification_ == 0) + callback_copy_ = trace_log_->notification_callback_; + notification_ |= notification; +} + +void TraceLog::NotificationHelper::SendNotificationIfAny() { + if (notification_) + callback_copy_.Run(notification_); +} + // static TraceLog* TraceLog::GetInstance() { return Singleton<TraceLog, LeakySingletonTraits<TraceLog> >::get(); } +// static +// Note, if you add more options here you also need to update: +// content/browser/devtools/devtools_tracing_handler:TraceOptionsFromString +TraceLog::Options TraceLog::TraceOptionsFromString(const std::string& options) { + std::vector<std::string> split; + base::SplitString(options, ',', &split); + int ret = 0; + for (std::vector<std::string>::iterator iter = split.begin(); + iter != split.end(); + ++iter) { + if (*iter == kRecordUntilFull) { + ret |= RECORD_UNTIL_FULL; + } else if (*iter == kRecordContinuously) { + ret |= RECORD_CONTINUOUSLY; + } else if (*iter == kEnableSampling) { + ret |= ENABLE_SAMPLING; + } else if (*iter == kMonitorSampling) { + ret |= MONITOR_SAMPLING; + } else { + NOTREACHED(); // Unknown option provided. + } + } + if (!(ret & RECORD_UNTIL_FULL) && !(ret & RECORD_CONTINUOUSLY)) + ret |= RECORD_UNTIL_FULL; // Default when no options are specified. + + return static_cast<Options>(ret); +} + TraceLog::TraceLog() : enabled_(false), num_traces_recorded_(0), + buffer_is_full_(0), event_callback_(0), dispatching_to_observer_list_(false), process_sort_index_(0), @@ -1273,6 +1336,7 @@ void TraceLog::SetEnabled(const CategoryFilter& category_filter, subtle::NoBarrier_Store(&trace_options_, options); logged_events_.reset(CreateTraceBuffer()); NextGeneration(); + subtle::NoBarrier_Store(&buffer_is_full_, 0); } num_traces_recorded_++; @@ -1319,52 +1383,49 @@ CategoryFilter TraceLog::GetCurrentCategoryFilter() { } void TraceLog::SetDisabled() { - AutoLock lock(lock_); - SetDisabledWhileLocked(); -} + std::vector<EnabledStateObserver*> observer_list; + { + AutoLock lock(lock_); + if (!enabled_) + return; -void TraceLog::SetDisabledWhileLocked() { - lock_.AssertAcquired(); + if (dispatching_to_observer_list_) { + DLOG(ERROR) + << "Cannot manipulate TraceLog::Enabled state from an observer."; + return; + } - if (!enabled_) - return; + enabled_ = false; - if (dispatching_to_observer_list_) { - DLOG(ERROR) - << "Cannot manipulate TraceLog::Enabled state from an observer."; - return; - } + if (sampling_thread_.get()) { + // Stop the sampling thread. + sampling_thread_->Stop(); + lock_.Release(); + PlatformThread::Join(sampling_thread_handle_); + lock_.Acquire(); + sampling_thread_handle_ = PlatformThreadHandle(); + sampling_thread_.reset(); + } - enabled_ = false; + category_filter_.Clear(); + subtle::NoBarrier_Store(&watch_category_, 0); + watch_event_name_ = ""; + UpdateCategoryGroupEnabledFlags(); + AddMetadataEventsWhileLocked(); - if (sampling_thread_.get()) { - // Stop the sampling thread. - sampling_thread_->Stop(); - lock_.Release(); - PlatformThread::Join(sampling_thread_handle_); - lock_.Acquire(); - sampling_thread_handle_ = PlatformThreadHandle(); - sampling_thread_.reset(); + dispatching_to_observer_list_ = true; + observer_list = enabled_state_observer_list_; } - category_filter_.Clear(); - subtle::NoBarrier_Store(&watch_category_, 0); - watch_event_name_ = ""; - UpdateCategoryGroupEnabledFlags(); - AddMetadataEventsWhileLocked(); - - dispatching_to_observer_list_ = true; - std::vector<EnabledStateObserver*> observer_list = - enabled_state_observer_list_; + // Dispatch to observers outside the lock in case the observer triggers a + // trace event. + for (size_t i = 0; i < observer_list.size(); ++i) + observer_list[i]->OnTraceLogDisabled(); { - // Dispatch to observers outside the lock in case the observer triggers a - // trace event. - AutoUnlock unlock(lock_); - for (size_t i = 0; i < observer_list.size(); ++i) - observer_list[i]->OnTraceLogDisabled(); + AutoLock lock(lock_); + dispatching_to_observer_list_ = false; } - dispatching_to_observer_list_ = false; } int TraceLog::GetNumTracesRecorded() { @@ -1396,14 +1457,14 @@ bool TraceLog::HasEnabledStateObserver(EnabledStateObserver* listener) const { } float TraceLog::GetBufferPercentFull() const { - AutoLock lock(lock_); return static_cast<float>(static_cast<double>(logged_events_->Size()) / logged_events_->Capacity()); } -bool TraceLog::BufferIsFull() const { +void TraceLog::SetNotificationCallback( + const TraceLog::NotificationCallback& cb) { AutoLock lock(lock_); - return logged_events_->IsFull(); + notification_callback_ = cb; } TraceBuffer* TraceLog::CreateTraceBuffer() { @@ -1418,7 +1479,7 @@ TraceBuffer* TraceLog::CreateTraceBuffer() { } TraceEvent* TraceLog::AddEventToThreadSharedChunkWhileLocked( - TraceEventHandle* handle, bool check_buffer_is_full) { + NotificationHelper* notifier, TraceEventHandle* handle) { lock_.AssertAcquired(); if (thread_shared_chunk_ && thread_shared_chunk_->IsFull()) { @@ -1429,8 +1490,8 @@ TraceEvent* TraceLog::AddEventToThreadSharedChunkWhileLocked( if (!thread_shared_chunk_) { thread_shared_chunk_ = logged_events_->GetChunk( &thread_shared_chunk_index_); - if (check_buffer_is_full) - CheckIfBufferIsFullWhileLocked(); + if (notifier) + CheckIfBufferIsFullWhileLocked(notifier); } if (!thread_shared_chunk_) return NULL; @@ -1444,10 +1505,13 @@ TraceEvent* TraceLog::AddEventToThreadSharedChunkWhileLocked( return trace_event; } -void TraceLog::CheckIfBufferIsFullWhileLocked() { +void TraceLog::CheckIfBufferIsFullWhileLocked(NotificationHelper* notifier) { lock_.AssertAcquired(); - if (logged_events_->IsFull()) - SetDisabledWhileLocked(); + if (!subtle::NoBarrier_Load(&buffer_is_full_) && logged_events_->IsFull()) { + subtle::NoBarrier_Store(&buffer_is_full_, + static_cast<subtle::AtomicWord>(1)); + notifier->AddNotificationWhileLocked(TRACE_BUFFER_FULL); + } } void TraceLog::SetEventCallbackEnabled(const CategoryFilter& category_filter, @@ -1564,6 +1628,7 @@ void TraceLog::FinishFlush(int generation) { previous_logged_events.swap(logged_events_); logged_events_.reset(CreateTraceBuffer()); NextGeneration(); + subtle::NoBarrier_Store(&buffer_is_full_, 0); thread_message_loops_.clear(); flush_message_loop_proxy_ = NULL; @@ -1683,6 +1748,8 @@ TraceEventHandle TraceLog::AddTraceEventWithThreadIdAndTimestamp( TimeTicks now = OffsetTimestamp(timestamp); TimeTicks thread_now = ThreadNow(); + NotificationHelper notifier(this); + ThreadLocalEventBuffer* thread_local_event_buffer = NULL; // A ThreadLocalEventBuffer needs the message loop // - to know when the thread exits; @@ -1739,13 +1806,15 @@ TraceEventHandle TraceLog::AddTraceEventWithThreadIdAndTimestamp( } TraceEvent* trace_event = NULL; - if ((*category_group_enabled & ENABLED_FOR_RECORDING)) { + if ((*category_group_enabled & ENABLED_FOR_RECORDING) && + !subtle::NoBarrier_Load(&buffer_is_full_)) { if (thread_local_event_buffer) { lock.EnsureReleased(); - trace_event = thread_local_event_buffer->AddTraceEvent(&handle); + trace_event = thread_local_event_buffer->AddTraceEvent(¬ifier, + &handle); } else { lock.EnsureAcquired(); - trace_event = AddEventToThreadSharedChunkWhileLocked(&handle, true); + trace_event = AddEventToThreadSharedChunkWhileLocked(¬ifier, &handle); } if (trace_event) { @@ -1758,24 +1827,20 @@ TraceEventHandle TraceLog::AddTraceEventWithThreadIdAndTimestamp( trace_event->SendToATrace(); #endif } + } - if (trace_options() & ECHO_TO_CONSOLE) { - lock.EnsureAcquired(); - OutputEventToConsoleWhileLocked( - phase == TRACE_EVENT_PHASE_COMPLETE ? TRACE_EVENT_PHASE_BEGIN : phase, - timestamp, trace_event); - } + if (trace_options() & ECHO_TO_CONSOLE) { + lock.EnsureAcquired(); + OutputEventToConsoleWhileLocked( + phase == TRACE_EVENT_PHASE_COMPLETE ? TRACE_EVENT_PHASE_BEGIN : phase, + timestamp, trace_event); } if (reinterpret_cast<const unsigned char*>(subtle::NoBarrier_Load( &watch_category_)) == category_group_enabled) { lock.EnsureAcquired(); - if (watch_event_name_ == name) { - WatchEventCallback watch_event_callback_copy = watch_event_callback_; - lock.EnsureReleased(); - if (!watch_event_callback_copy.is_null()) - watch_event_callback_copy.Run(); - } + if (watch_event_name_ == name) + notifier.AddNotificationWhileLocked(EVENT_WATCH_NOTIFICATION); } lock.EnsureReleased(); @@ -1793,7 +1858,9 @@ TraceEventHandle TraceLog::AddTraceEventWithThreadIdAndTimestamp( } if (thread_local_event_buffer) - thread_local_event_buffer->ReportOverhead(now, thread_now); + thread_local_event_buffer->ReportOverhead(now, thread_now, ¬ifier); + + notifier.SendNotificationIfAny(); return handle; } @@ -1904,22 +1971,19 @@ void TraceLog::UpdateTraceEventDuration( } void TraceLog::SetWatchEvent(const std::string& category_name, - const std::string& event_name, - const WatchEventCallback& callback) { + const std::string& event_name) { const unsigned char* category = GetCategoryGroupEnabled( category_name.c_str()); AutoLock lock(lock_); subtle::NoBarrier_Store(&watch_category_, reinterpret_cast<subtle::AtomicWord>(category)); watch_event_name_ = event_name; - watch_event_callback_ = callback; } void TraceLog::CancelWatchEvent() { AutoLock lock(lock_); subtle::NoBarrier_Store(&watch_category_, 0); watch_event_name_ = ""; - watch_event_callback_.Reset(); } void TraceLog::AddMetadataEventsWhileLocked() { @@ -1927,14 +1991,14 @@ void TraceLog::AddMetadataEventsWhileLocked() { int current_thread_id = static_cast<int>(base::PlatformThread::CurrentId()); if (process_sort_index_ != 0) { - InitializeMetadataEvent(AddEventToThreadSharedChunkWhileLocked(NULL, false), + InitializeMetadataEvent(AddEventToThreadSharedChunkWhileLocked(NULL, NULL), current_thread_id, "process_sort_index", "sort_index", process_sort_index_); } if (process_name_.size()) { - InitializeMetadataEvent(AddEventToThreadSharedChunkWhileLocked(NULL, false), + InitializeMetadataEvent(AddEventToThreadSharedChunkWhileLocked(NULL, NULL), current_thread_id, "process_name", "name", process_name_); @@ -1947,7 +2011,7 @@ void TraceLog::AddMetadataEventsWhileLocked() { it++) { labels.push_back(it->second); } - InitializeMetadataEvent(AddEventToThreadSharedChunkWhileLocked(NULL, false), + InitializeMetadataEvent(AddEventToThreadSharedChunkWhileLocked(NULL, NULL), current_thread_id, "process_labels", "labels", JoinString(labels, ',')); @@ -1959,7 +2023,7 @@ void TraceLog::AddMetadataEventsWhileLocked() { it++) { if (it->second == 0) continue; - InitializeMetadataEvent(AddEventToThreadSharedChunkWhileLocked(NULL, false), + InitializeMetadataEvent(AddEventToThreadSharedChunkWhileLocked(NULL, NULL), it->first, "thread_sort_index", "sort_index", it->second); @@ -1971,7 +2035,7 @@ void TraceLog::AddMetadataEventsWhileLocked() { it++) { if (it->second.empty()) continue; - InitializeMetadataEvent(AddEventToThreadSharedChunkWhileLocked(NULL, false), + InitializeMetadataEvent(AddEventToThreadSharedChunkWhileLocked(NULL, NULL), it->first, "thread_name", "name", it->second); diff --git a/base/debug/trace_event_impl.h b/base/debug/trace_event_impl.h index 15adcab..189466e 100644 --- a/base/debug/trace_event_impl.h +++ b/base/debug/trace_event_impl.h @@ -354,6 +354,16 @@ class TraceSamplingThread; class BASE_EXPORT TraceLog { public: + // Notification is a mask of one or more of the following events. + enum Notification { + // The trace buffer does not flush dynamically, so when it fills up, + // subsequent trace events will be dropped. This callback is generated when + // the trace buffer is full. The callback must be thread safe. + TRACE_BUFFER_FULL = 1 << 0, + // A subscribed trace-event occurred. + EVENT_WATCH_NOTIFICATION = 1 << 1 + }; + // Options determines how the trace buffer stores data. enum Options { // Record until the trace buffer is full. @@ -385,6 +395,10 @@ class BASE_EXPORT TraceLog { static TraceLog* GetInstance(); + // Convert the given string to trace options. Defaults to RECORD_UNTIL_FULL if + // the string does not provide valid options. + static Options TraceOptionsFromString(const std::string& str); + // Get set of known category groups. This can change as new code paths are // reached. The known category groups are inserted into |category_groups|. void GetKnownCategoryGroups(std::vector<std::string>* category_groups); @@ -438,7 +452,14 @@ class BASE_EXPORT TraceLog { bool HasEnabledStateObserver(EnabledStateObserver* listener) const; float GetBufferPercentFull() const; - bool BufferIsFull() const; + + // Set the thread-safe notification callback. The callback can occur at any + // time and from any thread. WARNING: It is possible for the previously set + // callback to be called during OR AFTER a call to SetNotificationCallback. + // Therefore, the target of the callback must either be a global function, + // ref-counted object or a LazyInstance with Leaky traits (or equivalent). + typedef base::Callback<void(int)> NotificationCallback; + void SetNotificationCallback(const NotificationCallback& cb); // Not using base::Callback because of its limited by 7 parameters. // Also, using primitive type allows directly passing callback from WebCore. @@ -526,11 +547,12 @@ class BASE_EXPORT TraceLog { const char* name, TraceEventHandle handle); - // For every matching event, the callback will be called. - typedef base::Callback<void()> WatchEventCallback; + // For every matching event, a notification will be fired. NOTE: the + // notification will fire for each matching event that has already occurred + // since tracing was started (including before tracing if the process was + // started with tracing turned on). void SetWatchEvent(const std::string& category_name, - const std::string& event_name, - const WatchEventCallback& callback); + const std::string& event_name); // Cancel the watch event. If tracing is enabled, this may race with the // watch event notification firing. void CancelWatchEvent(); @@ -599,6 +621,29 @@ class BASE_EXPORT TraceLog { void UpdateCategoryGroupEnabledFlags(); void UpdateCategoryGroupEnabledFlag(int category_index); + // Helper class for managing notification_thread_count_ and running + // notification callbacks. This is very similar to a reader-writer lock, but + // shares the lock with TraceLog and manages the notification flags. + class NotificationHelper { + public: + inline explicit NotificationHelper(TraceLog* trace_log); + inline ~NotificationHelper(); + + // Called only while TraceLog::lock_ is held. This ORs the given + // notification with any existing notifications. + inline void AddNotificationWhileLocked(int notification); + + // Called only while TraceLog::lock_ is NOT held. If there are any pending + // notifications from previous calls to AddNotificationWhileLocked, this + // will call the NotificationCallback. + inline void SendNotificationIfAny(); + + private: + TraceLog* trace_log_; + NotificationCallback callback_copy_; + int notification_; + }; + class ThreadLocalEventBuffer; class OptionalAutoLock; @@ -614,10 +659,9 @@ class BASE_EXPORT TraceLog { const TimeTicks& timestamp, TraceEvent* trace_event); - TraceEvent* AddEventToThreadSharedChunkWhileLocked(TraceEventHandle* handle, - bool check_buffer_is_full); - void CheckIfBufferIsFullWhileLocked(); - void SetDisabledWhileLocked(); + TraceEvent* AddEventToThreadSharedChunkWhileLocked( + NotificationHelper* notifier, TraceEventHandle* handle); + void CheckIfBufferIsFullWhileLocked(NotificationHelper* notifier); TraceEvent* GetEventByHandleInternal(TraceEventHandle handle, OptionalAutoLock* lock); @@ -648,10 +692,12 @@ class BASE_EXPORT TraceLog { } // This lock protects TraceLog member accesses from arbitrary threads. - mutable Lock lock_; + Lock lock_; int locked_line_; bool enabled_; int num_traces_recorded_; + subtle::AtomicWord /* bool */ buffer_is_full_; + NotificationCallback notification_callback_; scoped_ptr<TraceBuffer> logged_events_; subtle::AtomicWord /* EventCallback */ event_callback_; bool dispatching_to_observer_list_; @@ -675,7 +721,6 @@ class BASE_EXPORT TraceLog { TimeDelta time_offset_; // Allow tests to wake up when certain events occur. - WatchEventCallback watch_event_callback_; subtle::AtomicWord /* const unsigned char* */ watch_category_; std::string watch_event_name_; diff --git a/base/debug/trace_event_unittest.cc b/base/debug/trace_event_unittest.cc index 0849c08..4aca180 100644 --- a/base/debug/trace_event_unittest.cc +++ b/base/debug/trace_event_unittest.cc @@ -53,8 +53,10 @@ class TraceEventTestFixture : public testing::Test { WaitableEvent* flush_complete_event, const scoped_refptr<base::RefCountedString>& events_str, bool has_more_events); - void OnWatchEventMatched() { - ++event_watch_notification_; + void OnTraceNotification(int notification) { + if (notification & TraceLog::EVENT_WATCH_NOTIFICATION) + ++event_watch_notification_; + notifications_received_ |= notification; } DictionaryValue* FindMatchingTraceEntry(const JsonKeyValue* key_values); DictionaryValue* FindNamePhase(const char* name, const char* phase); @@ -77,6 +79,7 @@ class TraceEventTestFixture : public testing::Test { void BeginSpecificTrace(const std::string& filter) { event_watch_notification_ = 0; + notifications_received_ = 0; TraceLog::GetInstance()->SetEnabled(CategoryFilter(filter), TraceLog::RECORD_UNTIL_FULL); } @@ -124,13 +127,16 @@ class TraceEventTestFixture : public testing::Test { virtual void SetUp() OVERRIDE { const char* name = PlatformThread::GetName(); old_thread_name_ = name ? strdup(name) : NULL; + notifications_received_ = 0; TraceLog::DeleteForTesting(); TraceLog* tracelog = TraceLog::GetInstance(); ASSERT_TRUE(tracelog); ASSERT_FALSE(tracelog->IsEnabled()); + tracelog->SetNotificationCallback( + base::Bind(&TraceEventTestFixture::OnTraceNotification, + base::Unretained(this))); trace_buffer_.SetOutputCallback(json_output_.GetCallback()); - event_watch_notification_ = 0; } virtual void TearDown() OVERRIDE { if (TraceLog::GetInstance()) @@ -147,6 +153,7 @@ class TraceEventTestFixture : public testing::Test { base::debug::TraceResultBuffer trace_buffer_; base::debug::TraceResultBuffer::SimpleOutput json_output_; int event_watch_notification_; + int notifications_received_; private: // We want our singleton torn down after each test. @@ -1181,17 +1188,14 @@ TEST_F(TraceEventTestFixture, Categories) { TEST_F(TraceEventTestFixture, EventWatchNotification) { // Basic one occurrence. BeginTrace(); - TraceLog::WatchEventCallback callback = - base::Bind(&TraceEventTestFixture::OnWatchEventMatched, - base::Unretained(this)); - TraceLog::GetInstance()->SetWatchEvent("cat", "event", callback); + TraceLog::GetInstance()->SetWatchEvent("cat", "event"); TRACE_EVENT_INSTANT0("cat", "event", TRACE_EVENT_SCOPE_THREAD); EndTraceAndFlush(); EXPECT_EQ(event_watch_notification_, 1); // Auto-reset after end trace. BeginTrace(); - TraceLog::GetInstance()->SetWatchEvent("cat", "event", callback); + TraceLog::GetInstance()->SetWatchEvent("cat", "event"); EndTraceAndFlush(); BeginTrace(); TRACE_EVENT_INSTANT0("cat", "event", TRACE_EVENT_SCOPE_THREAD); @@ -1201,7 +1205,7 @@ TEST_F(TraceEventTestFixture, EventWatchNotification) { // Multiple occurrence. BeginTrace(); int num_occurrences = 5; - TraceLog::GetInstance()->SetWatchEvent("cat", "event", callback); + TraceLog::GetInstance()->SetWatchEvent("cat", "event"); for (int i = 0; i < num_occurrences; ++i) TRACE_EVENT_INSTANT0("cat", "event", TRACE_EVENT_SCOPE_THREAD); EndTraceAndFlush(); @@ -1209,21 +1213,21 @@ TEST_F(TraceEventTestFixture, EventWatchNotification) { // Wrong category. BeginTrace(); - TraceLog::GetInstance()->SetWatchEvent("cat", "event", callback); + TraceLog::GetInstance()->SetWatchEvent("cat", "event"); TRACE_EVENT_INSTANT0("wrong_cat", "event", TRACE_EVENT_SCOPE_THREAD); EndTraceAndFlush(); EXPECT_EQ(event_watch_notification_, 0); // Wrong name. BeginTrace(); - TraceLog::GetInstance()->SetWatchEvent("cat", "event", callback); + TraceLog::GetInstance()->SetWatchEvent("cat", "event"); TRACE_EVENT_INSTANT0("cat", "wrong_event", TRACE_EVENT_SCOPE_THREAD); EndTraceAndFlush(); EXPECT_EQ(event_watch_notification_, 0); // Canceled. BeginTrace(); - TraceLog::GetInstance()->SetWatchEvent("cat", "event", callback); + TraceLog::GetInstance()->SetWatchEvent("cat", "event"); TraceLog::GetInstance()->CancelWatchEvent(); TRACE_EVENT_INSTANT0("cat", "event", TRACE_EVENT_SCOPE_THREAD); EndTraceAndFlush(); @@ -1730,7 +1734,23 @@ TEST_F(TraceEventTestFixture, TraceCategoriesAfterNestedEnable) { trace_log->SetDisabled(); } +TEST_F(TraceEventTestFixture, TraceOptionsParsing) { + EXPECT_EQ(TraceLog::RECORD_UNTIL_FULL, + TraceLog::TraceOptionsFromString(std::string())); + + EXPECT_EQ(TraceLog::RECORD_UNTIL_FULL, + TraceLog::TraceOptionsFromString("record-until-full")); + EXPECT_EQ(TraceLog::RECORD_CONTINUOUSLY, + TraceLog::TraceOptionsFromString("record-continuously")); + EXPECT_EQ(TraceLog::RECORD_UNTIL_FULL | TraceLog::ENABLE_SAMPLING, + TraceLog::TraceOptionsFromString("enable-sampling")); + EXPECT_EQ(TraceLog::RECORD_CONTINUOUSLY | TraceLog::ENABLE_SAMPLING, + TraceLog::TraceOptionsFromString( + "record-continuously,enable-sampling")); +} + TEST_F(TraceEventTestFixture, TraceSampling) { + event_watch_notification_ = 0; TraceLog::GetInstance()->SetEnabled( CategoryFilter("*"), TraceLog::Options(TraceLog::RECORD_UNTIL_FULL | @@ -1749,6 +1769,7 @@ TEST_F(TraceEventTestFixture, TraceSampling) { } TEST_F(TraceEventTestFixture, TraceSamplingScope) { + event_watch_notification_ = 0; TraceLog::GetInstance()->SetEnabled( CategoryFilter("*"), TraceLog::Options(TraceLog::RECORD_UNTIL_FULL | @@ -1783,6 +1804,7 @@ TEST_F(TraceEventTestFixture, TraceSamplingScope) { } TEST_F(TraceEventTestFixture, TraceContinuousSampling) { + event_watch_notification_ = 0; TraceLog::GetInstance()->SetEnabled( CategoryFilter("*"), TraceLog::Options(TraceLog::MONITOR_SAMPLING)); @@ -2049,7 +2071,7 @@ TEST_F(TraceEventCallbackTest, TraceEventCallbackWhileFull) { TraceLog::RECORD_UNTIL_FULL); do { TRACE_EVENT_INSTANT0("all", "badger badger", TRACE_EVENT_SCOPE_GLOBAL); - } while (!TraceLog::GetInstance()->BufferIsFull()); + } while ((notifications_received_ & TraceLog::TRACE_BUFFER_FULL) == 0); TraceLog::GetInstance()->SetEventCallbackEnabled(CategoryFilter("*"), Callback); TRACE_EVENT_INSTANT0("all", "a snake", TRACE_EVENT_SCOPE_GLOBAL); diff --git a/chrome/browser/automation/automation_provider.cc b/chrome/browser/automation/automation_provider.cc index 6905cf5..b2dc726 100644 --- a/chrome/browser/automation/automation_provider.cc +++ b/chrome/browser/automation/automation_provider.cc @@ -66,7 +66,7 @@ #include "content/public/browser/download_item.h" #include "content/public/browser/native_web_keyboard_event.h" #include "content/public/browser/render_view_host.h" -#include "content/public/browser/tracing_controller.h" +#include "content/public/browser/trace_controller.h" #include "content/public/browser/web_contents.h" #include "content/public/browser/web_contents_view.h" #include "net/proxy/proxy_config_service_fixed.h" @@ -86,7 +86,7 @@ using content::BrowserThread; using content::DownloadItem; using content::NavigationController; using content::RenderViewHost; -using content::TracingController; +using content::TraceController; using content::WebContents; namespace { @@ -376,6 +376,20 @@ void AutomationProvider::OnChannelConnected(int pid) { SendInitialLoadMessage(); } +void AutomationProvider::OnEndTracingComplete() { + IPC::Message* reply_message = tracing_data_.reply_message.release(); + if (reply_message) { + AutomationMsg_EndTracing::WriteReplyParams( + reply_message, tracing_data_.trace_output.size(), true); + Send(reply_message); + } +} + +void AutomationProvider::OnTraceDataCollected( + const scoped_refptr<base::RefCountedString>& trace_fragment) { + tracing_data_.trace_output.push_back(trace_fragment->data()); +} + bool AutomationProvider::OnMessageReceived(const IPC::Message& message) { bool handled = true; bool deserialize_success = true; @@ -398,6 +412,7 @@ bool AutomationProvider::OnMessageReceived(const IPC::Message& message) { JavaScriptStressTestControl) IPC_MESSAGE_HANDLER(AutomationMsg_BeginTracing, BeginTracing) IPC_MESSAGE_HANDLER_DELAY_REPLY(AutomationMsg_EndTracing, EndTracing) + IPC_MESSAGE_HANDLER(AutomationMsg_GetTracingOutput, GetTracingOutput) #if defined(OS_WIN) // These are for use with external tabs. IPC_MESSAGE_HANDLER(AutomationMsg_CreateExternalTab, CreateExternalTab) @@ -707,28 +722,39 @@ void AutomationProvider::JavaScriptStressTestControl(int tab_handle, void AutomationProvider::BeginTracing(const std::string& category_patterns, bool* success) { - *success = TracingController::GetInstance()->EnableRecording( - category_patterns, TracingController::DEFAULT_OPTIONS, - TracingController::EnableRecordingDoneCallback()); + tracing_data_.trace_output.clear(); + *success = TraceController::GetInstance()->BeginTracing( + this, + category_patterns, + base::debug::TraceLog::RECORD_UNTIL_FULL); } void AutomationProvider::EndTracing(IPC::Message* reply_message) { - base::FilePath path; - if (!TracingController::GetInstance()->DisableRecording( - path, base::Bind(&AutomationProvider::OnTraceDataCollected, this, - reply_message))) { + bool success = false; + if (!tracing_data_.reply_message.get()) + success = TraceController::GetInstance()->EndTracingAsync(this); + if (success) { + // Defer EndTracing reply until TraceController calls us back with all the + // events. + tracing_data_.reply_message.reset(reply_message); + } else { // If failed to call EndTracingAsync, need to reply with failure now. - AutomationMsg_EndTracing::WriteReplyParams(reply_message, path, false); + AutomationMsg_EndTracing::WriteReplyParams(reply_message, size_t(0), false); Send(reply_message); } - // Otherwise defer EndTracing reply until TraceController calls us back. } -void AutomationProvider::OnTraceDataCollected(IPC::Message* reply_message, - const base::FilePath& path) { - if (reply_message) { - AutomationMsg_EndTracing::WriteReplyParams(reply_message, path, true); - Send(reply_message); +void AutomationProvider::GetTracingOutput(std::string* chunk, + bool* success) { + // The JSON data is sent back to the test in chunks, because IPC sends will + // fail if they are too large. + if (tracing_data_.trace_output.empty()) { + *chunk = ""; + *success = false; + } else { + *chunk = tracing_data_.trace_output.front(); + tracing_data_.trace_output.pop_front(); + *success = true; } } diff --git a/chrome/browser/automation/automation_provider.h b/chrome/browser/automation/automation_provider.h index a97b6d2..eed3887 100644 --- a/chrome/browser/automation/automation_provider.h +++ b/chrome/browser/automation/automation_provider.h @@ -29,6 +29,7 @@ #include "components/autofill/core/browser/field_types.h" #include "content/public/browser/browser_thread.h" #include "content/public/browser/notification_observer.h" +#include "content/public/browser/trace_subscriber.h" #include "ipc/ipc_channel.h" #include "ipc/ipc_listener.h" #include "ipc/ipc_sender.h" @@ -81,7 +82,8 @@ class AutomationProvider public IPC::Sender, public base::SupportsWeakPtr<AutomationProvider>, public base::RefCountedThreadSafe< - AutomationProvider, content::BrowserThread::DeleteOnUIThread> { + AutomationProvider, content::BrowserThread::DeleteOnUIThread>, + public content::TraceSubscriber { public: explicit AutomationProvider(Profile* profile); @@ -213,6 +215,17 @@ class AutomationProvider bool reinitialize_on_channel_error_; private: + // Storage for EndTracing() to resume operations after a callback. + struct TracingData { + std::list<std::string> trace_output; + scoped_ptr<IPC::Message> reply_message; + }; + + // TraceSubscriber: + virtual void OnEndTracingComplete() OVERRIDE; + virtual void OnTraceDataCollected( + const scoped_refptr<base::RefCountedString>& trace_fragment) OVERRIDE; + void OnUnhandledMessage(const IPC::Message& message); // Clear and reinitialize the automation IPC channel. @@ -241,8 +254,7 @@ class AutomationProvider void BeginTracing(const std::string& category_patterns, bool* success); void EndTracing(IPC::Message* reply_message); - void OnTraceDataCollected(IPC::Message* reply_message, - const base::FilePath& path); + void GetTracingOutput(std::string* chunk, bool* success); // Asynchronous request for printing the current tab. void PrintAsync(int tab_handle); @@ -339,6 +351,10 @@ class AutomationProvider // ID of automation channel. std::string channel_id_; + // Trace data that has been collected but not flushed to the automation + // client. + TracingData tracing_data_; + DISALLOW_COPY_AND_ASSIGN(AutomationProvider); }; diff --git a/chrome/browser/feedback/feedback_util.cc b/chrome/browser/feedback/feedback_util.cc index 969bb9e..ace8c39 100644 --- a/chrome/browser/feedback/feedback_util.cc +++ b/chrome/browser/feedback/feedback_util.cc @@ -374,33 +374,24 @@ void SendReport(scoped_refptr<FeedbackData> data) { bool ZipString(const base::FilePath& filename, const std::string& data, std::string* compressed_logs) { base::FilePath temp_path; + base::FilePath zip_file; - // Create a temporary directory, put the logs into a file in it. + // Create a temporary directory, put the logs into a file in it. Create + // another temporary file to receive the zip file in. if (!file_util::CreateNewTempDirectory(FILE_PATH_LITERAL(""), &temp_path)) return false; - - base::FilePath temp_file = temp_path.Append(filename); - if (file_util::WriteFile(temp_file, data.c_str(), data.size()) == -1) + if (file_util::WriteFile(temp_path.Append(filename), + data.c_str(), data.size()) == -1) return false; - - return ZipFile(temp_file, compressed_logs); -} - -bool ZipFile(const base::FilePath& filename, std::string* compressed_logs) { - base::FilePath zip_file; - - // Create a temporary file to receive the zip file in it. if (!file_util::CreateTemporaryFile(&zip_file)) return false; - if (!zip::Zip(filename, zip_file, false)) + if (!zip::Zip(temp_path, zip_file, false)) return false; if (!base::ReadFileToString(zip_file, compressed_logs)) return false; - base::DeleteFile(zip_file, false); - return true; } diff --git a/chrome/browser/feedback/feedback_util.h b/chrome/browser/feedback/feedback_util.h index 69385a9..1fc9e64 100644 --- a/chrome/browser/feedback/feedback_util.h +++ b/chrome/browser/feedback/feedback_util.h @@ -38,7 +38,6 @@ namespace feedback_util { void SendReport(scoped_refptr<FeedbackData> data); bool ZipString(const base::FilePath& filename, const std::string& data, std::string* compressed_data); - bool ZipFile(const base::FilePath& filename, std::string* compressed_data); } // namespace feedback_util diff --git a/chrome/browser/feedback/tracing_manager.cc b/chrome/browser/feedback/tracing_manager.cc index a78c292..92dba45 100644 --- a/chrome/browser/feedback/tracing_manager.cc +++ b/chrome/browser/feedback/tracing_manager.cc @@ -5,21 +5,20 @@ #include "chrome/browser/feedback/tracing_manager.h" #include "base/bind.h" -#include "base/file_util.h" -#include "base/location.h" -#include "base/memory/ref_counted_memory.h" -#include "base/message_loop/message_loop_proxy.h" #include "base/prefs/pref_service.h" #include "chrome/browser/browser_process.h" #include "chrome/browser/feedback/feedback_util.h" #include "chrome/common/pref_names.h" -#include "content/public/browser/tracing_controller.h" +#include "content/public/browser/trace_controller.h" namespace { // Only once trace manager can exist at a time. TracingManager* g_tracing_manager = NULL; // Trace IDs start at 1 and increase. int g_next_trace_id = 1; +// Name of the file to store the tracing data as. +const base::FilePath::CharType kTracingFilename[] = + FILE_PATH_LITERAL("tracing.json"); } TracingManager::TracingManager() @@ -42,10 +41,7 @@ int TracingManager::RequestTrace() { current_trace_id_ = g_next_trace_id; ++g_next_trace_id; - content::TracingController::GetInstance()->DisableRecording( - base::FilePath(), - base::Bind(&TracingManager::OnTraceDataCollected, - weak_ptr_factory_.GetWeakPtr())); + content::TraceController::GetInstance()->EndTracingAsync(this); return current_trace_id_; } @@ -80,6 +76,7 @@ void TracingManager::DiscardTraceData(int id) { // If the trace is discarded before it is complete, clean up the accumulators. if (id == current_trace_id_) { current_trace_id_ = 0; + data_ = ""; // If the trace has already been requested, provide an empty string. if (!trace_callback_.is_null()) { @@ -90,18 +87,20 @@ void TracingManager::DiscardTraceData(int id) { } void TracingManager::StartTracing() { - content::TracingController::GetInstance()->EnableRecording( - "", content::TracingController::DEFAULT_OPTIONS, - content::TracingController::EnableRecordingDoneCallback()); + content::TraceController::GetInstance()->BeginTracing( + this, "-test_*", + base::debug::TraceLog::RECORD_CONTINUOUSLY); } -void TracingManager::OnTraceDataCollected(const base::FilePath& path) { +void TracingManager::OnEndTracingComplete() { if (!current_trace_id_) return; + data_ = std::string("[") + data_ + "]"; + std::string output_val; - feedback_util::ZipFile(path, &output_val); - base::DeleteFile(path, false); + feedback_util::ZipString( + base::FilePath(kTracingFilename), data_, &output_val); scoped_refptr<base::RefCountedString> output( base::RefCountedString::TakeString(&output_val)); @@ -114,6 +113,7 @@ void TracingManager::OnTraceDataCollected(const base::FilePath& path) { } current_trace_id_ = 0; + data_ = ""; // Tracing has to be restarted asynchronous, so the TracingController can // clean up. @@ -123,6 +123,15 @@ void TracingManager::OnTraceDataCollected(const base::FilePath& path) { weak_ptr_factory_.GetWeakPtr())); } +void TracingManager::OnTraceDataCollected( + const scoped_refptr<base::RefCountedString>& trace_fragment) { + if (current_trace_id_) { + if (!data_.empty()) + data_ += ","; + data_ += trace_fragment->data(); + } +} + // static scoped_ptr<TracingManager> TracingManager::Create() { if (g_tracing_manager) diff --git a/chrome/browser/feedback/tracing_manager.h b/chrome/browser/feedback/tracing_manager.h index 5fd5588..c70206a 100644 --- a/chrome/browser/feedback/tracing_manager.h +++ b/chrome/browser/feedback/tracing_manager.h @@ -12,18 +12,13 @@ #include "base/callback.h" #include "base/memory/scoped_ptr.h" #include "base/memory/weak_ptr.h" +#include "content/public/browser/trace_subscriber.h" -namespace base { - -class RefCountedString; -class FilePath; - -} // Callback used for getting the output of a trace. typedef base::Callback<void(scoped_refptr<base::RefCountedString> trace_data)> TraceDataCallback; -// This class is used to manage performance metrics that can be attached to +// This class is used to manage performance meterics that can be attached to // feedback reports. This class is a Singleton that is owned by the preference // system. It should only be created when it is enabled, and should only be // accessed elsewhere via Get(). @@ -33,7 +28,7 @@ typedef base::Callback<void(scoped_refptr<base::RefCountedString> trace_data)> // version of the performance data. That data can then be requested via // GetTraceData(). When the data is no longer needed, it should be discarded // via DiscardTraceData(). -class TracingManager { +class TracingManager : public content::TraceSubscriber { public: virtual ~TracingManager(); @@ -55,10 +50,17 @@ class TracingManager { void DiscardTraceData(int id); private: + void StartTracing(); + + // content::TraceSubscriber overrides + virtual void OnEndTracingComplete() OVERRIDE; + virtual void OnTraceDataCollected( + const scoped_refptr<base::RefCountedString>& trace_fragment) OVERRIDE; + TracingManager(); - void StartTracing(); - void OnTraceDataCollected(const base::FilePath& path); + // Data being collected from the current trace. + std::string data_; // ID of the trace that is being collected. int current_trace_id_; diff --git a/chrome/common/automation_messages_internal.h b/chrome/common/automation_messages_internal.h index 0625ef9..1070dad 100644 --- a/chrome/common/automation_messages_internal.h +++ b/chrome/common/automation_messages_internal.h @@ -934,7 +934,15 @@ IPC_SYNC_MESSAGE_CONTROL1_1(AutomationMsg_BeginTracing, // End tracing (called after BeginTracing). This blocks until tracing has // stopped on all processes and all the events are ready to be retrieved. IPC_SYNC_MESSAGE_CONTROL0_2(AutomationMsg_EndTracing, - base::FilePath /* result_file_path */, + size_t /* num_trace_chunks */, + bool /* success */) + +// Retrieve trace event data (called after EndTracing). Must call exactly +// |num_trace_chunks| times. +// TODO(jbates): See bug 100255, IPC send fails if message is too big. This +// code can be removed if that limitation is fixed. +IPC_SYNC_MESSAGE_CONTROL0_2(AutomationMsg_GetTracingOutput, + std::string /* trace_chunk */, bool /* success */) // Used on Mac OS X to read the number of active Mach ports used in the browser diff --git a/chrome/test/automation/automation_proxy.cc b/chrome/test/automation/automation_proxy.cc index aae6691..1c8cdb2 100644 --- a/chrome/test/automation/automation_proxy.cc +++ b/chrome/test/automation/automation_proxy.cc @@ -7,7 +7,7 @@ #include <sstream> #include "base/basictypes.h" -#include "base/file_util.h" +#include "base/debug/trace_event.h" #include "base/logging.h" #include "base/memory/ref_counted.h" #include "base/synchronization/waitable_event.h" @@ -410,13 +410,31 @@ bool AutomationProxy::BeginTracing(const std::string& category_patterns) { bool AutomationProxy::EndTracing(std::string* json_trace_output) { bool success = false; - base::FilePath path; - if (!Send(new AutomationMsg_EndTracing(&path, &success)) || !success) + size_t num_trace_chunks = 0; + if (!Send(new AutomationMsg_EndTracing(&num_trace_chunks, &success)) || + !success) return false; - bool ok = base::ReadFileToString(path, json_trace_output); - DCHECK(ok); - base::DeleteFile(path, false); + std::string chunk; + base::debug::TraceResultBuffer buffer; + base::debug::TraceResultBuffer::SimpleOutput output; + buffer.SetOutputCallback(output.GetCallback()); + + // TODO(jbates): See bug 100255, IPC send fails if message is too big. This + // code can be simplified if that limitation is fixed. + // Workaround IPC payload size limitation by getting chunks. + buffer.Start(); + for (size_t i = 0; i < num_trace_chunks; ++i) { + // The broswer side AutomationProvider resets state at BeginTracing, + // so it can recover even after this fails mid-way. + if (!Send(new AutomationMsg_GetTracingOutput(&chunk, &success)) || + !success) + return false; + buffer.AddFragment(chunk); + } + buffer.Finish(); + + *json_trace_output = output.json_output; return true; } diff --git a/chrome/test/base/tracing.cc b/chrome/test/base/tracing.cc index 5aa07e7..7060b9b 100644 --- a/chrome/test/base/tracing.cc +++ b/chrome/test/base/tracing.cc @@ -4,21 +4,19 @@ #include "chrome/test/base/tracing.h" -#include "base/file_util.h" -#include "base/files/file_path.h" +#include "base/debug/trace_event.h" #include "base/memory/singleton.h" #include "base/message_loop/message_loop.h" -#include "base/strings/string_util.h" -#include "base/timer/timer.h" #include "content/public/browser/browser_thread.h" -#include "content/public/browser/tracing_controller.h" +#include "content/public/browser/trace_controller.h" +#include "content/public/browser/trace_subscriber.h" #include "content/public/test/test_utils.h" namespace { using content::BrowserThread; -class InProcessTraceController { +class InProcessTraceController : public content::TraceSubscriber { public: static InProcessTraceController* GetInstance() { return Singleton<InProcessTraceController>::get(); @@ -31,10 +29,8 @@ class InProcessTraceController { bool BeginTracing(const std::string& category_patterns) { DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI)); - return content::TracingController::GetInstance()->EnableRecording( - category_patterns, content::TracingController::DEFAULT_OPTIONS, - content::TracingController::EnableRecordingDoneCallback()); - return true; + return content::TraceController::GetInstance()->BeginTracing( + this, category_patterns, base::debug::TraceLog::RECORD_UNTIL_FULL); } bool BeginTracingWithWatch(const std::string& category_patterns, @@ -44,11 +40,9 @@ class InProcessTraceController { DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI)); DCHECK(num_occurrences > 0); watch_notification_count_ = num_occurrences; - return content::TracingController::GetInstance()->SetWatchEvent( - category_name, event_name, - base::Bind(&InProcessTraceController::OnWatchEventMatched, - base::Unretained(this))) && - BeginTracing(category_patterns); + return BeginTracing(category_patterns) && + content::TraceController::GetInstance()->SetWatchEvent( + this, category_name, event_name); } bool WaitForWatchEvent(base::TimeDelta timeout) { @@ -73,16 +67,20 @@ class InProcessTraceController { DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI)); using namespace base::debug; - if (!content::TracingController::GetInstance()->DisableRecording( - base::FilePath(), - base::Bind(&InProcessTraceController::OnTraceDataCollected, - base::Unretained(this), - base::Unretained(json_trace_output)))) - return false; + TraceResultBuffer::SimpleOutput output; + trace_buffer_.SetOutputCallback(output.GetCallback()); + trace_buffer_.Start(); + if (!content::TraceController::GetInstance()->EndTracingAsync(this)) + return false; // Wait for OnEndTracingComplete() to quit the message loop. + // OnTraceDataCollected may be called multiple times while blocking here. message_loop_runner_ = new content::MessageLoopRunner; message_loop_runner_->Run(); + trace_buffer_.Finish(); + trace_buffer_.SetOutputCallback(TraceResultBuffer::OutputCallback()); + + *json_trace_output = output.json_output; // Watch notifications can occur during this method's message loop run, but // not after, so clear them here. @@ -93,40 +91,19 @@ class InProcessTraceController { private: friend struct DefaultSingletonTraits<InProcessTraceController>; - void OnEndTracingComplete() { + // TraceSubscriber implementation + virtual void OnEndTracingComplete() OVERRIDE { message_loop_runner_->Quit(); } - void OnTraceDataCollected(std::string* json_trace_output, - const base::FilePath& path) { - BrowserThread::PostTask(BrowserThread::FILE, FROM_HERE, - base::Bind(&InProcessTraceController::ReadTraceData, - base::Unretained(this), - base::Unretained(json_trace_output), - path)); + // TraceSubscriber implementation + virtual void OnTraceDataCollected( + const scoped_refptr<base::RefCountedString>& trace_fragment) OVERRIDE { + trace_buffer_.AddFragment(trace_fragment->data()); } - void ReadTraceData(std::string* json_trace_output, - const base::FilePath& path) { - json_trace_output->clear(); - bool ok = base::ReadFileToString(path, json_trace_output); - DCHECK(ok); - base::DeleteFile(path, false); - - // The callers expect an array of trace events. - const char* preamble = "{\"traceEvents\": "; - const char* trailout = "}"; - DCHECK(StartsWithASCII(*json_trace_output, preamble, true)); - DCHECK(EndsWith(*json_trace_output, trailout, true)); - json_trace_output->erase(0, strlen(preamble)); - json_trace_output->erase(json_trace_output->end() - 1); - - BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, - base::Bind(&InProcessTraceController::OnEndTracingComplete, - base::Unretained(this))); - } - - void OnWatchEventMatched() { + // TraceSubscriber implementation + virtual void OnEventWatchNotification() OVERRIDE { if (watch_notification_count_ == 0) return; if (--watch_notification_count_ == 0) { @@ -141,6 +118,9 @@ class InProcessTraceController { message_loop_runner_->Quit(); } + // For collecting trace data asynchronously. + base::debug::TraceResultBuffer trace_buffer_; + scoped_refptr<content::MessageLoopRunner> message_loop_runner_; base::OneShotTimer<InProcessTraceController> timer_; diff --git a/components/tracing/child_trace_message_filter.cc b/components/tracing/child_trace_message_filter.cc index d3875c7..8a0e414 100644 --- a/components/tracing/child_trace_message_filter.cc +++ b/components/tracing/child_trace_message_filter.cc @@ -19,11 +19,14 @@ ChildTraceMessageFilter::ChildTraceMessageFilter( void ChildTraceMessageFilter::OnFilterAdded(IPC::Channel* channel) { channel_ = channel; + TraceLog::GetInstance()->SetNotificationCallback( + base::Bind(&ChildTraceMessageFilter::OnTraceNotification, this)); channel_->Send(new TracingHostMsg_ChildSupportsTracing()); } void ChildTraceMessageFilter::OnFilterRemoved() { - channel_ = NULL; + TraceLog::GetInstance()->SetNotificationCallback( + TraceLog::NotificationCallback()); } bool ChildTraceMessageFilter::OnMessageReceived(const IPC::Message& message) { @@ -107,24 +110,14 @@ void ChildTraceMessageFilter::OnGetTraceBufferPercentFull() { void ChildTraceMessageFilter::OnSetWatchEvent(const std::string& category_name, const std::string& event_name) { - TraceLog::GetInstance()->SetWatchEvent( - category_name, event_name, - base::Bind(&ChildTraceMessageFilter::OnWatchEventMatched, this)); + TraceLog::GetInstance()->SetWatchEvent(category_name.c_str(), + event_name.c_str()); } void ChildTraceMessageFilter::OnCancelWatchEvent() { TraceLog::GetInstance()->CancelWatchEvent(); } -void ChildTraceMessageFilter::OnWatchEventMatched() { - if (!ipc_message_loop_->BelongsToCurrentThread()) { - ipc_message_loop_->PostTask(FROM_HERE, - base::Bind(&ChildTraceMessageFilter::OnWatchEventMatched, this)); - return; - } - channel_->Send(new TracingHostMsg_WatchEventMatched); -} - void ChildTraceMessageFilter::OnTraceDataCollected( const scoped_refptr<base::RefCountedString>& events_str_ptr, bool has_more_events) { @@ -164,4 +157,14 @@ void ChildTraceMessageFilter::OnMonitoringTraceDataCollected( channel_->Send(new TracingHostMsg_CaptureMonitoringSnapshotAck()); } +void ChildTraceMessageFilter::OnTraceNotification(int notification) { + if (!ipc_message_loop_->BelongsToCurrentThread()) { + ipc_message_loop_->PostTask(FROM_HERE, + base::Bind(&ChildTraceMessageFilter::OnTraceNotification, this, + notification)); + return; + } + channel_->Send(new TracingHostMsg_TraceNotification(notification)); +} + } // namespace tracing diff --git a/components/tracing/child_trace_message_filter.h b/components/tracing/child_trace_message_filter.h index d2aae3b..cbd300f 100644 --- a/components/tracing/child_trace_message_filter.h +++ b/components/tracing/child_trace_message_filter.h @@ -43,7 +43,6 @@ class ChildTraceMessageFilter : public IPC::ChannelProxy::MessageFilter { void OnSetWatchEvent(const std::string& category_name, const std::string& event_name); void OnCancelWatchEvent(); - void OnWatchEventMatched(); // Callback from trace subsystem. void OnTraceDataCollected( @@ -54,6 +53,8 @@ class ChildTraceMessageFilter : public IPC::ChannelProxy::MessageFilter { const scoped_refptr<base::RefCountedString>& events_str_ptr, bool has_more_events); + void OnTraceNotification(int notification); + IPC::Channel* channel_; base::MessageLoopProxy* ipc_message_loop_; diff --git a/components/tracing/tracing_messages.h b/components/tracing/tracing_messages.h index 1107baf..25b45bd 100644 --- a/components/tracing/tracing_messages.h +++ b/components/tracing/tracing_messages.h @@ -30,7 +30,7 @@ IPC_MESSAGE_CONTROL3(TracingMsg_EnableMonitoring, base::TimeTicks /* browser_time */, int /* base::debug::TraceLog::Options */) -// Sent to all child processes to stop monitoring. +// Sent to all child processes to stop monitoring.. IPC_MESSAGE_CONTROL0(TracingMsg_DisableMonitoring) // Sent to all child processes to capture the current monitorint snapshot. @@ -47,9 +47,6 @@ IPC_MESSAGE_CONTROL2(TracingMsg_SetWatchEvent, // Sent to all child processes to clear watch event. IPC_MESSAGE_CONTROL0(TracingMsg_CancelWatchEvent) -// Sent everytime when a watch event is matched. -IPC_MESSAGE_CONTROL0(TracingHostMsg_WatchEventMatched); - // Notify the browser that this child process supports tracing. IPC_MESSAGE_CONTROL0(TracingHostMsg_ChildSupportsTracing) @@ -60,6 +57,10 @@ IPC_MESSAGE_CONTROL1(TracingHostMsg_EndTracingAck, // Reply from child processes acking TracingMsg_CaptureMonitoringSnapshot. IPC_MESSAGE_CONTROL0(TracingHostMsg_CaptureMonitoringSnapshotAck) +// Sent if the trace buffer becomes full. +IPC_MESSAGE_CONTROL1(TracingHostMsg_TraceNotification, + int /* base::debug::TraceLog::Notification */) + // Child processes send back trace data in JSON chunks. IPC_MESSAGE_CONTROL1(TracingHostMsg_TraceDataCollected, std::string /*json trace data*/) diff --git a/content/browser/android/tracing_controller_android.cc b/content/browser/android/tracing_controller_android.cc index 75ac6d7..42d147e 100644 --- a/content/browser/android/tracing_controller_android.cc +++ b/content/browser/android/tracing_controller_android.cc @@ -6,9 +6,12 @@ #include "base/android/jni_android.h" #include "base/android/jni_string.h" +#include "base/command_line.h" #include "base/debug/trace_event.h" +#include "base/files/file_path.h" #include "base/logging.h" -#include "content/public/browser/tracing_controller.h" +#include "content/browser/tracing/trace_subscriber_stdio.h" +#include "content/public/browser/trace_controller.h" #include "jni/TracingControllerAndroid_jni.h" namespace content { @@ -18,9 +21,29 @@ static jlong Init(JNIEnv* env, jobject obj) { return reinterpret_cast<intptr_t>(profiler); } +class TracingControllerAndroid::Subscriber + : public content::TraceSubscriberStdio { + public: + Subscriber(TracingControllerAndroid* profiler, const base::FilePath& path) + : TraceSubscriberStdio(path, FILE_TYPE_ARRAY, false), + profiler_(profiler) {} + + void set_profiler(TracingControllerAndroid* profiler) { + CHECK(!profiler_); + profiler_ = profiler; + } + + virtual void OnEndTracingComplete() OVERRIDE { + TraceSubscriberStdio::OnEndTracingComplete(); + profiler_->OnTracingStopped(); + } + + private: + TracingControllerAndroid* profiler_; +}; + TracingControllerAndroid::TracingControllerAndroid(JNIEnv* env, jobject obj) - : weak_java_object_(env, obj), - weak_factory_(this) {} + : weak_java_object_(env, obj) {} TracingControllerAndroid::~TracingControllerAndroid() {} @@ -33,37 +56,39 @@ bool TracingControllerAndroid::StartTracing(JNIEnv* env, jstring jfilename, jstring jcategories, jboolean record_continuously) { - file_path_ = base::FilePath( - base::android::ConvertJavaStringToUTF8(env, jfilename)); + if (subscriber_.get()) { + return false; + } + std::string filename = base::android::ConvertJavaStringToUTF8(env, jfilename); std::string categories = base::android::ConvertJavaStringToUTF8(env, jcategories); - - // This log is required by adb_profile_chrome.py. - LOG(WARNING) << "Logging performance trace to file: " << file_path_.value(); - - return TracingController::GetInstance()->EnableRecording( + subscriber_.reset(new Subscriber(this, base::FilePath(filename))); + return TraceController::GetInstance()->BeginTracing( + subscriber_.get(), categories, - record_continuously ? TracingController::RECORD_CONTINUOUSLY - : TracingController::DEFAULT_OPTIONS, - TracingController::EnableRecordingDoneCallback()); + record_continuously ? base::debug::TraceLog::RECORD_CONTINUOUSLY + : base::debug::TraceLog::RECORD_UNTIL_FULL); } void TracingControllerAndroid::StopTracing(JNIEnv* env, jobject obj) { - if (!TracingController::GetInstance()->DisableRecording( - file_path_, - base::Bind(&TracingControllerAndroid::OnTracingStopped, - weak_factory_.GetWeakPtr()))) { + if (!subscriber_.get()) { + return; + } + TraceController* controller = TraceController::GetInstance(); + if (!controller->EndTracingAsync(subscriber_.get())) { LOG(ERROR) << "EndTracingAsync failed, forcing an immediate stop"; - OnTracingStopped(file_path_); + controller->CancelSubscriber(subscriber_.get()); + OnTracingStopped(); } } -void TracingControllerAndroid::OnTracingStopped( - const base::FilePath& file_path) { +void TracingControllerAndroid::OnTracingStopped() { JNIEnv* env = base::android::AttachCurrentThread(); base::android::ScopedJavaLocalRef<jobject> obj = weak_java_object_.get(env); - if (obj.obj()) + if (obj.obj()) { Java_TracingControllerAndroid_onTracingStopped(env, obj.obj()); + } + subscriber_.reset(); } static jstring GetDefaultCategories(JNIEnv* env, jobject obj) { diff --git a/content/browser/android/tracing_controller_android.h b/content/browser/android/tracing_controller_android.h index 4d70e7b..0cd310e 100644 --- a/content/browser/android/tracing_controller_android.h +++ b/content/browser/android/tracing_controller_android.h @@ -6,8 +6,7 @@ #define CONTENT_BROWSER_ANDROID_TRACING_CONTROLLER_ANDROID_H_ #include "base/android/jni_helper.h" -#include "base/files/file_path.h" -#include "base/memory/weak_ptr.h" +#include "base/memory/scoped_ptr.h" namespace content { @@ -26,11 +25,12 @@ class TracingControllerAndroid { private: ~TracingControllerAndroid(); - void OnTracingStopped(const base::FilePath& file_path); + void OnTracingStopped(); JavaObjectWeakGlobalRef weak_java_object_; - base::FilePath file_path_; - base::WeakPtrFactory<TracingControllerAndroid> weak_factory_; + + class Subscriber; + scoped_ptr<Subscriber> subscriber_; DISALLOW_COPY_AND_ASSIGN(TracingControllerAndroid); }; diff --git a/content/browser/devtools/devtools_tracing_handler.cc b/content/browser/devtools/devtools_tracing_handler.cc index 0e1869a..0657b8e 100644 --- a/content/browser/devtools/devtools_tracing_handler.cc +++ b/content/browser/devtools/devtools_tracing_handler.cc @@ -6,18 +6,14 @@ #include "base/bind.h" #include "base/callback.h" -#include "base/file_util.h" -#include "base/json/json_reader.h" -#include "base/json/json_writer.h" #include "base/location.h" -#include "base/memory/ref_counted_memory.h" #include "base/strings/string_split.h" #include "base/strings/stringprintf.h" #include "base/values.h" #include "content/browser/devtools/devtools_http_handler_impl.h" #include "content/browser/devtools/devtools_protocol_constants.h" -#include "content/public/browser/browser_thread.h" -#include "content/public/browser/tracing_controller.h" +#include "content/public/browser/trace_controller.h" +#include "content/public/browser/trace_subscriber.h" namespace content { @@ -27,23 +23,10 @@ const char kRecordUntilFull[] = "record-until-full"; const char kRecordContinuously[] = "record-continuously"; const char kEnableSampling[] = "enable-sampling"; -void ReadFile( - const base::FilePath& path, - const base::Callback<void(const scoped_refptr<base::RefCountedString>&)> - callback) { - std::string trace_data; - if (!base::ReadFileToString(path, &trace_data)) - LOG(ERROR) << "Failed to read file: " << path.value(); - base::DeleteFile(path, false); - BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, - base::Bind(callback, make_scoped_refptr( - base::RefCountedString::TakeString(&trace_data)))); -} - } // namespace DevToolsTracingHandler::DevToolsTracingHandler() - : weak_factory_(this) { + : is_running_(false) { RegisterCommandHandler(devtools::Tracing::start::kName, base::Bind(&DevToolsTracingHandler::OnStart, base::Unretained(this))); @@ -55,60 +38,28 @@ DevToolsTracingHandler::DevToolsTracingHandler() DevToolsTracingHandler::~DevToolsTracingHandler() { } -void DevToolsTracingHandler::BeginReadingRecordingResult( - const base::FilePath& path) { - BrowserThread::PostTask( - BrowserThread::FILE, FROM_HERE, - base::Bind(&ReadFile, path, - base::Bind(&DevToolsTracingHandler::ReadRecordingResult, - weak_factory_.GetWeakPtr()))); -} - -void DevToolsTracingHandler::ReadRecordingResult( - const scoped_refptr<base::RefCountedString>& trace_data) { - if (trace_data->data().size()) { - scoped_ptr<base::Value> trace_value(base::JSONReader::Read( - trace_data->data())); - DictionaryValue* dictionary = NULL; - bool ok = trace_value->GetAsDictionary(&dictionary); - DCHECK(ok); - ListValue* list = NULL; - ok = dictionary->GetList("traceEvents", &list); - DCHECK(ok); - std::string buffer; - for (size_t i = 0; i < list->GetSize(); ++i) { - std::string item; - base::Value* item_value; - list->Get(i, &item_value); - base::JSONWriter::Write(item_value, &item); - if (buffer.size()) - buffer.append(","); - buffer.append(item); - if (i % 1000 == 0) { - OnTraceDataCollected(buffer); - buffer.clear(); - } - } - if (buffer.size()) - OnTraceDataCollected(buffer); - } - +void DevToolsTracingHandler::OnEndTracingComplete() { + is_running_ = false; SendNotification(devtools::Tracing::tracingComplete::kName, NULL); } void DevToolsTracingHandler::OnTraceDataCollected( - const std::string& trace_fragment) { - // Hand-craft protocol notification message so we can substitute JSON - // that we already got as string as a bare object, not a quoted string. - std::string message = base::StringPrintf( - "{ \"method\": \"%s\", \"params\": { \"%s\": [ %s ] } }", - devtools::Tracing::dataCollected::kName, - devtools::Tracing::dataCollected::kValue, - trace_fragment.c_str()); - SendRawMessage(message); + const scoped_refptr<base::RefCountedString>& trace_fragment) { + if (is_running_) { + // Hand-craft protocol notification message so we can substitute JSON + // that we already got as string as a bare object, not a quoted string. + std::string message = base::StringPrintf( + "{ \"method\": \"%s\", \"params\": { \"%s\": [ %s ] } }", + devtools::Tracing::dataCollected::kName, + devtools::Tracing::dataCollected::kValue, + trace_fragment->data().c_str()); + SendRawMessage(message); + } } -TracingController::Options DevToolsTracingHandler::TraceOptionsFromString( +// Note, if you add more options here you also need to update: +// base/debug/trace_event_impl:TraceOptionsFromString +base::debug::TraceLog::Options DevToolsTracingHandler::TraceOptionsFromString( const std::string& options) { std::vector<std::string> split; std::vector<std::string>::iterator iter; @@ -117,14 +68,18 @@ TracingController::Options DevToolsTracingHandler::TraceOptionsFromString( base::SplitString(options, ',', &split); for (iter = split.begin(); iter != split.end(); ++iter) { if (*iter == kRecordUntilFull) { - ret &= ~TracingController::RECORD_CONTINUOUSLY; + ret |= base::debug::TraceLog::RECORD_UNTIL_FULL; } else if (*iter == kRecordContinuously) { - ret |= TracingController::RECORD_CONTINUOUSLY; + ret |= base::debug::TraceLog::RECORD_CONTINUOUSLY; } else if (*iter == kEnableSampling) { - ret |= TracingController::ENABLE_SAMPLING; + ret |= base::debug::TraceLog::ENABLE_SAMPLING; } } - return static_cast<TracingController::Options>(ret); + if (!(ret & base::debug::TraceLog::RECORD_UNTIL_FULL) && + !(ret & base::debug::TraceLog::RECORD_CONTINUOUSLY)) + ret |= base::debug::TraceLog::RECORD_UNTIL_FULL; + + return static_cast<base::debug::TraceLog::Options>(ret); } scoped_refptr<DevToolsProtocol::Response> @@ -135,26 +90,23 @@ DevToolsTracingHandler::OnStart( if (params) params->GetString(devtools::Tracing::start::kCategories, &categories); - TracingController::Options options = TracingController::DEFAULT_OPTIONS; + base::debug::TraceLog::Options options = + base::debug::TraceLog::RECORD_UNTIL_FULL; if (params && params->HasKey(devtools::Tracing::start::kTraceOptions)) { std::string options_param; params->GetString(devtools::Tracing::start::kTraceOptions, &options_param); options = TraceOptionsFromString(options_param); } - TracingController::GetInstance()->EnableRecording( - categories, options, - TracingController::EnableRecordingDoneCallback()); + TraceController::GetInstance()->BeginTracing(this, categories, options); + is_running_ = true; return command->SuccessResponse(NULL); } scoped_refptr<DevToolsProtocol::Response> DevToolsTracingHandler::OnEnd( scoped_refptr<DevToolsProtocol::Command> command) { - TracingController::GetInstance()->DisableRecording( - base::FilePath(), - base::Bind(&DevToolsTracingHandler::BeginReadingRecordingResult, - weak_factory_.GetWeakPtr())); + TraceController::GetInstance()->EndTracingAsync(this); return command->SuccessResponse(NULL); } diff --git a/content/browser/devtools/devtools_tracing_handler.h b/content/browser/devtools/devtools_tracing_handler.h index b551e75..43cd615 100644 --- a/content/browser/devtools/devtools_tracing_handler.h +++ b/content/browser/devtools/devtools_tracing_handler.h @@ -5,36 +5,36 @@ #ifndef CONTENT_BROWSER_DEVTOOLS_DEVTOOLS_TRACING_HANDLER_H_ #define CONTENT_BROWSER_DEVTOOLS_DEVTOOLS_TRACING_HANDLER_H_ -#include "base/memory/weak_ptr.h" +#include "base/debug/trace_event.h" #include "content/browser/devtools/devtools_protocol.h" -#include "content/public/browser/tracing_controller.h" - -namespace base { -class RefCountedString; -} +#include "content/public/browser/trace_subscriber.h" namespace content { // This class bridges DevTools remote debugging server with the trace // infrastructure. -class DevToolsTracingHandler : public DevToolsProtocol::Handler { +class DevToolsTracingHandler + : public TraceSubscriber, + public DevToolsProtocol::Handler { public: DevToolsTracingHandler(); virtual ~DevToolsTracingHandler(); - private: - void BeginReadingRecordingResult(const base::FilePath& path); - void ReadRecordingResult(const scoped_refptr<base::RefCountedString>& result); - void OnTraceDataCollected(const std::string& trace_fragment); + // TraceSubscriber: + virtual void OnEndTracingComplete() OVERRIDE;; + virtual void OnTraceDataCollected( + const scoped_refptr<base::RefCountedString>& trace_fragment) OVERRIDE; + private: scoped_refptr<DevToolsProtocol::Response> OnStart( scoped_refptr<DevToolsProtocol::Command> command); scoped_refptr<DevToolsProtocol::Response> OnEnd( scoped_refptr<DevToolsProtocol::Command> command); - TracingController::Options TraceOptionsFromString(const std::string& options); + base::debug::TraceLog::Options TraceOptionsFromString( + const std::string& options); - base::WeakPtrFactory<DevToolsTracingHandler> weak_factory_; + bool is_running_; DISALLOW_COPY_AND_ASSIGN(DevToolsTracingHandler); }; diff --git a/content/browser/renderer_host/render_process_host_impl.cc b/content/browser/renderer_host/render_process_host_impl.cc index 90b14e6..da44fd8 100644 --- a/content/browser/renderer_host/render_process_host_impl.cc +++ b/content/browser/renderer_host/render_process_host_impl.cc @@ -101,6 +101,7 @@ #include "content/browser/speech/speech_recognition_dispatcher_host.h" #include "content/browser/storage_partition_impl.h" #include "content/browser/streams/stream_context.h" +#include "content/browser/tracing/trace_controller_impl.h" #include "content/browser/tracing/trace_message_filter.h" #include "content/browser/vibration/vibration_message_filter.h" #include "content/browser/webui/web_ui_controller_factory_registry.h" diff --git a/content/browser/tracing/trace_controller_impl.cc b/content/browser/tracing/trace_controller_impl.cc new file mode 100644 index 0000000..061e508 --- /dev/null +++ b/content/browser/tracing/trace_controller_impl.cc @@ -0,0 +1,371 @@ +// Copyright 2013 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 "content/browser/tracing/trace_controller_impl.h" + +#include "base/bind.h" +#include "base/command_line.h" +#include "base/debug/trace_event.h" +#include "base/strings/string_number_conversions.h" +#include "components/tracing/tracing_messages.h" +#include "content/browser/tracing/trace_message_filter.h" +#include "content/browser/tracing/trace_subscriber_stdio.h" +#include "content/common/child_process_messages.h" +#include "content/public/browser/browser_message_filter.h" +#include "content/public/common/content_switches.h" + +using base::debug::TraceLog; + +namespace content { + +namespace { + +base::LazyInstance<TraceControllerImpl>::Leaky g_controller = + LAZY_INSTANCE_INITIALIZER; + +} // namespace + +TraceController* TraceController::GetInstance() { + return TraceControllerImpl::GetInstance(); +} + +TraceControllerImpl::TraceControllerImpl() : + subscriber_(NULL), + pending_end_ack_count_(0), + pending_bpf_ack_count_(0), + maximum_bpf_(0.0f), + is_tracing_(false), + is_get_category_groups_(false), + category_filter_( + base::debug::CategoryFilter::kDefaultCategoryFilterString) { + TraceLog::GetInstance()->SetNotificationCallback( + base::Bind(&TraceControllerImpl::OnTraceNotification, + base::Unretained(this))); +} + +TraceControllerImpl::~TraceControllerImpl() { + // No need to SetNotificationCallback(nil) on the TraceLog since this is a + // Leaky instance. + NOTREACHED(); +} + +TraceControllerImpl* TraceControllerImpl::GetInstance() { + return g_controller.Pointer(); +} + +bool TraceControllerImpl::GetKnownCategoryGroupsAsync( + TraceSubscriber* subscriber) { + DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI)); + + // Known categories come back from child processes with the EndTracingAck + // message. So to get known categories, just begin and end tracing immediately + // afterwards. This will ping all the child processes for categories. + is_get_category_groups_ = true; + bool success = BeginTracing(subscriber, "*", + TraceLog::GetInstance()->trace_options()) && + EndTracingAsync(subscriber); + is_get_category_groups_ = success; + return success; +} + +bool TraceControllerImpl::BeginTracing(TraceSubscriber* subscriber, + const std::string& category_patterns, + base::debug::TraceLog::Options options) { + DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI)); + + if (!can_begin_tracing(subscriber)) + return false; + +#if defined(OS_ANDROID) + if (!is_get_category_groups_) + TraceLog::GetInstance()->AddClockSyncMetadataEvent(); +#endif + + // Enable tracing + TraceLog::GetInstance()->SetEnabled( + base::debug::CategoryFilter(category_patterns), options); + + OnTracingBegan(subscriber); + + return true; +} + +bool TraceControllerImpl::EndTracingAsync(TraceSubscriber* subscriber) { + DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI)); + + if (!can_end_tracing() || subscriber != subscriber_) + return false; + + // Disable local trace early to avoid traces during end-tracing process from + // interfering with the process. + TraceLog::GetInstance()->SetDisabled(); + +#if defined(OS_ANDROID) + if (!is_get_category_groups_) + TraceLog::GetInstance()->AddClockSyncMetadataEvent(); +#endif + + // There could be a case where there are no child processes and filters_ + // is empty. In that case we can immediately tell the subscriber that tracing + // has ended. To avoid recursive calls back to the subscriber, we will just + // use the existing asynchronous OnEndTracingAck code. + // Count myself (local trace) in pending_end_ack_count_, acked below. + pending_end_ack_count_ = filters_.size() + 1; + + // Handle special case of zero child processes. + if (pending_end_ack_count_ == 1) { + // Ack asynchronously now, because we don't have any children to wait for. + std::vector<std::string> category_groups; + TraceLog::GetInstance()->GetKnownCategoryGroups(&category_groups); + BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, + base::Bind(&TraceControllerImpl::OnEndTracingAck, + base::Unretained(this), category_groups)); + } + + // Notify all child processes. + for (FilterMap::iterator it = filters_.begin(); it != filters_.end(); ++it) { + it->get()->SendEndTracing(); + } + + return true; +} + +bool TraceControllerImpl::GetTraceBufferPercentFullAsync( + TraceSubscriber* subscriber) { + DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI)); + + if (!can_get_buffer_percent_full() || subscriber != subscriber_) + return false; + + maximum_bpf_ = 0.0f; + pending_bpf_ack_count_ = filters_.size() + 1; + + // Handle special case of zero child processes. + if (pending_bpf_ack_count_ == 1) { + // Ack asynchronously now, because we don't have any children to wait for. + float bpf = TraceLog::GetInstance()->GetBufferPercentFull(); + BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, + base::Bind(&TraceControllerImpl::OnTraceBufferPercentFullReply, + base::Unretained(this), bpf)); + } + + // Message all child processes. + for (FilterMap::iterator it = filters_.begin(); it != filters_.end(); ++it) { + it->get()->SendGetTraceBufferPercentFull(); + } + + return true; +} + +bool TraceControllerImpl::SetWatchEvent(TraceSubscriber* subscriber, + const std::string& category_name, + const std::string& event_name) { + DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI)); + if (subscriber != subscriber_) + return false; + + watch_category_ = category_name; + watch_name_ = event_name; + + TraceLog::GetInstance()->SetWatchEvent(category_name, event_name); + for (FilterMap::iterator it = filters_.begin(); it != filters_.end(); ++it) + it->get()->SendSetWatchEvent(category_name, event_name); + + return true; +} + +bool TraceControllerImpl::CancelWatchEvent(TraceSubscriber* subscriber) { + DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI)); + if (subscriber != subscriber_) + return false; + + watch_category_.clear(); + watch_name_.clear(); + + TraceLog::GetInstance()->CancelWatchEvent(); + for (FilterMap::iterator it = filters_.begin(); it != filters_.end(); ++it) + it->get()->SendCancelWatchEvent(); + + return true; +} + +void TraceControllerImpl::CancelSubscriber(TraceSubscriber* subscriber) { + DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI)); + + if (subscriber == subscriber_) { + subscriber_ = NULL; + // End tracing if necessary. + if (is_tracing_ && pending_end_ack_count_ == 0) + EndTracingAsync(NULL); + } +} + +void TraceControllerImpl::AddFilter(TraceMessageFilter* filter) { + if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) { + BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, + base::Bind(&TraceControllerImpl::AddFilter, base::Unretained(this), + make_scoped_refptr(filter))); + return; + } + + filters_.insert(filter); + if (is_tracing_enabled()) { + std::string cf_str = category_filter_.ToString(); + filter->SendBeginTracing(cf_str, trace_options_); + if (!watch_category_.empty()) + filter->SendSetWatchEvent(watch_category_, watch_name_); + } +} + +void TraceControllerImpl::RemoveFilter(TraceMessageFilter* filter) { + if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) { + BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, + base::Bind(&TraceControllerImpl::RemoveFilter, base::Unretained(this), + make_scoped_refptr(filter))); + return; + } + + filters_.erase(filter); +} + +void TraceControllerImpl::OnTracingBegan(TraceSubscriber* subscriber) { + is_tracing_ = true; + + subscriber_ = subscriber; + + category_filter_ = TraceLog::GetInstance()->GetCurrentCategoryFilter(); + trace_options_ = TraceLog::GetInstance()->trace_options(); + + // Notify all child processes. + for (FilterMap::iterator it = filters_.begin(); it != filters_.end(); ++it) { + it->get()->SendBeginTracing(category_filter_.ToString(), trace_options_); + } +} + +void TraceControllerImpl::OnEndTracingAck( + const std::vector<std::string>& known_category_groups) { + if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) { + BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, + base::Bind(&TraceControllerImpl::OnEndTracingAck, + base::Unretained(this), known_category_groups)); + return; + } + + // Merge known_category_groups with known_category_groups_ + known_category_groups_.insert(known_category_groups.begin(), + known_category_groups.end()); + + if (pending_end_ack_count_ == 0) + return; + + + if (--pending_end_ack_count_ == 1) { + // All acks from subprocesses have been received. Now flush the local trace. + // During or after this call, our OnLocalTraceDataCollected will be + // called with the last of the local trace data. + TraceLog::GetInstance()->Flush( + base::Bind(&TraceControllerImpl::OnLocalTraceDataCollected, + base::Unretained(this))); + } + + if (pending_end_ack_count_ == 0) { + // All acks (including from the subprocesses and the local trace) have been + // received. + is_tracing_ = false; + + // Trigger callback if one is set. + if (subscriber_) { + if (is_get_category_groups_) + subscriber_->OnKnownCategoriesCollected(known_category_groups_); + else + subscriber_->OnEndTracingComplete(); + // Clear subscriber so that others can use TraceController. + subscriber_ = NULL; + } + + is_get_category_groups_ = false; + } +} + +void TraceControllerImpl::OnTraceDataCollected( + const scoped_refptr<base::RefCountedString>& events_str_ptr) { + // OnTraceDataCollected may be called from any browser thread, either by the + // local event trace system or from child processes via TraceMessageFilter. + if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) { + BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, + base::Bind(&TraceControllerImpl::OnTraceDataCollected, + base::Unretained(this), events_str_ptr)); + return; + } + + // Drop trace events if we are just getting categories. + if (subscriber_ && !is_get_category_groups_) + subscriber_->OnTraceDataCollected(events_str_ptr); +} + +void TraceControllerImpl::OnLocalTraceDataCollected( + const scoped_refptr<base::RefCountedString>& events_str_ptr, + bool has_more_events) { + if (events_str_ptr->data().size()) + OnTraceDataCollected(events_str_ptr); + + if (!has_more_events) { + // Simulate an EndTrackingAck for the local trace. + std::vector<std::string> category_groups; + TraceLog::GetInstance()->GetKnownCategoryGroups(&category_groups); + OnEndTracingAck(category_groups); + } +} + +void TraceControllerImpl::OnTraceNotification(int notification) { + // OnTraceNotification may be called from any browser thread, either by the + // local event trace system or from child processes via TraceMessageFilter. + if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) { + BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, + base::Bind(&TraceControllerImpl::OnTraceNotification, + base::Unretained(this), notification)); + return; + } + + if (notification & base::debug::TraceLog::TRACE_BUFFER_FULL) { + // EndTracingAsync may return false if tracing is already in the process + // of being ended. That is ok. + EndTracingAsync(subscriber_); + } + if (notification & base::debug::TraceLog::EVENT_WATCH_NOTIFICATION) { + if (subscriber_) + subscriber_->OnEventWatchNotification(); + } +} + +void TraceControllerImpl::OnTraceBufferPercentFullReply(float percent_full) { + if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) { + BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, + base::Bind(&TraceControllerImpl::OnTraceBufferPercentFullReply, + base::Unretained(this), percent_full)); + return; + } + + if (pending_bpf_ack_count_ == 0) + return; + + maximum_bpf_ = (maximum_bpf_ > percent_full)? maximum_bpf_ : percent_full; + + if (--pending_bpf_ack_count_ == 0) { + // Trigger callback if one is set. + if (subscriber_) + subscriber_->OnTraceBufferPercentFullReply(maximum_bpf_); + } + + if (pending_bpf_ack_count_ == 1) { + // The last ack represents local trace, so we need to ack it now. Note that + // this code only executes if there were child processes. + float bpf = TraceLog::GetInstance()->GetBufferPercentFull(); + BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, + base::Bind(&TraceControllerImpl::OnTraceBufferPercentFullReply, + base::Unretained(this), bpf)); + } +} + +} // namespace content diff --git a/content/browser/tracing/trace_controller_impl.h b/content/browser/tracing/trace_controller_impl.h new file mode 100644 index 0000000..fc993be --- /dev/null +++ b/content/browser/tracing/trace_controller_impl.h @@ -0,0 +1,105 @@ +// Copyright 2013 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. + +#ifndef CONTENT_BROWSER_TRACING_TRACE_CONTROLLER_IMPL_H_ +#define CONTENT_BROWSER_TRACING_TRACE_CONTROLLER_IMPL_H_ + +#include <set> +#include <string> +#include <vector> + +#include "base/debug/trace_event.h" +#include "base/lazy_instance.h" +#include "content/public/browser/trace_controller.h" + +class CommandLine; + +namespace content { +class TraceMessageFilter; + +class TraceControllerImpl : public TraceController { + public: + static TraceControllerImpl* GetInstance(); + + // TraceController implementation: + virtual bool BeginTracing(TraceSubscriber* subscriber, + const std::string& category_patterns, + base::debug::TraceLog::Options options) OVERRIDE; + virtual bool EndTracingAsync(TraceSubscriber* subscriber) OVERRIDE; + virtual bool GetTraceBufferPercentFullAsync( + TraceSubscriber* subscriber) OVERRIDE; + virtual bool SetWatchEvent(TraceSubscriber* subscriber, + const std::string& category_name, + const std::string& event_name) OVERRIDE; + virtual bool CancelWatchEvent(TraceSubscriber* subscriber) OVERRIDE; + virtual void CancelSubscriber(TraceSubscriber* subscriber) OVERRIDE; + virtual bool GetKnownCategoryGroupsAsync(TraceSubscriber* subscriber) + OVERRIDE; + + private: + typedef std::set<scoped_refptr<TraceMessageFilter> > FilterMap; + + friend struct base::DefaultLazyInstanceTraits<TraceControllerImpl>; + friend class TraceMessageFilter; + + TraceControllerImpl(); + virtual ~TraceControllerImpl(); + + bool is_tracing_enabled() const { + return can_end_tracing(); + } + + bool can_end_tracing() const { + return is_tracing_ && pending_end_ack_count_ == 0; + } + + // Can get Buffer Percent Full + bool can_get_buffer_percent_full() const { + return is_tracing_ && + pending_end_ack_count_ == 0 && + pending_bpf_ack_count_ == 0; + } + + bool can_begin_tracing(TraceSubscriber* subscriber) const { + return !is_tracing_ && + (subscriber_ == NULL || subscriber == subscriber_); + } + + // Methods for use by TraceMessageFilter. + + void AddFilter(TraceMessageFilter* filter); + void RemoveFilter(TraceMessageFilter* filter); + void OnTracingBegan(TraceSubscriber* subscriber); + void OnEndTracingAck(const std::vector<std::string>& known_category_groups); + void OnTraceDataCollected( + const scoped_refptr<base::RefCountedString>& events_str_ptr); + void OnTraceNotification(int notification); + void OnTraceBufferPercentFullReply(float percent_full); + + // Callback of TraceLog::Flush() for the local trace. + void OnLocalTraceDataCollected( + const scoped_refptr<base::RefCountedString>& events_str_ptr, + bool has_more_events); + + FilterMap filters_; + TraceSubscriber* subscriber_; + // Pending acks for EndTracingAsync: + int pending_end_ack_count_; + // Pending acks for GetTraceBufferPercentFullAsync: + int pending_bpf_ack_count_; + float maximum_bpf_; + bool is_tracing_; + bool is_get_category_groups_; + std::set<std::string> known_category_groups_; + std::string watch_category_; + std::string watch_name_; + base::debug::TraceLog::Options trace_options_; + base::debug::CategoryFilter category_filter_; + + DISALLOW_COPY_AND_ASSIGN(TraceControllerImpl); +}; + +} // namespace content + +#endif // CONTENT_BROWSER_TRACING_TRACE_CONTROLLER_IMPL_H_ diff --git a/content/browser/tracing/trace_message_filter.cc b/content/browser/tracing/trace_message_filter.cc index 35f23dc..00fffb9 100644 --- a/content/browser/tracing/trace_message_filter.cc +++ b/content/browser/tracing/trace_message_filter.cc @@ -5,6 +5,7 @@ #include "content/browser/tracing/trace_message_filter.h" #include "components/tracing/tracing_messages.h" +#include "content/browser/tracing/trace_controller_impl.h" #include "content/browser/tracing/tracing_controller_impl.h" namespace content { @@ -16,8 +17,6 @@ TraceMessageFilter::TraceMessageFilter() : is_awaiting_buffer_percent_full_ack_(false) { } -TraceMessageFilter::~TraceMessageFilter() {} - void TraceMessageFilter::OnChannelClosing() { if (has_child_) { if (is_awaiting_end_ack_) @@ -29,7 +28,8 @@ void TraceMessageFilter::OnChannelClosing() { if (is_awaiting_buffer_percent_full_ack_) OnTraceBufferPercentFullReply(0.0f); - TracingControllerImpl::GetInstance()->RemoveTraceMessageFilter(this); + TraceControllerImpl::GetInstance()->RemoveFilter(this); + TracingControllerImpl::GetInstance()->RemoveFilter(this); } } @@ -47,8 +47,8 @@ bool TraceMessageFilter::OnMessageReceived(const IPC::Message& message, OnTraceDataCollected) IPC_MESSAGE_HANDLER(TracingHostMsg_MonitoringTraceDataCollected, OnMonitoringTraceDataCollected) - IPC_MESSAGE_HANDLER(TracingHostMsg_WatchEventMatched, - OnWatchEventMatched) + IPC_MESSAGE_HANDLER(TracingHostMsg_TraceNotification, + OnTraceNotification) IPC_MESSAGE_HANDLER(TracingHostMsg_TraceBufferPercentFullReply, OnTraceBufferPercentFullReply) IPC_MESSAGE_UNHANDLED(handled = false) @@ -109,9 +109,12 @@ void TraceMessageFilter::SendCancelWatchEvent() { Send(new TracingMsg_CancelWatchEvent); } +TraceMessageFilter::~TraceMessageFilter() {} + void TraceMessageFilter::OnChildSupportsTracing() { has_child_ = true; - TracingControllerImpl::GetInstance()->AddTraceMessageFilter(this); + TraceControllerImpl::GetInstance()->AddFilter(this); + TracingControllerImpl::GetInstance()->AddFilter(this); } void TraceMessageFilter::OnEndTracingAck( @@ -120,6 +123,7 @@ void TraceMessageFilter::OnEndTracingAck( // child process is compromised. if (is_awaiting_end_ack_) { is_awaiting_end_ack_ = false; + TraceControllerImpl::GetInstance()->OnEndTracingAck(known_categories); TracingControllerImpl::GetInstance()->OnDisableRecordingAcked( known_categories); } else { @@ -141,6 +145,7 @@ void TraceMessageFilter::OnCaptureMonitoringSnapshotAcked() { void TraceMessageFilter::OnTraceDataCollected(const std::string& data) { scoped_refptr<base::RefCountedString> data_ptr(new base::RefCountedString()); data_ptr->data() = data; + TraceControllerImpl::GetInstance()->OnTraceDataCollected(data_ptr); TracingControllerImpl::GetInstance()->OnTraceDataCollected(data_ptr); } @@ -152,13 +157,15 @@ void TraceMessageFilter::OnMonitoringTraceDataCollected( data_ptr); } -void TraceMessageFilter::OnWatchEventMatched() { - TracingControllerImpl::GetInstance()->OnWatchEventMatched(); +void TraceMessageFilter::OnTraceNotification(int notification) { + TraceControllerImpl::GetInstance()->OnTraceNotification(notification); } void TraceMessageFilter::OnTraceBufferPercentFullReply(float percent_full) { if (is_awaiting_buffer_percent_full_ack_) { is_awaiting_buffer_percent_full_ack_ = false; + TraceControllerImpl::GetInstance()->OnTraceBufferPercentFullReply( + percent_full); TracingControllerImpl::GetInstance()->OnTraceBufferPercentFullReply( percent_full); } else { diff --git a/content/browser/tracing/trace_message_filter.h b/content/browser/tracing/trace_message_filter.h index 0f9e18e..c8290d9 100644 --- a/content/browser/tracing/trace_message_filter.h +++ b/content/browser/tracing/trace_message_filter.h @@ -45,7 +45,7 @@ class TraceMessageFilter : public BrowserMessageFilter { void OnChildSupportsTracing(); void OnEndTracingAck(const std::vector<std::string>& known_categories); void OnCaptureMonitoringSnapshotAcked(); - void OnWatchEventMatched(); + void OnTraceNotification(int notification); void OnTraceBufferPercentFullReply(float percent_full); void OnTraceDataCollected(const std::string& data); void OnMonitoringTraceDataCollected(const std::string& data); diff --git a/content/browser/tracing/trace_subscriber_stdio.cc b/content/browser/tracing/trace_subscriber_stdio.cc new file mode 100644 index 0000000..50bc361 --- /dev/null +++ b/content/browser/tracing/trace_subscriber_stdio.cc @@ -0,0 +1,201 @@ +// Copyright 2013 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 "content/browser/tracing/trace_subscriber_stdio.h" + +#include "base/bind.h" +#include "base/debug/trace_event.h" +#include "base/file_util.h" +#include "base/logging.h" +#include "base/threading/sequenced_worker_pool.h" +#include "content/public/browser/browser_thread.h" + +namespace content { + +// All method calls on this class are done on a SequencedWorkerPool thread. +class TraceSubscriberStdio::TraceSubscriberStdioWorker + : public base::RefCountedThreadSafe<TraceSubscriberStdioWorker> { + public: + TraceSubscriberStdioWorker(const base::FilePath& path, + FileType file_type, + bool has_system_trace) + : path_(path), + file_type_(file_type), + has_system_trace_(has_system_trace), + file_(0), + needs_comma_(false), + wrote_trace_(false), + has_pending_system_trace_(false), + wrote_system_trace_(false) {} + + void OnTraceStart() { + DCHECK(!file_); + file_ = file_util::OpenFile(path_, "w+"); + if (!IsValid()) { + LOG(ERROR) << "Failed to open performance trace file: " << path_.value(); + return; + } + + VLOG(0) << "Logging performance trace to file: " << path_.value(); + if (file_type_ == FILE_TYPE_PROPERTY_LIST) + WriteString("{\"traceEvents\":"); + WriteString("["); + } + + void OnTraceData(const scoped_refptr<base::RefCountedString>& data_ptr) { + if (!IsValid()) + return; + DCHECK(!data_ptr->data().empty()); + if (needs_comma_) + WriteString(","); + WriteString(data_ptr->data()); + needs_comma_ = true; + } + + void OnSystemTraceData( + const scoped_refptr<base::RefCountedString>& data_ptr) { + if (wrote_trace_) { + WriteSystemTrace(data_ptr); + End(); + } else { + pending_system_trace_ = data_ptr; + has_pending_system_trace_ = true; + } + } + + void OnTraceEnd() { + if (!IsValid()) + return; + WriteString("]"); + + wrote_trace_ = true; + + if (!has_system_trace_ || wrote_system_trace_) { + End(); + return; + } + + WriteString(","); + if (has_pending_system_trace_) { + WriteSystemTrace(pending_system_trace_); + End(); + } + } + + private: + friend class base::RefCountedThreadSafe<TraceSubscriberStdioWorker>; + + ~TraceSubscriberStdioWorker() { + CloseFile(); + } + + bool IsValid() const { + return file_ && (0 == ferror(file_)); + } + + void CloseFile() { + if (file_) { + fclose(file_); + file_ = 0; + + } + } + + void End() { + if (file_type_ == FILE_TYPE_PROPERTY_LIST) + WriteString("}"); + CloseFile(); + } + + void WriteSystemTrace(const scoped_refptr<base::RefCountedString>& data_ptr) { + // Newlines need to be replaced with the string "\n" to be parsed correctly. + // Double quotes need to be replaced with the string "\"". + // System logs are ASCII. + const std::string& data = data_ptr->data(); + const char* chars = data.c_str(); + WriteString("\"systemTraceEvents\":\""); + size_t old_index = 0; + for (size_t new_index = data.find_first_of("\n\""); + std::string::npos != new_index; + old_index = new_index + 1, + new_index = data.find_first_of("\n\"", old_index)) { + WriteChars(chars + old_index, new_index - old_index); + if (chars[new_index] == '\n') + WriteChars("\\n", 2); + else + WriteChars("\\\"", 2); + } + WriteChars(chars + old_index, data.size() - old_index); + WriteString("\""); + wrote_system_trace_ = true; + } + + void WriteChars(const char* output_chars, size_t size) { + if (size == 0) + return; + + if (IsValid()) { + size_t written = fwrite(output_chars, 1, size, file_); + if (written != size) { + LOG(ERROR) << "Error " << ferror(file_) << " in fwrite() to trace file"; + CloseFile(); + } + } + } + + void WriteString(const std::string& output_str) { + WriteChars(output_str.data(), output_str.size()); + } + + base::FilePath path_; + const FileType file_type_; + const bool has_system_trace_; + FILE* file_; + bool needs_comma_; + bool wrote_trace_; + bool has_pending_system_trace_; + bool wrote_system_trace_; + scoped_refptr<base::RefCountedString> pending_system_trace_; + DISALLOW_COPY_AND_ASSIGN(TraceSubscriberStdioWorker); +}; + +TraceSubscriberStdio::TraceSubscriberStdio(const base::FilePath& path, + FileType file_type, + bool has_system_trace) + : worker_(new TraceSubscriberStdioWorker(path, + file_type, + has_system_trace)) { + if (has_system_trace) + CHECK_EQ(FILE_TYPE_PROPERTY_LIST, file_type); + BrowserThread::PostBlockingPoolSequencedTask( + __FILE__, FROM_HERE, + base::Bind(&TraceSubscriberStdioWorker::OnTraceStart, worker_)); +} + +TraceSubscriberStdio::~TraceSubscriberStdio() { +} + +void TraceSubscriberStdio::OnEndTracingComplete() { + BrowserThread::PostBlockingPoolSequencedTask( + __FILE__, FROM_HERE, + base::Bind(&TraceSubscriberStdioWorker::OnTraceEnd, worker_)); +} + +void TraceSubscriberStdio::OnTraceDataCollected( + const scoped_refptr<base::RefCountedString>& data_ptr) { + BrowserThread::PostBlockingPoolSequencedTask( + __FILE__, FROM_HERE, + base::Bind(&TraceSubscriberStdioWorker::OnTraceData, worker_, data_ptr)); +} + +void TraceSubscriberStdio::OnEndSystemTracing( + const scoped_refptr<base::RefCountedString>& events_str_ptr) { + BrowserThread::PostBlockingPoolSequencedTask( + __FILE__, FROM_HERE, + base::Bind(&TraceSubscriberStdioWorker::OnSystemTraceData, + worker_, + events_str_ptr)); +} + +} // namespace content diff --git a/content/browser/tracing/trace_subscriber_stdio.h b/content/browser/tracing/trace_subscriber_stdio.h new file mode 100644 index 0000000..95c8f9f --- /dev/null +++ b/content/browser/tracing/trace_subscriber_stdio.h @@ -0,0 +1,57 @@ +// Copyright 2013 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. + +#ifndef CONTENT_BROWSER_TRACING_TRACE_SUBSCRIBER_STDIO_H_ +#define CONTENT_BROWSER_TRACING_TRACE_SUBSCRIBER_STDIO_H_ + +#include <string> + +#include "base/compiler_specific.h" +#include "content/public/browser/trace_subscriber.h" +#include "content/common/content_export.h" + +namespace base { +class FilePath; +} + +namespace content { + +// Stdio implementation of TraceSubscriber. Use this to write traces to a file. +class CONTENT_EXPORT TraceSubscriberStdio + : NON_EXPORTED_BASE(public TraceSubscriber) { + public: + enum FileType { + // Output file as array, representing trace events: + // [event1, event2, ...] + FILE_TYPE_ARRAY, + // Output file as property list with one or two items: + // {traceEvents: [event1, event2, ...], + // systemTraceEvents: "event1\nevent2\n..." // optional} + FILE_TYPE_PROPERTY_LIST + }; + + // has_system_trace indicates whether system trace events are expected. + TraceSubscriberStdio(const base::FilePath& path, + FileType file_type, + bool has_system_trace); + virtual ~TraceSubscriberStdio(); + + // Implementation of TraceSubscriber + virtual void OnEndTracingComplete() OVERRIDE; + virtual void OnTraceDataCollected( + const scoped_refptr<base::RefCountedString>& data_ptr) OVERRIDE; + + // To be used as callback to DebugDaemonClient::RequestStopSystemTracing(). + virtual void OnEndSystemTracing( + const scoped_refptr<base::RefCountedString>& events_str_ptr); + + private: + class TraceSubscriberStdioWorker; + scoped_refptr<TraceSubscriberStdioWorker> worker_; + DISALLOW_COPY_AND_ASSIGN(TraceSubscriberStdio); +}; + +} // namespace content + +#endif // CONTENT_BROWSER_TRACING_TRACE_SUBSCRIBER_STDIO_H_ diff --git a/content/browser/tracing/trace_subscriber_stdio_unittest.cc b/content/browser/tracing/trace_subscriber_stdio_unittest.cc new file mode 100644 index 0000000..2364299 --- /dev/null +++ b/content/browser/tracing/trace_subscriber_stdio_unittest.cc @@ -0,0 +1,132 @@ +// Copyright 2013 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 "content/browser/tracing/trace_subscriber_stdio.h" + +#include "base/file_util.h" +#include "base/files/scoped_temp_dir.h" +#include "base/threading/sequenced_worker_pool.h" +#include "content/public/browser/browser_thread.h" +#include "testing/gtest/include/gtest/gtest.h" + +namespace content { + +class TraceSubscriberStdioTest : public ::testing::Test {}; + +TEST_F(TraceSubscriberStdioTest, CanWriteArray) { + base::ScopedTempDir trace_dir; + ASSERT_TRUE(trace_dir.CreateUniqueTempDir()); + base::FilePath trace_file(trace_dir.path().AppendASCII("trace.txt")); + { + TraceSubscriberStdio subscriber(trace_file, + TraceSubscriberStdio::FILE_TYPE_ARRAY, + false); + + std::string foo("foo"); + subscriber.OnTraceDataCollected( + make_scoped_refptr(base::RefCountedString::TakeString(&foo))); + + std::string bar("bar"); + subscriber.OnTraceDataCollected( + make_scoped_refptr(base::RefCountedString::TakeString(&bar))); + + subscriber.OnEndTracingComplete(); + } + BrowserThread::GetBlockingPool()->FlushForTesting(); + std::string result; + EXPECT_TRUE(base::ReadFileToString(trace_file, &result)); + EXPECT_EQ("[foo,bar]", result); +} + +TEST_F(TraceSubscriberStdioTest, CanWritePropertyList) { + base::ScopedTempDir trace_dir; + ASSERT_TRUE(trace_dir.CreateUniqueTempDir()); + base::FilePath trace_file(trace_dir.path().AppendASCII("trace.txt")); + { + TraceSubscriberStdio subscriber( + trace_file, + TraceSubscriberStdio::FILE_TYPE_PROPERTY_LIST, + false); + + std::string foo("foo"); + subscriber.OnTraceDataCollected( + make_scoped_refptr(base::RefCountedString::TakeString(&foo))); + + std::string bar("bar"); + subscriber.OnTraceDataCollected( + make_scoped_refptr(base::RefCountedString::TakeString(&bar))); + + subscriber.OnEndTracingComplete(); + } + BrowserThread::GetBlockingPool()->FlushForTesting(); + std::string result; + EXPECT_TRUE(base::ReadFileToString(trace_file, &result)); + EXPECT_EQ("{\"traceEvents\":[foo,bar]}", result); +} + +TEST_F(TraceSubscriberStdioTest, CanWriteSystemDataFirst) { + base::ScopedTempDir trace_dir; + ASSERT_TRUE(trace_dir.CreateUniqueTempDir()); + base::FilePath trace_file(trace_dir.path().AppendASCII("trace.txt")); + { + TraceSubscriberStdio subscriber( + trace_file, + TraceSubscriberStdio::FILE_TYPE_PROPERTY_LIST, + true); + + std::string foo("foo"); + subscriber.OnTraceDataCollected( + make_scoped_refptr(base::RefCountedString::TakeString(&foo))); + + std::string bar("bar"); + subscriber.OnTraceDataCollected( + make_scoped_refptr(base::RefCountedString::TakeString(&bar))); + + std::string systemTrace("event1\nev\"ent\"2\n"); + subscriber.OnEndSystemTracing( + make_scoped_refptr(base::RefCountedString::TakeString(&systemTrace))); + subscriber.OnEndTracingComplete(); + } + BrowserThread::GetBlockingPool()->FlushForTesting(); + std::string result; + EXPECT_TRUE(base::ReadFileToString(trace_file, &result)); + EXPECT_EQ( + "{\"traceEvents\":[foo,bar],\"" + "systemTraceEvents\":\"event1\\nev\\\"ent\\\"2\\n\"}", + result); +} + +TEST_F(TraceSubscriberStdioTest, CanWriteSystemDataLast) { + base::ScopedTempDir trace_dir; + ASSERT_TRUE(trace_dir.CreateUniqueTempDir()); + base::FilePath trace_file(trace_dir.path().AppendASCII("trace.txt")); + { + TraceSubscriberStdio subscriber( + trace_file, + TraceSubscriberStdio::FILE_TYPE_PROPERTY_LIST, + true); + + std::string foo("foo"); + subscriber.OnTraceDataCollected( + make_scoped_refptr(base::RefCountedString::TakeString(&foo))); + + std::string bar("bar"); + subscriber.OnTraceDataCollected( + make_scoped_refptr(base::RefCountedString::TakeString(&bar))); + + std::string systemTrace("event1\nev\"ent\"2\n"); + subscriber.OnEndTracingComplete(); + subscriber.OnEndSystemTracing( + make_scoped_refptr(base::RefCountedString::TakeString(&systemTrace))); + } + BrowserThread::GetBlockingPool()->FlushForTesting(); + std::string result; + EXPECT_TRUE(base::ReadFileToString(trace_file, &result)); + EXPECT_EQ( + "{\"traceEvents\":[foo,bar],\"" + "systemTraceEvents\":\"event1\\nev\\\"ent\\\"2\\n\"}", + result); +} + +} // namespace content diff --git a/content/browser/tracing/tracing_controller_browsertest.cc b/content/browser/tracing/tracing_controller_browsertest.cc index 6d5b381..0affc27 100644 --- a/content/browser/tracing/tracing_controller_browsertest.cc +++ b/content/browser/tracing/tracing_controller_browsertest.cc @@ -122,7 +122,8 @@ class TracingControllerTest : public ContentBrowserTest { base::Unretained(this), run_loop.QuitClosure()); bool result = controller->EnableRecording( - "", TracingController::DEFAULT_OPTIONS, callback); + base::debug::CategoryFilter(""), TracingController::Options(), + callback); ASSERT_TRUE(result); run_loop.Run(); EXPECT_EQ(enable_recording_done_callback_count(), 1); @@ -154,7 +155,8 @@ class TracingControllerTest : public ContentBrowserTest { base::Unretained(this), run_loop.QuitClosure()); bool result = controller->EnableMonitoring( - "", TracingController::ENABLE_SAMPLING, callback); + base::debug::CategoryFilter(""), TracingController::ENABLE_SAMPLING, + callback); ASSERT_TRUE(result); run_loop.Run(); EXPECT_EQ(enable_monitoring_done_callback_count(), 1); @@ -167,8 +169,7 @@ class TracingControllerTest : public ContentBrowserTest { CaptureMonitoringSnapshotDoneCallbackTest, base::Unretained(this), run_loop.QuitClosure()); - ASSERT_TRUE(controller->CaptureMonitoringSnapshot(result_file_path, - callback)); + controller->CaptureMonitoringSnapshot(result_file_path, callback); run_loop.Run(); EXPECT_EQ(capture_monitoring_snapshot_done_callback_count(), 1); } @@ -207,7 +208,7 @@ IN_PROC_BROWSER_TEST_F(TracingControllerTest, GetCategories) { base::Bind(&TracingControllerTest::GetCategoriesDoneCallbackTest, base::Unretained(this), run_loop.QuitClosure()); - ASSERT_TRUE(controller->GetCategories(callback)); + controller->GetCategories(callback); run_loop.Run(); EXPECT_EQ(get_categories_done_callback_count(), 1); } @@ -230,7 +231,7 @@ IN_PROC_BROWSER_TEST_F(TracingControllerTest, TracingController* controller = TracingController::GetInstance(); EXPECT_TRUE(controller->EnableRecording( - "", TracingController::DEFAULT_OPTIONS, + base::debug::CategoryFilter(""), TracingController::Options(), TracingController::EnableRecordingDoneCallback())); EXPECT_TRUE(controller->DisableRecording( base::FilePath(), TracingController::TracingFileResultCallback())); @@ -257,7 +258,7 @@ IN_PROC_BROWSER_TEST_F( TracingController* controller = TracingController::GetInstance(); EXPECT_TRUE(controller->EnableMonitoring( - "", TracingController::ENABLE_SAMPLING, + base::debug::CategoryFilter(""), TracingController::ENABLE_SAMPLING, TracingController::EnableMonitoringDoneCallback())); controller->CaptureMonitoringSnapshot( base::FilePath(), TracingController::TracingFileResultCallback()); diff --git a/content/browser/tracing/tracing_controller_impl.cc b/content/browser/tracing/tracing_controller_impl.cc index 0601866..1340b67 100644 --- a/content/browser/tracing/tracing_controller_impl.cc +++ b/content/browser/tracing/tracing_controller_impl.cc @@ -5,7 +5,6 @@ #include "content/browser/tracing/tracing_controller_impl.h" #include "base/bind.h" -#include "base/debug/trace_event.h" #include "base/file_util.h" #include "base/json/string_escape.h" #include "base/strings/string_number_conversions.h" @@ -119,7 +118,9 @@ TracingControllerImpl::TracingControllerImpl() : // Tracing may have been enabled by ContentMainRunner if kTraceStartup // is specified in command line. is_recording_(TraceLog::GetInstance()->IsEnabled()), - is_monitoring_(false) { + is_monitoring_(false), + category_filter_( + base::debug::CategoryFilter::kDefaultCategoryFilterString) { } TracingControllerImpl::~TracingControllerImpl() { @@ -131,7 +132,7 @@ TracingControllerImpl* TracingControllerImpl::GetInstance() { return g_controller.Pointer(); } -bool TracingControllerImpl::GetCategories( +void TracingControllerImpl::GetCategories( const GetCategoriesDoneCallback& callback) { DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI)); @@ -139,19 +140,14 @@ bool TracingControllerImpl::GetCategories( // message. So to get known categories, just begin and end tracing immediately // afterwards. This will ping all the child processes for categories. pending_get_categories_done_callback_ = callback; - if (!EnableRecording("*", TracingController::Options(), - EnableRecordingDoneCallback())) { - pending_get_categories_done_callback_.Reset(); - return false; - } - - bool ok = DisableRecording(base::FilePath(), TracingFileResultCallback()); - DCHECK(ok); - return true; + EnableRecording(base::debug::CategoryFilter("*"), + TracingController::Options(), + EnableRecordingDoneCallback()); + DisableRecording(base::FilePath(), TracingFileResultCallback()); } bool TracingControllerImpl::EnableRecording( - const std::string& category_filter, + const base::debug::CategoryFilter& filter, TracingController::Options options, const EnableRecordingDoneCallback& callback) { DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI)); @@ -172,14 +168,13 @@ bool TracingControllerImpl::EnableRecording( } // TODO(haraken): How to handle ENABLE_SYSTRACE? - TraceLog::GetInstance()->SetEnabled( - base::debug::CategoryFilter(category_filter), trace_options); + TraceLog::GetInstance()->SetEnabled(filter, trace_options); is_recording_ = true; + category_filter_ = TraceLog::GetInstance()->GetCurrentCategoryFilter(); // Notify all child processes. - for (TraceMessageFilterMap::iterator it = trace_message_filters_.begin(); - it != trace_message_filters_.end(); ++it) { - it->get()->SendBeginTracing(category_filter, trace_options); + for (FilterMap::iterator it = filters_.begin(); it != filters_.end(); ++it) { + it->get()->SendBeginTracing(category_filter_.ToString(), trace_options); } if (!callback.is_null()) @@ -209,13 +204,15 @@ bool TracingControllerImpl::DisableRecording( if (!callback.is_null() || !result_file_path.empty()) result_file_.reset(new ResultFile(result_file_path)); + // There could be a case where there are no child processes and filters_ + // is empty. In that case we can immediately tell the subscriber that tracing + // has ended. To avoid recursive calls back to the subscriber, we will just + // use the existing asynchronous OnDisableRecordingAcked code. // Count myself (local trace) in pending_disable_recording_ack_count_, // acked below. - pending_disable_recording_ack_count_ = trace_message_filters_.size() + 1; + pending_disable_recording_ack_count_ = filters_.size() + 1; - // Handle special case of zero child processes by immediately telling the - // caller that tracing has ended. Use asynchronous OnDisableRecordingAcked - // to avoid recursive call back to the caller. + // Handle special case of zero child processes. if (pending_disable_recording_ack_count_ == 1) { // Ack asynchronously now, because we don't have any children to wait for. std::vector<std::string> category_groups; @@ -226,15 +223,14 @@ bool TracingControllerImpl::DisableRecording( } // Notify all child processes. - for (TraceMessageFilterMap::iterator it = trace_message_filters_.begin(); - it != trace_message_filters_.end(); ++it) { + for (FilterMap::iterator it = filters_.begin(); it != filters_.end(); ++it) { it->get()->SendEndTracing(); } return true; } bool TracingControllerImpl::EnableMonitoring( - const std::string& category_filter, + const base::debug::CategoryFilter& filter, TracingController::Options options, const EnableMonitoringDoneCallback& callback) { DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI)); @@ -252,14 +248,12 @@ bool TracingControllerImpl::EnableMonitoring( monitoring_tracing_options |= base::debug::TraceLog::MONITOR_SAMPLING; TraceLog::GetInstance()->SetEnabled( - base::debug::CategoryFilter(category_filter), - static_cast<TraceLog::Options>(monitoring_tracing_options)); + filter, base::debug::TraceLog::Options(monitoring_tracing_options)); // Notify all child processes. - for (TraceMessageFilterMap::iterator it = trace_message_filters_.begin(); - it != trace_message_filters_.end(); ++it) { - it->get()->SendEnableMonitoring(category_filter, - static_cast<TraceLog::Options>(monitoring_tracing_options)); + for (FilterMap::iterator it = filters_.begin(); it != filters_.end(); ++it) { + it->get()->SendEnableMonitoring(filter.ToString(), + base::debug::TraceLog::Options(monitoring_tracing_options)); } if (!callback.is_null()) @@ -278,8 +272,7 @@ bool TracingControllerImpl::DisableMonitoring( TraceLog::GetInstance()->SetDisabled(); // Notify all child processes. - for (TraceMessageFilterMap::iterator it = trace_message_filters_.begin(); - it != trace_message_filters_.end(); ++it) { + for (FilterMap::iterator it = filters_.begin(); it != filters_.end(); ++it) { it->get()->SendDisableMonitoring(); } @@ -290,34 +283,34 @@ bool TracingControllerImpl::DisableMonitoring( void TracingControllerImpl::GetMonitoringStatus( bool* out_enabled, - std::string* out_category_filter, + base::debug::CategoryFilter* out_filter, TracingController::Options* out_options) { NOTIMPLEMENTED(); } -bool TracingControllerImpl::CaptureMonitoringSnapshot( +void TracingControllerImpl::CaptureMonitoringSnapshot( const base::FilePath& result_file_path, const TracingFileResultCallback& callback) { DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI)); if (!can_disable_monitoring()) - return false; + return; if (callback.is_null() && result_file_path.empty()) - return false; + return; pending_capture_monitoring_snapshot_done_callback_ = callback; monitoring_snapshot_file_.reset(new ResultFile(result_file_path)); + // There could be a case where there are no child processes and filters_ + // is empty. In that case we can immediately tell the subscriber that tracing + // has ended. To avoid recursive calls back to the subscriber, we will just + // use the existing asynchronous OnCaptureMonitoringSnapshotAcked code. // Count myself in pending_capture_monitoring_snapshot_ack_count_, // acked below. - pending_capture_monitoring_snapshot_ack_count_ = - trace_message_filters_.size() + 1; + pending_capture_monitoring_snapshot_ack_count_ = filters_.size() + 1; - // Handle special case of zero child processes by immediately telling the - // caller that capturing snapshot has ended. Use asynchronous - // OnCaptureMonitoringSnapshotAcked to avoid recursive call back to the - // caller. + // Handle special case of zero child processes. if (pending_capture_monitoring_snapshot_ack_count_ == 1) { // Ack asynchronously now, because we don't have any children to wait for. BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, @@ -326,16 +319,13 @@ bool TracingControllerImpl::CaptureMonitoringSnapshot( } // Notify all child processes. - for (TraceMessageFilterMap::iterator it = trace_message_filters_.begin(); - it != trace_message_filters_.end(); ++it) { + for (FilterMap::iterator it = filters_.begin(); it != filters_.end(); ++it) { it->get()->SendCaptureMonitoringSnapshot(); } #if defined(OS_ANDROID) TraceLog::GetInstance()->AddClockSyncMetadataEvent(); #endif - - return true; } bool TracingControllerImpl::GetTraceBufferPercentFull( @@ -348,8 +338,7 @@ bool TracingControllerImpl::GetTraceBufferPercentFull( pending_trace_buffer_percent_full_callback_ = callback; // Count myself in pending_trace_buffer_percent_full_ack_count_, acked below. - pending_trace_buffer_percent_full_ack_count_ = - trace_message_filters_.size() + 1; + pending_trace_buffer_percent_full_ack_count_ = filters_.size() + 1; maximum_trace_buffer_percent_full_ = 0; // Handle special case of zero child processes. @@ -361,86 +350,36 @@ bool TracingControllerImpl::GetTraceBufferPercentFull( } // Notify all child processes. - for (TraceMessageFilterMap::iterator it = trace_message_filters_.begin(); - it != trace_message_filters_.end(); ++it) { + for (FilterMap::iterator it = filters_.begin(); it != filters_.end(); ++it) { it->get()->SendGetTraceBufferPercentFull(); } return true; } -bool TracingControllerImpl::SetWatchEvent( - const std::string& category_name, - const std::string& event_name, - const WatchEventCallback& callback) { - DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI)); - - if (callback.is_null()) - return false; - - watch_category_name_ = category_name; - watch_event_name_ = event_name; - watch_event_callback_ = callback; - - TraceLog::GetInstance()->SetWatchEvent( - category_name, event_name, - base::Bind(&TracingControllerImpl::OnWatchEventMatched, - base::Unretained(this))); - - for (TraceMessageFilterMap::iterator it = trace_message_filters_.begin(); - it != trace_message_filters_.end(); ++it) { - it->get()->SendSetWatchEvent(category_name, event_name); - } - return true; -} - -bool TracingControllerImpl::CancelWatchEvent() { - DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI)); - - if (!can_cancel_watch_event()) - return false; - - for (TraceMessageFilterMap::iterator it = trace_message_filters_.begin(); - it != trace_message_filters_.end(); ++it) { - it->get()->SendCancelWatchEvent(); - } - - watch_event_callback_.Reset(); - return true; -} - -void TracingControllerImpl::AddTraceMessageFilter( - TraceMessageFilter* trace_message_filter) { +void TracingControllerImpl::AddFilter(TraceMessageFilter* filter) { if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) { BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, - base::Bind(&TracingControllerImpl::AddTraceMessageFilter, - base::Unretained(this), - make_scoped_refptr(trace_message_filter))); + base::Bind(&TracingControllerImpl::AddFilter, base::Unretained(this), + make_scoped_refptr(filter))); return; } - trace_message_filters_.insert(trace_message_filter); - if (can_cancel_watch_event()) { - trace_message_filter->SendSetWatchEvent(watch_category_name_, - watch_event_name_); - } + filters_.insert(filter); if (can_disable_recording()) { - trace_message_filter->SendBeginTracing( - TraceLog::GetInstance()->GetCurrentCategoryFilter().ToString(), - TraceLog::GetInstance()->trace_options()); + std::string cf_str = category_filter_.ToString(); + filter->SendBeginTracing(cf_str, TraceLog::GetInstance()->trace_options()); } } -void TracingControllerImpl::RemoveTraceMessageFilter( - TraceMessageFilter* trace_message_filter) { +void TracingControllerImpl::RemoveFilter(TraceMessageFilter* filter) { if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) { BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, - base::Bind(&TracingControllerImpl::RemoveTraceMessageFilter, - base::Unretained(this), - make_scoped_refptr(trace_message_filter))); + base::Bind(&TracingControllerImpl::RemoveFilter, base::Unretained(this), + make_scoped_refptr(filter))); return; } - trace_message_filters_.erase(trace_message_filter); + filters_.erase(filter); } void TracingControllerImpl::OnDisableRecordingAcked( @@ -466,7 +405,6 @@ void TracingControllerImpl::OnDisableRecordingAcked( TraceLog::GetInstance()->Flush( base::Bind(&TracingControllerImpl::OnLocalTraceDataCollected, base::Unretained(this))); - return; } if (pending_disable_recording_ack_count_ != 0) @@ -518,7 +456,6 @@ void TracingControllerImpl::OnCaptureMonitoringSnapshotAcked() { TraceLog::GetInstance()->FlushButLeaveBufferIntact( base::Bind(&TracingControllerImpl::OnLocalMonitoringTraceDataCollected, base::Unretained(this))); - return; } if (pending_capture_monitoring_snapshot_ack_count_ != 0) @@ -632,15 +569,4 @@ void TracingControllerImpl::OnTraceBufferPercentFullReply(float percent_full) { } } -void TracingControllerImpl::OnWatchEventMatched() { - if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) { - BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, - base::Bind(&TracingControllerImpl::OnWatchEventMatched, - base::Unretained(this))); - } - - if (!watch_event_callback_.is_null()) - watch_event_callback_.Run(); -} - } // namespace content diff --git a/content/browser/tracing/tracing_controller_impl.h b/content/browser/tracing/tracing_controller_impl.h index ed3c8fd..7eab907 100644 --- a/content/browser/tracing/tracing_controller_impl.h +++ b/content/browser/tracing/tracing_controller_impl.h @@ -11,12 +11,9 @@ #include "base/files/file_path.h" #include "base/lazy_instance.h" +#include "content/public/browser/trace_subscriber.h" #include "content/public/browser/tracing_controller.h" -namespace base { -class RefCountedString; -} - namespace content { class TraceMessageFilter; @@ -26,36 +23,32 @@ class TracingControllerImpl : public TracingController { static TracingControllerImpl* GetInstance(); // TracingController implementation. - virtual bool GetCategories( + virtual void GetCategories( const GetCategoriesDoneCallback& callback) OVERRIDE; virtual bool EnableRecording( - const std::string& category_filter, + const base::debug::CategoryFilter& filter, TracingController::Options options, const EnableRecordingDoneCallback& callback) OVERRIDE; virtual bool DisableRecording( const base::FilePath& result_file_path, const TracingFileResultCallback& callback) OVERRIDE; - virtual bool EnableMonitoring(const std::string& category_filter, + virtual bool EnableMonitoring(const base::debug::CategoryFilter& filter, TracingController::Options options, const EnableMonitoringDoneCallback& callback) OVERRIDE; virtual bool DisableMonitoring( const DisableMonitoringDoneCallback& callback) OVERRIDE; virtual void GetMonitoringStatus( bool* out_enabled, - std::string* out_category_filter, + base::debug::CategoryFilter* out_filter, TracingController::Options* out_options) OVERRIDE; - virtual bool CaptureMonitoringSnapshot( + virtual void CaptureMonitoringSnapshot( const base::FilePath& result_file_path, const TracingFileResultCallback& callback) OVERRIDE; virtual bool GetTraceBufferPercentFull( const GetTraceBufferPercentFullCallback& callback) OVERRIDE; - virtual bool SetWatchEvent(const std::string& category_name, - const std::string& event_name, - const WatchEventCallback& callback) OVERRIDE; - virtual bool CancelWatchEvent() OVERRIDE; private: - typedef std::set<scoped_refptr<TraceMessageFilter> > TraceMessageFilterMap; + typedef std::set<scoped_refptr<TraceMessageFilter> > FilterMap; class ResultFile; friend struct base::DefaultLazyInstanceTraits<TracingControllerImpl>; @@ -84,13 +77,9 @@ class TracingControllerImpl : public TracingController { return pending_trace_buffer_percent_full_callback_.is_null(); } - bool can_cancel_watch_event() const { - return !watch_event_callback_.is_null(); - } - // Methods for use by TraceMessageFilter. - void AddTraceMessageFilter(TraceMessageFilter* trace_message_filter); - void RemoveTraceMessageFilter(TraceMessageFilter* trace_message_filter); + void AddFilter(TraceMessageFilter* filter); + void RemoveFilter(TraceMessageFilter* filter); void OnTraceDataCollected( const scoped_refptr<base::RefCountedString>& events_str_ptr); @@ -113,11 +102,10 @@ class TracingControllerImpl : public TracingController { void OnCaptureMonitoringSnapshotAcked(); void OnMonitoringSnapshotFileClosed(); + void OnTraceNotification(int notification); void OnTraceBufferPercentFullReply(float percent_full); - void OnWatchEventMatched(); - - TraceMessageFilterMap trace_message_filters_; + FilterMap filters_; // Pending acks for DisableRecording. int pending_disable_recording_ack_count_; // Pending acks for CaptureMonitoringSnapshot. @@ -134,11 +122,8 @@ class TracingControllerImpl : public TracingController { TracingFileResultCallback pending_capture_monitoring_snapshot_done_callback_; GetTraceBufferPercentFullCallback pending_trace_buffer_percent_full_callback_; - std::string watch_category_name_; - std::string watch_event_name_; - WatchEventCallback watch_event_callback_; - std::set<std::string> known_category_groups_; + base::debug::CategoryFilter category_filter_; scoped_ptr<ResultFile> result_file_; scoped_ptr<ResultFile> monitoring_snapshot_file_; DISALLOW_COPY_AND_ASSIGN(TracingControllerImpl); diff --git a/content/browser/tracing/tracing_ui.cc b/content/browser/tracing/tracing_ui.cc index e59f566..6e471c2 100644 --- a/content/browser/tracing/tracing_ui.cc +++ b/content/browser/tracing/tracing_ui.cc @@ -86,10 +86,11 @@ bool OnBeginRecording(const std::string& data64, if (use_continuous_tracing) tracing_options |= TracingController::RECORD_CONTINUOUSLY; + base::debug::CategoryFilter category_filter(category_filter_string); return TracingController::GetInstance()->EnableRecording( - category_filter_string, + category_filter, static_cast<TracingController::Options>(tracing_options), - base::Bind(&OnRecordingEnabledAck, callback)); + base::Bind(OnRecordingEnabledAck, callback)); } void OnRecordingEnabledAck(const WebUIDataSource::GotDataCallback& callback) { diff --git a/content/content_browser.gypi b/content/content_browser.gypi index 5c697e1..a628a7d 100644 --- a/content/content_browser.gypi +++ b/content/content_browser.gypi @@ -177,6 +177,8 @@ 'public/browser/speech_recognition_session_context.h', 'public/browser/storage_partition.h', 'public/browser/stream_handle.h', + 'public/browser/trace_controller.h', + 'public/browser/trace_subscriber.h', 'public/browser/tracing_controller.h', 'public/browser/user_metrics.h', 'public/browser/utility_process_host.h', @@ -1156,8 +1158,12 @@ 'browser/tcmalloc_internals_request_job.h', 'browser/theme_helper_mac.mm', 'browser/theme_helper_mac.h', + 'browser/tracing/trace_controller_impl.cc', + 'browser/tracing/trace_controller_impl.h', 'browser/tracing/trace_message_filter.cc', 'browser/tracing/trace_message_filter.h', + 'browser/tracing/trace_subscriber_stdio.cc', + 'browser/tracing/trace_subscriber_stdio.h', 'browser/tracing/tracing_controller_impl.cc', 'browser/tracing/tracing_controller_impl.h', 'browser/tracing/tracing_ui.cc', diff --git a/content/content_tests.gypi b/content/content_tests.gypi index eed3507..f2d0236 100644 --- a/content/content_tests.gypi +++ b/content/content_tests.gypi @@ -473,6 +473,7 @@ 'browser/streams/stream_unittest.cc', 'browser/streams/stream_url_request_job_unittest.cc', 'browser/system_message_window_win_unittest.cc', + 'browser/tracing/trace_subscriber_stdio_unittest.cc', 'browser/web_contents/aura/window_slider_unittest.cc', 'browser/web_contents/web_contents_delegate_unittest.cc', 'browser/web_contents/web_contents_impl_unittest.cc', diff --git a/content/public/browser/trace_controller.h b/content/public/browser/trace_controller.h new file mode 100644 index 0000000..dee5f91 --- /dev/null +++ b/content/public/browser/trace_controller.h @@ -0,0 +1,107 @@ +// Copyright 2013 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. + +#ifndef CONTENT_PUBLIC_BROWSER_TRACE_CONTROLLER_H_ +#define CONTENT_PUBLIC_BROWSER_TRACE_CONTROLLER_H_ + +#include "base/debug/trace_event.h" +#include "content/common/content_export.h" + +namespace content { + +class TraceSubscriber; + +// Note: TraceController is going to be deprecated and replaced with +// TracingController. +// +// TraceController is used on the browser processes to enable/disable +// trace status and collect trace data. Only the browser UI thread is allowed +// to interact with the TraceController object. All calls on the TraceSubscriber +// happen on the UI thread. +class TraceController { + public: + CONTENT_EXPORT static TraceController* GetInstance(); + + // Called by browser process to start tracing events on all processes. + // + // Currently only one subscriber is allowed at a time. + // Tracing begins immediately locally, and asynchronously on child processes + // as soon as they receive the BeginTracing request. + // + // If BeginTracing was already called previously, + // or if an EndTracingAsync is pending, + // or if another subscriber is tracing, + // BeginTracing will return false meaning it failed. + // + // |category_patterns| is a comma-delimited list of category wildcards. + // A category pattern can have an optional '-' prefix to exclude category + // groups that contain a matching category. + // All the same rules apply above, so for example, having both included and + // excluded category patterns in the same list would not be supported. + // + // |mode| is the tracing mode being used. + // + // Example: BeginTracing("test_MyTest*"); + // Example: BeginTracing("test_MyTest*,test_OtherStuff"); + // Example: BeginTracing("-excluded_category1,-excluded_category2"); + virtual bool BeginTracing(TraceSubscriber* subscriber, + const std::string& category_patterns, + base::debug::TraceLog::Options options) = 0; + + // Called by browser process to stop tracing events on all processes. + // + // Child processes typically are caching trace data and only rarely flush + // and send trace data back to the browser process. That is because it may be + // an expensive operation to send the trace data over IPC, and we would like + // to avoid much runtime overhead of tracing. So, to end tracing, we must + // asynchronously ask all child processes to flush any pending trace data. + // + // Once all child processes have acked the EndTracing request, + // TraceSubscriber will be called with OnEndTracingComplete. + // + // If a previous call to EndTracingAsync is already pending, + // or if another subscriber is tracing, + // EndTracingAsync will return false meaning it failed. + virtual bool EndTracingAsync(TraceSubscriber* subscriber) = 0; + + // Get the maximum across processes of trace buffer percent full state. + // When the TraceBufferPercentFull value is determined, + // subscriber->OnTraceBufferPercentFullReply is called. + // When any child process reaches 100% full, the TraceController will end + // tracing, and call TraceSubscriber::OnEndTracingComplete. + // GetTraceBufferPercentFullAsync fails in the following conditions: + // trace is ending or disabled; + // a previous call to GetTraceBufferPercentFullAsync is pending; or + // the caller is not the current subscriber. + virtual bool GetTraceBufferPercentFullAsync(TraceSubscriber* subscriber) = 0; + + // |subscriber->OnEventWatchNotification()| will be called every time the + // given event occurs on any process. + virtual bool SetWatchEvent(TraceSubscriber* subscriber, + const std::string& category_name, + const std::string& event_name) = 0; + + // Cancel the watch event. If tracing is enabled, this may race with the + // watch event notification firing. + virtual bool CancelWatchEvent(TraceSubscriber* subscriber) = 0; + + // Cancel the subscriber so that it will not be called when EndTracingAsync is + // acked by all child processes. This will also call EndTracingAsync + // internally if necessary. + // Safe to call even if caller is not the current subscriber. + virtual void CancelSubscriber(TraceSubscriber* subscriber) = 0; + + // Get set of known category groups. This can change as new code paths are + // reached. If true is returned, subscriber->OnKnownCategoriesCollected will + // be called once the categories are retrieved from child processes. + virtual bool GetKnownCategoryGroupsAsync(TraceSubscriber* subscriber) = 0; + + protected: + virtual ~TraceController() {} +}; + +} // namespace content + +#endif // CONTENT_PUBLIC_BROWSER_TRACE_CONTROLLER_H_ + diff --git a/content/public/browser/trace_subscriber.h b/content/public/browser/trace_subscriber.h new file mode 100644 index 0000000..b8a7850 --- /dev/null +++ b/content/public/browser/trace_subscriber.h @@ -0,0 +1,43 @@ +// Copyright 2013 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. + +#ifndef CONTENT_PUBLIC_BROWSER_TRACE_SUBSCRIBER_H_ +#define CONTENT_PUBLIC_BROWSER_TRACE_SUBSCRIBER_H_ + +#include <set> + +#include "base/memory/ref_counted_memory.h" + +namespace content { + +// Objects interested in receiving trace data derive from TraceSubscriber. All +// callbacks occur on the UI thread. +// See also: trace_message_filter.h +// See also: child_trace_message_filter.h +class TraceSubscriber { + public: + // Called once after TraceController::EndTracingAsync. + virtual void OnEndTracingComplete() {} + + // Called 0 or more times between TraceController::BeginTracing and + // OnEndTracingComplete. Use base::debug::TraceResultBuffer to convert one or + // more trace fragments to JSON. + virtual void OnTraceDataCollected( + const scoped_refptr<base::RefCountedString>& trace_fragment) = 0; + + // Called once after TraceController::GetKnownCategoryGroupsAsync. + virtual void OnKnownCategoriesCollected( + const std::set<std::string>& known_categories) {} + + virtual void OnTraceBufferPercentFullReply(float percent_full) {} + + virtual void OnEventWatchNotification() {} + + protected: + virtual ~TraceSubscriber() {} +}; + +} // namespace content + +#endif // CONTENT_PUBLIC_BROWSER_TRACE_SUBSCRIBER_H_ diff --git a/content/public/browser/tracing_controller.h b/content/public/browser/tracing_controller.h index 68184a5..ae46199 100644 --- a/content/public/browser/tracing_controller.h +++ b/content/public/browser/tracing_controller.h @@ -6,9 +6,8 @@ #define CONTENT_PUBLIC_BROWSER_TRACING_CONTROLLER_H_ #include <set> -#include <string> -#include "base/callback.h" +#include "base/debug/trace_event.h" #include "content/common/content_export.h" namespace base { @@ -26,7 +25,6 @@ class TracingController; class TracingController { public: enum Options { - DEFAULT_OPTIONS = 0, ENABLE_SYSTRACE = 1 << 0, ENABLE_SAMPLING = 1 << 1, RECORD_CONTINUOUSLY = 1 << 2, // For EnableRecording() only. @@ -42,7 +40,7 @@ class TracingController { // groups. typedef base::Callback<void(const std::set<std::string>&)> GetCategoriesDoneCallback; - virtual bool GetCategories( + virtual void GetCategories( const GetCategoriesDoneCallback& callback) = 0; // Start recording on all processes. @@ -53,8 +51,8 @@ class TracingController { // Once all child processes have acked to the EnableRecording request, // EnableRecordingDoneCallback will be called back. // - // |category_filter| is a filter to control what category groups should be - // traced. A filter can have an optional '-' prefix to exclude category groups + // |filter| is a filter to control what category groups should be traced. + // A filter can have an optional '-' prefix to exclude category groups // that contain a matching category. Having both included and excluded // category patterns in the same list would not be supported. // @@ -65,7 +63,7 @@ class TracingController { // |options| controls what kind of tracing is enabled. typedef base::Callback<void()> EnableRecordingDoneCallback; virtual bool EnableRecording( - const std::string& category_filter, + const base::debug::CategoryFilter& filter, TracingController::Options options, const EnableRecordingDoneCallback& callback) = 0; @@ -99,13 +97,11 @@ class TracingController { // Once all child processes have acked to the EnableMonitoring request, // EnableMonitoringDoneCallback will be called back. // - // |category_filter| is a filter to control what category groups should be - // traced. + // |filter| is a filter to control what category groups should be traced. // // |options| controls what kind of tracing is enabled. typedef base::Callback<void()> EnableMonitoringDoneCallback; - virtual bool EnableMonitoring( - const std::string& category_filter, + virtual bool EnableMonitoring(const base::debug::CategoryFilter& filter, TracingController::Options options, const EnableMonitoringDoneCallback& callback) = 0; @@ -119,8 +115,8 @@ class TracingController { // Get the current monitoring configuration. virtual void GetMonitoringStatus(bool* out_enabled, - std::string* out_category_filter, - TracingController::Options* out_options) = 0; + base::debug::CategoryFilter* out_filter, + TracingController::Options* out_options) = 0; // Get the current monitoring traced data. // @@ -139,7 +135,7 @@ class TracingController { // // If |result_file_path| is empty and |callback| is null, trace data won't be // written to any file. - virtual bool CaptureMonitoringSnapshot( + virtual void CaptureMonitoringSnapshot( const base::FilePath& result_file_path, const TracingFileResultCallback& callback) = 0; @@ -150,17 +146,6 @@ class TracingController { virtual bool GetTraceBufferPercentFull( const GetTraceBufferPercentFullCallback& callback) = 0; - // |callback| will will be called every time the given event occurs on any - // process. - typedef base::Callback<void()> WatchEventCallback; - virtual bool SetWatchEvent(const std::string& category_name, - const std::string& event_name, - const WatchEventCallback& callback) = 0; - - // Cancel the watch event. If tracing is enabled, this may race with the - // watch event callback. - virtual bool CancelWatchEvent() = 0; - protected: virtual ~TracingController() {} }; |