Adds a callback to TracingAgent::StartAgentTracing()

content/browser/tracing/tracing_controller_impl.cc

 // Copyright (c) 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/cpu.h"
 #include "base/files/file_util.h"
 #include "base/json/string_escape.h"
 #include "base/macros.h"
 #include "base/strings/string_number_conversions.h"
 #include "base/sys_info.h"
+#include "base/thread_task_runner_handle.h"
+#include "base/time/time.h"
 #include "base/trace_event/trace_event.h"
 #include "build/build_config.h"
 #include "content/browser/tracing/file_tracing_provider_impl.h"
 #include "content/browser/tracing/power_tracing_agent.h"
 #include "content/browser/tracing/trace_message_filter.h"
 #include "content/browser/tracing/tracing_ui.h"
 #include "content/common/child_process_messages.h"
 #include "content/public/browser/browser_message_filter.h"
 #include "content/public/browser/content_browser_client.h"
 #include "content/public/browser/gpu_data_manager.h"
@@ skipping 20 matching lines @@
 
 namespace {
 
 base::LazyInstance<TracingControllerImpl>::Leaky g_controller =
     LAZY_INSTANCE_INITIALIZER;
 
 const char kChromeTracingAgentName[] = "chrome";
 const char kETWTracingAgentName[] = "etw";
 const char kChromeTraceLabel[] = "traceEvents";
 
-const int kIssueClockSyncTimeout = 30;
+const int kStartTracingTimeout = 30;
+const int kIssueClockSyncTimeoutSeconds = 30;
+const int kStopTracingRetryTimeMilliseconds = 100;
 
 std::string GetNetworkTypeString() {
   switch (net::NetworkChangeNotifier::GetConnectionType()) {
     case net::NetworkChangeNotifier::CONNECTION_ETHERNET:
       return "Ethernet";
     case net::NetworkChangeNotifier::CONNECTION_WIFI:
       return "WiFi";
     case net::NetworkChangeNotifier::CONNECTION_2G:
       return "2G";
     case net::NetworkChangeNotifier::CONNECTION_3G:
@@ skipping 73 matching lines @@
   return metadata_dict;
 }
 
 }  // namespace
 
 TracingController* TracingController::GetInstance() {
   return TracingControllerImpl::GetInstance();
 }
 
 TracingControllerImpl::TracingControllerImpl()
-    : pending_stop_tracing_ack_count_(0),
+    : pending_start_tracing_ack_count_(0),
+      pending_stop_tracing_ack_count_(0),
       pending_capture_monitoring_snapshot_ack_count_(0),
       pending_trace_log_status_ack_count_(0),
       maximum_trace_buffer_usage_(0),
       approximate_event_count_(0),
       pending_memory_dump_ack_count_(0),
       failed_memory_dump_count_(0),
       clock_sync_id_(0),
       pending_clock_sync_ack_count_(0),
       is_tracing_(false),
       is_monitoring_(false) {
@@ skipping 53 matching lines @@
 bool TracingControllerImpl::StartTracing(
     const TraceConfig& trace_config,
     const StartTracingDoneCallback& callback) {
   DCHECK_CURRENTLY_ON(BrowserThread::UI);
   DCHECK(additional_tracing_agents_.empty());
 
   if (!can_start_tracing())
     return false;
   is_tracing_ = true;
   start_tracing_done_callback_ = callback;
+  start_tracing_trace_config_.reset(
+      new base::trace_event::TraceConfig(trace_config));
+  pending_start_tracing_ack_count_ = 0;
 
 #if defined(OS_ANDROID)
   if (pending_get_categories_done_callback_.is_null())
     TraceLog::GetInstance()->AddClockSyncMetadataEvent();
 #endif
 
   if (trace_config.IsSystraceEnabled()) {
-    if (PowerTracingAgent::GetInstance()->StartAgentTracing(trace_config))
-      additional_tracing_agents_.push_back(PowerTracingAgent::GetInstance());
+    PowerTracingAgent::GetInstance()->StartAgentTracing(
+        trace_config,
+        base::Bind(&TracingControllerImpl::OnStartAgentTracingAcked,
+                   base::Unretained(this)));
+    ++pending_start_tracing_ack_count_;
+
 #if defined(OS_CHROMEOS)
     chromeos::DebugDaemonClient* debug_daemon =
         chromeos::DBusThreadManager::Get()->GetDebugDaemonClient();
-    if (debug_daemon && debug_daemon->StartAgentTracing(trace_config)) {
-      debug_daemon->SetStopAgentTracingTaskRunner(
-          BrowserThread::GetBlockingPool());
-      additional_tracing_agents_.push_back(
-          chromeos::DBusThreadManager::Get()->GetDebugDaemonClient());
+    if (debug_daemon) {
+      debug_daemon->StartAgentTracing(
+          trace_config,
+          base::Bind(&TracingControllerImpl::OnStartAgentTracingAcked,
+                     base::Unretained(this)));
+      ++pending_start_tracing_ack_count_;
     }
 #elif defined(OS_WIN)
-    if (EtwSystemEventConsumer::GetInstance()->StartAgentTracing(
-        trace_config)) {
-      additional_tracing_agents_.push_back(
-          EtwSystemEventConsumer::GetInstance());
-    }
+    EtwSystemEventConsumer::GetInstance()->StartAgentTracing(
+        trace_config,
+        base::Bind(&TracingControllerImpl::OnStartAgentTracingAcked,
+                   base::Unretained(this)));
+    ++pending_start_tracing_ack_count_;
 #endif
   }
 
   // TraceLog may have been enabled in startup tracing before threads are ready.
   if (TraceLog::GetInstance()->IsEnabled())
     return true;
-  return StartAgentTracing(trace_config);
+
+  StartAgentTracing(trace_config,
+                    base::Bind(&TracingControllerImpl::OnStartAgentTracingAcked,
+                               base::Unretained(this)));
+  ++pending_start_tracing_ack_count_;
+
+  // Set a deadline to ensure all agents ack within a reasonable time frame.
+  start_tracing_timer_.Start(
+      FROM_HERE, base::TimeDelta::FromSeconds(kStartTracingTimeout),
+      base::Bind(&TracingControllerImpl::OnAllTracingAgentsStarted,
+                 base::Unretained(this)));
+
+  return true;
 }
 
-void TracingControllerImpl::OnStartAgentTracingDone(
-    const TraceConfig& trace_config) {
+void TracingControllerImpl::OnAllTracingAgentsStarted() {
   DCHECK_CURRENTLY_ON(BrowserThread::UI);
 
   TRACE_EVENT_API_ADD_METADATA_EVENT("IsTimeTicksHighResolution", "value",
                                      base::TimeTicks::IsHighResolution());
-  TRACE_EVENT_API_ADD_METADATA_EVENT("TraceConfig", "value",
-                                     trace_config.AsConvertableToTraceFormat());
+  TRACE_EVENT_API_ADD_METADATA_EVENT(
+      "TraceConfig", "value",
+      start_tracing_trace_config_->AsConvertableToTraceFormat());
 
   // Notify all child processes.
   for (TraceMessageFilterSet::iterator it = trace_message_filters_.begin();
       it != trace_message_filters_.end(); ++it) {
-    it->get()->SendBeginTracing(trace_config);
+    it->get()->SendBeginTracing(*start_tracing_trace_config_);
   }
 
-  if (!start_tracing_done_callback_.is_null()) {
+  if (!start_tracing_done_callback_.is_null())
     start_tracing_done_callback_.Run();
-    start_tracing_done_callback_.Reset();
-  }
+
+  start_tracing_done_callback_.Reset();
+  start_tracing_trace_config_.reset();
 }
 
 bool TracingControllerImpl::StopTracing(
     const scoped_refptr<TraceDataSink>& trace_data_sink) {
   DCHECK_CURRENTLY_ON(BrowserThread::UI);
 
+  if (!can_stop_tracing())
+    return false;
+
+  // If we're still waiting to start tracing, try again after a delay.
+  if (start_tracing_timer_.IsRunning()) {
+    base::ThreadTaskRunnerHandle::Get()->PostDelayedTask(
+        FROM_HERE,
+        base::Bind(base::IgnoreResult(&TracingControllerImpl::StopTracing),
+                   base::Unretained(this), trace_data_sink),
+        base::TimeDelta::FromMilliseconds(kStopTracingRetryTimeMilliseconds));
+    return true;
+  }
+
   if (trace_data_sink) {
     if (TraceLog::GetInstance()->GetCurrentTraceConfig()
         .IsArgumentFilterEnabled()) {
       scoped_ptr<TracingDelegate> delegate(
           GetContentClient()->browser()->GetTracingDelegate());
       if (delegate) {
         trace_data_sink->SetMetadataFilterPredicate(
             delegate->GetMetadataFilterPredicate());
       }
     }
     trace_data_sink->AddMetadata(*GenerateTracingMetadataDict().get());
   }
 
-  if (!can_stop_tracing())
-    return false;
-
   trace_data_sink_ = trace_data_sink;
 
   // Issue clock sync marker before actually stopping tracing.
   // StopTracingAfterClockSync() will be called after clock sync is done.
   IssueClockSyncMarker();
 
   return true;
 }
 
 void TracingControllerImpl::StopTracingAfterClockSync() {
@@ skipping 324 matching lines @@
           BrowserThread::UI, FROM_HERE,
           base::Bind(&TracingControllerImpl::OnProcessMemoryDumpResponse,
                      base::Unretained(this),
                      make_scoped_refptr(trace_message_filter),
                      pending_memory_dump_guid_, false /* success */));
     }
   }
   trace_message_filters_.erase(trace_message_filter);
 }
 
+void TracingControllerImpl::AddTracingAgent(const std::string& agent_name) {
+#if defined(OS_CHROMEOS)
+  auto debug_daemon =
+      chromeos::DBusThreadManager::Get()->GetDebugDaemonClient();
+  if (agent_name == debug_daemon->GetTracingAgentName()) {
+    additional_tracing_agents_.push_back(debug_daemon);
+    debug_daemon->SetStopAgentTracingTaskRunner(
+        BrowserThread::GetBlockingPool());
+    return;
+  }
+#elif defined(OS_WIN)
+  auto etw_agent = EtwSystemEventConsumer::GetInstance();
+  if (agent_name == etw_agent->GetTracingAgentName()) {
+    additional_tracing_agents_.push_back(etw_agent);
+    return;
+  }
+#endif
+
+  auto power_agent = PowerTracingAgent::GetInstance();
+  if (agent_name == power_agent->GetTracingAgentName()) {
+    additional_tracing_agents_.push_back(power_agent);
+    return;
+  }
+
+  DCHECK(agent_name == kChromeTracingAgentName);
+}
+
+void TracingControllerImpl::OnStartAgentTracingAcked(
+    const std::string& agent_name,
+    bool success) {
+  DCHECK_CURRENTLY_ON(BrowserThread::UI);
+
+  // Don't taken any further action if the ack came after the deadline.
+  if (!start_tracing_timer_.IsRunning())
+    return;
+
+  if (success)
+    AddTracingAgent(agent_name);
+
+  if (--pending_start_tracing_ack_count_ == 0) {
+    start_tracing_timer_.Stop();
+    OnAllTracingAgentsStarted();
+  }
+}
+
 void TracingControllerImpl::OnStopTracingAcked(
     TraceMessageFilter* trace_message_filter,
     const std::vector<std::string>& known_category_groups) {
   if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) {
     BrowserThread::PostTask(BrowserThread::UI, FROM_HERE,
         base::Bind(&TracingControllerImpl::OnStopTracingAcked,
                    base::Unretained(this),
                    make_scoped_refptr(trace_message_filter),
                    known_category_groups));
     return;
@@ skipping 220 matching lines @@
 }
 
 std::string TracingControllerImpl::GetTracingAgentName() {
   return kChromeTracingAgentName;
 }
 
 std::string TracingControllerImpl::GetTraceEventLabel() {
   return kChromeTraceLabel;
 }
 
-bool TracingControllerImpl::StartAgentTracing(
-    const base::trace_event::TraceConfig& trace_config) {
+void TracingControllerImpl::StartAgentTracing(
+    const base::trace_event::TraceConfig& trace_config,
+    const StartAgentTracingCallback& callback) {
   DCHECK_CURRENTLY_ON(BrowserThread::UI);
 
-  base::Closure on_start_tracing_done_callback =
-      base::Bind(&TracingControllerImpl::OnStartAgentTracingDone,
-                 base::Unretained(this), trace_config);
+  base::Closure on_agent_started =
+      base::Bind(callback, kChromeTracingAgentName, true);
   if (!BrowserThread::PostTask(
           BrowserThread::FILE, FROM_HERE,
           base::Bind(&TracingControllerImpl::SetEnabledOnFileThread,
                      base::Unretained(this), trace_config,
                      base::trace_event::TraceLog::RECORDING_MODE,
-                     on_start_tracing_done_callback))) {
+                     on_agent_started))) {
     // BrowserThread::PostTask fails if the threads haven't been created yet,
     // so it should be safe to just use TraceLog::SetEnabled directly.
     base::trace_event::TraceLog::GetInstance()->SetEnabled(
         trace_config, base::trace_event::TraceLog::RECORDING_MODE);
-    BrowserThread::PostTask(BrowserThread::UI, FROM_HERE,
-                            on_start_tracing_done_callback);
+    BrowserThread::PostTask(BrowserThread::UI, FROM_HERE, on_agent_started);
   }
-
-  return true;
 }
 
 void TracingControllerImpl::StopAgentTracing(
     const StopAgentTracingCallback& callback) {
   DCHECK_CURRENTLY_ON(BrowserThread::UI);
   // Handle special case of zero child processes by immediately flushing the
   // trace log. Once the flush has completed the caller will be notified that
   // tracing has ended.
   if (pending_stop_tracing_ack_count_ == 1) {
     // Flush/cancel asynchronously now, because we don't have any children to
@@ skipping 51 matching lines @@
     }
   }
 
   // If no clock sync is needed, stop tracing right away. Otherwise, schedule
   // to stop tracing after timeout.
   if (pending_clock_sync_ack_count_ == 0) {
     StopTracingAfterClockSync();
   } else {
     clock_sync_timer_.Start(
         FROM_HERE,
-        base::TimeDelta::FromSeconds(kIssueClockSyncTimeout),
+        base::TimeDelta::FromSeconds(kIssueClockSyncTimeoutSeconds),
         this,
         &TracingControllerImpl::StopTracingAfterClockSync);
   }
 }
 
 void TracingControllerImpl::OnClockSyncMarkerRecordedByAgent(
     int sync_id,
     const base::TimeTicks& issue_ts,
     const base::TimeTicks& issue_end_ts) {
   DCHECK_CURRENTLY_ON(BrowserThread::UI);
@@ skipping 140 matching lines @@
   is_monitoring_ = is_monitoring;
 #if !defined(OS_ANDROID)
   for (std::set<TracingUI*>::iterator it = tracing_uis_.begin();
        it != tracing_uis_.end(); it++) {
     (*it)->OnMonitoringStateChanged(is_monitoring);
   }
 #endif
 }
 
 }  // namespace content