// 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/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" #include "content/browser/tracing/trace_message_filter.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::Leaky g_controller = LAZY_INSTANCE_INITIALIZER; } // namespace TracingController* TracingController::GetInstance() { return TracingControllerImpl::GetInstance(); } class TracingControllerImpl::ResultFile { public: explicit ResultFile(const base::FilePath& path); void Write(const scoped_refptr& events_str_ptr) { BrowserThread::PostTask(BrowserThread::FILE, FROM_HERE, base::Bind(&TracingControllerImpl::ResultFile::WriteTask, base::Unretained(this), events_str_ptr)); } void Close(const base::Closure& callback) { BrowserThread::PostTask(BrowserThread::FILE, FROM_HERE, base::Bind(&TracingControllerImpl::ResultFile::CloseTask, base::Unretained(this), callback)); } const base::FilePath& path() const { return path_; } private: void OpenTask(); void WriteTask(const scoped_refptr& events_str_ptr); void CloseTask(const base::Closure& callback); FILE* file_; base::FilePath path_; bool has_at_least_one_result_; DISALLOW_COPY_AND_ASSIGN(ResultFile); }; TracingControllerImpl::ResultFile::ResultFile(const base::FilePath& path) : file_(NULL), path_(path), has_at_least_one_result_(false) { BrowserThread::PostTask(BrowserThread::FILE, FROM_HERE, base::Bind(&TracingControllerImpl::ResultFile::OpenTask, base::Unretained(this))); } void TracingControllerImpl::ResultFile::OpenTask() { if (path_.empty()) base::CreateTemporaryFile(&path_); file_ = base::OpenFile(path_, "w"); if (!file_) { LOG(ERROR) << "Failed to open " << path_.value(); return; } const char* preamble = "{\"traceEvents\": ["; size_t written = fwrite(preamble, strlen(preamble), 1, file_); DCHECK(written == 1); } void TracingControllerImpl::ResultFile::WriteTask( const scoped_refptr& events_str_ptr) { if (!file_) return; // If there is already a result in the file, then put a commma // before the next batch of results. if (has_at_least_one_result_) { size_t written = fwrite(",", 1, 1, file_); DCHECK(written == 1); } has_at_least_one_result_ = true; size_t written = fwrite(events_str_ptr->data().c_str(), events_str_ptr->data().size(), 1, file_); DCHECK(written == 1); } void TracingControllerImpl::ResultFile::CloseTask( const base::Closure& callback) { if (!file_) return; const char* trailout = "]}"; size_t written = fwrite(trailout, strlen(trailout), 1, file_); DCHECK(written == 1); base::CloseFile(file_); file_ = NULL; BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, callback); } TracingControllerImpl::TracingControllerImpl() : pending_disable_recording_ack_count_(0), pending_capture_monitoring_snapshot_ack_count_(0), pending_trace_buffer_percent_full_ack_count_(0), maximum_trace_buffer_percent_full_(0), // Tracing may have been enabled by ContentMainRunner if kTraceStartup // is specified in command line. is_recording_(TraceLog::GetInstance()->IsEnabled()), is_monitoring_(false) { } TracingControllerImpl::~TracingControllerImpl() { // This is a Leaky instance. NOTREACHED(); } TracingControllerImpl* TracingControllerImpl::GetInstance() { return g_controller.Pointer(); } bool TracingControllerImpl::GetCategories( const GetCategoriesDoneCallback& callback) { 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. 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; } bool TracingControllerImpl::EnableRecording( const std::string& category_filter, TracingController::Options options, const EnableRecordingDoneCallback& callback) { DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI)); if (!can_enable_recording()) return false; #if defined(OS_ANDROID) if (pending_get_categories_done_callback_.is_null()) TraceLog::GetInstance()->AddClockSyncMetadataEvent(); #endif TraceLog::Options trace_options = (options & RECORD_CONTINUOUSLY) ? TraceLog::RECORD_CONTINUOUSLY : TraceLog::RECORD_UNTIL_FULL; if (options & ENABLE_SAMPLING) { trace_options = static_cast( trace_options | TraceLog::ENABLE_SAMPLING); } // TODO(haraken): How to handle ENABLE_SYSTRACE? TraceLog::GetInstance()->SetEnabled( base::debug::CategoryFilter(category_filter), trace_options); is_recording_ = true; // 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); } if (!callback.is_null()) callback.Run(); return true; } bool TracingControllerImpl::DisableRecording( const base::FilePath& result_file_path, const TracingFileResultCallback& callback) { DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI)); if (!can_disable_recording()) return false; pending_disable_recording_done_callback_ = callback; // Disable local trace early to avoid traces during end-tracing process from // interfering with the process. TraceLog::GetInstance()->SetDisabled(); #if defined(OS_ANDROID) if (pending_get_categories_done_callback_.is_null()) TraceLog::GetInstance()->AddClockSyncMetadataEvent(); #endif if (!callback.is_null() || !result_file_path.empty()) result_file_.reset(new ResultFile(result_file_path)); // Count myself (local trace) in pending_disable_recording_ack_count_, // acked below. pending_disable_recording_ack_count_ = trace_message_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. if (pending_disable_recording_ack_count_ == 1) { // Ack asynchronously now, because we don't have any children to wait for. std::vector category_groups; TraceLog::GetInstance()->GetKnownCategoryGroups(&category_groups); BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, base::Bind(&TracingControllerImpl::OnDisableRecordingAcked, base::Unretained(this), category_groups)); } // Notify all child processes. for (TraceMessageFilterMap::iterator it = trace_message_filters_.begin(); it != trace_message_filters_.end(); ++it) { it->get()->SendEndTracing(); } return true; } bool TracingControllerImpl::EnableMonitoring( const std::string& category_filter, TracingController::Options options, const EnableMonitoringDoneCallback& callback) { DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI)); if (!can_enable_monitoring()) return false; is_monitoring_ = true; #if defined(OS_ANDROID) TraceLog::GetInstance()->AddClockSyncMetadataEvent(); #endif int monitoring_tracing_options = 0; if (options & ENABLE_SAMPLING) monitoring_tracing_options |= base::debug::TraceLog::MONITOR_SAMPLING; TraceLog::GetInstance()->SetEnabled( base::debug::CategoryFilter(category_filter), static_cast(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(monitoring_tracing_options)); } if (!callback.is_null()) callback.Run(); return true; } bool TracingControllerImpl::DisableMonitoring( const DisableMonitoringDoneCallback& callback) { DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI)); if (!can_disable_monitoring()) return false; is_monitoring_ = false; TraceLog::GetInstance()->SetDisabled(); // Notify all child processes. for (TraceMessageFilterMap::iterator it = trace_message_filters_.begin(); it != trace_message_filters_.end(); ++it) { it->get()->SendDisableMonitoring(); } if (!callback.is_null()) callback.Run(); return true; } void TracingControllerImpl::GetMonitoringStatus( bool* out_enabled, std::string* out_category_filter, TracingController::Options* out_options) { NOTIMPLEMENTED(); } bool TracingControllerImpl::CaptureMonitoringSnapshot( const base::FilePath& result_file_path, const TracingFileResultCallback& callback) { DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI)); if (!can_disable_monitoring()) return false; if (callback.is_null() && result_file_path.empty()) return false; pending_capture_monitoring_snapshot_done_callback_ = callback; monitoring_snapshot_file_.reset(new ResultFile(result_file_path)); // Count myself in pending_capture_monitoring_snapshot_ack_count_, // acked below. pending_capture_monitoring_snapshot_ack_count_ = trace_message_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. 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, base::Bind(&TracingControllerImpl::OnCaptureMonitoringSnapshotAcked, base::Unretained(this))); } // Notify all child processes. for (TraceMessageFilterMap::iterator it = trace_message_filters_.begin(); it != trace_message_filters_.end(); ++it) { it->get()->SendCaptureMonitoringSnapshot(); } #if defined(OS_ANDROID) TraceLog::GetInstance()->AddClockSyncMetadataEvent(); #endif return true; } bool TracingControllerImpl::GetTraceBufferPercentFull( const GetTraceBufferPercentFullCallback& callback) { DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI)); if (!can_get_trace_buffer_percent_full() || callback.is_null()) return false; 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; maximum_trace_buffer_percent_full_ = 0; // Handle special case of zero child processes. if (pending_trace_buffer_percent_full_ack_count_ == 1) { BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, base::Bind(&TracingControllerImpl::OnTraceBufferPercentFullReply, base::Unretained(this), TraceLog::GetInstance()->GetBufferPercentFull())); } // Notify all child processes. for (TraceMessageFilterMap::iterator it = trace_message_filters_.begin(); it != trace_message_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) { if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) { BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, base::Bind(&TracingControllerImpl::AddTraceMessageFilter, base::Unretained(this), make_scoped_refptr(trace_message_filter))); return; } trace_message_filters_.insert(trace_message_filter); if (can_cancel_watch_event()) { trace_message_filter->SendSetWatchEvent(watch_category_name_, watch_event_name_); } if (can_disable_recording()) { trace_message_filter->SendBeginTracing( TraceLog::GetInstance()->GetCurrentCategoryFilter().ToString(), TraceLog::GetInstance()->trace_options()); } } void TracingControllerImpl::RemoveTraceMessageFilter( TraceMessageFilter* trace_message_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))); return; } trace_message_filters_.erase(trace_message_filter); } void TracingControllerImpl::OnDisableRecordingAcked( const std::vector& known_category_groups) { if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) { BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, base::Bind(&TracingControllerImpl::OnDisableRecordingAcked, 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_disable_recording_ack_count_ == 0) return; if (--pending_disable_recording_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(&TracingControllerImpl::OnLocalTraceDataCollected, base::Unretained(this))); return; } if (pending_disable_recording_ack_count_ != 0) return; // All acks (including from the subprocesses and the local trace) have been // received. is_recording_ = false; // Trigger callback if one is set. if (!pending_get_categories_done_callback_.is_null()) { pending_get_categories_done_callback_.Run(known_category_groups_); pending_get_categories_done_callback_.Reset(); } else if (result_file_) { result_file_->Close( base::Bind(&TracingControllerImpl::OnResultFileClosed, base::Unretained(this))); } } void TracingControllerImpl::OnResultFileClosed() { DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI)); if (!result_file_) return; if (!pending_disable_recording_done_callback_.is_null()) { pending_disable_recording_done_callback_.Run(result_file_->path()); pending_disable_recording_done_callback_.Reset(); } result_file_.reset(); } void TracingControllerImpl::OnCaptureMonitoringSnapshotAcked() { if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) { BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, base::Bind(&TracingControllerImpl::OnCaptureMonitoringSnapshotAcked, base::Unretained(this))); return; } if (pending_capture_monitoring_snapshot_ack_count_ == 0) return; if (--pending_capture_monitoring_snapshot_ack_count_ == 1) { // All acks from subprocesses have been received. Now flush the local trace. // During or after this call, our OnLocalMonitoringTraceDataCollected // will be called with the last of the local trace data. TraceLog::GetInstance()->FlushButLeaveBufferIntact( base::Bind(&TracingControllerImpl::OnLocalMonitoringTraceDataCollected, base::Unretained(this))); return; } if (pending_capture_monitoring_snapshot_ack_count_ != 0) return; if (monitoring_snapshot_file_) { monitoring_snapshot_file_->Close( base::Bind(&TracingControllerImpl::OnMonitoringSnapshotFileClosed, base::Unretained(this))); } } void TracingControllerImpl::OnMonitoringSnapshotFileClosed() { DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI)); if (!monitoring_snapshot_file_) return; if (!pending_capture_monitoring_snapshot_done_callback_.is_null()) { pending_capture_monitoring_snapshot_done_callback_.Run( monitoring_snapshot_file_->path()); pending_capture_monitoring_snapshot_done_callback_.Reset(); } monitoring_snapshot_file_.reset(); } void TracingControllerImpl::OnTraceDataCollected( const scoped_refptr& 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(&TracingControllerImpl::OnTraceDataCollected, base::Unretained(this), events_str_ptr)); return; } if (result_file_) result_file_->Write(events_str_ptr); } void TracingControllerImpl::OnMonitoringTraceDataCollected( const scoped_refptr& events_str_ptr) { if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) { BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, base::Bind(&TracingControllerImpl::OnMonitoringTraceDataCollected, base::Unretained(this), events_str_ptr)); return; } if (monitoring_snapshot_file_) monitoring_snapshot_file_->Write(events_str_ptr); } void TracingControllerImpl::OnLocalTraceDataCollected( const scoped_refptr& events_str_ptr, bool has_more_events) { if (events_str_ptr->data().size()) OnTraceDataCollected(events_str_ptr); if (has_more_events) return; // Simulate an DisableRecordingAcked for the local trace. std::vector category_groups; TraceLog::GetInstance()->GetKnownCategoryGroups(&category_groups); OnDisableRecordingAcked(category_groups); } void TracingControllerImpl::OnLocalMonitoringTraceDataCollected( const scoped_refptr& events_str_ptr, bool has_more_events) { if (events_str_ptr->data().size()) OnMonitoringTraceDataCollected(events_str_ptr); if (has_more_events) return; // Simulate an CaptureMonitoringSnapshotAcked for the local trace. OnCaptureMonitoringSnapshotAcked(); } void TracingControllerImpl::OnTraceBufferPercentFullReply(float percent_full) { if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) { BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, base::Bind(&TracingControllerImpl::OnTraceBufferPercentFullReply, base::Unretained(this), percent_full)); return; } if (pending_trace_buffer_percent_full_ack_count_ == 0) return; maximum_trace_buffer_percent_full_ = std::max(maximum_trace_buffer_percent_full_, percent_full); if (--pending_trace_buffer_percent_full_ack_count_ == 0) { // Trigger callback if one is set. pending_trace_buffer_percent_full_callback_.Run( maximum_trace_buffer_percent_full_); pending_trace_buffer_percent_full_callback_.Reset(); } if (pending_trace_buffer_percent_full_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. BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, base::Bind(&TracingControllerImpl::OnTraceBufferPercentFullReply, base::Unretained(this), TraceLog::GetInstance()->GetBufferPercentFull())); } } void TracingControllerImpl::OnWatchEventMatched() { if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) { BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, base::Bind(&TracingControllerImpl::OnWatchEventMatched, base::Unretained(this))); return; } if (!watch_event_callback_.is_null()) watch_event_callback_.Run(); } } // namespace content