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/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 kStartTracingTimeout = 30;
 const int kIssueClockSyncTimeout = 30;
 
 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";
@@ skipping 74 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 (trace_data_sink) {
     if (TraceLog::GetInstance()->GetCurrentTraceConfig()
         .IsArgumentFilterEnabled()) {
       scoped_ptr<TracingDelegate> delegate(
@@ skipping 346 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(

[oystein (OOO til 10th of July), 2016/01/25 22:19:41]

What happens if StopTracing() gets called before all the callbacks have been
called? Looks like we may be getting in some inconsistent state at that point;
may need to insert a check, though I could be wrong.

[charliea (OOO until 10-5), 2016/01/26 00:30:09]

One thing that we could do is, when StopTracing is called, do something like:

if (start_tracing_timer_.IsRunning()) {
  start_tracing_timer_.Stop();
  OnAllTracingAgentsStarted();
  PostTask(BrowserThread::UI, base::Bind(&StopTracing, base::Unretained(this),
trace_data_sink));
}

In other words, if we see that we're still waiting for tracing agents,
immediately stop the timer to signal that the window has closed for agents to
register themselves, signal that all tracing agents are started to do any
necessary cleanup, and then retry StopTracing. I could see this could be
problematic if the StopTracing code relied on posted tasks from within
OnAllTracingAgentsStarted to be run, though, because I don't think the order of
execution of tasks is guaranteed within task runners. That's the most reasonable
thing I can think of. WDYT?

+    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 212 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