[Tracing Clock Sync] Implement clock sync in Chrome

content/browser/tracing/power_tracing_agent.cc

Index: content/browser/tracing/power_tracing_agent.cc
diff --git a/content/browser/tracing/power_tracing_agent.cc b/content/browser/tracing/power_tracing_agent.cc
index 6be153a81759bc512b38b84f7c7061eb5240a4a7..67ea21d201276886d0bf063db6a04977495e5f4f 100644
--- a/content/browser/tracing/power_tracing_agent.cc
+++ b/content/browser/tracing/power_tracing_agent.cc
@@ -23,8 +23,9 @@ PowerTracingAgent* PowerTracingAgent::GetInstance() {
   return base::Singleton<PowerTracingAgent>::get();
 }
 
-PowerTracingAgent::PowerTracingAgent() : is_tracing_(false) {
+PowerTracingAgent::PowerTracingAgent() : thread_("PowerTracingAgentThread") {
   battor_trace_provider_.reset(new BattorPowerTraceProvider());
+  thread_.Start();

[oystein (OOO til 10th of July), 2015/12/16 02:10:05]

I'm not sure if the lifespan of the thread should be tied to the lifespan of the
singleton like this. Can we tie it to the lifespan of the tracing session
instead? I.e. start it when we start tracing, stop it when we end tracing.

[Zhen Wang, 2015/12/16 23:49:12]

If stopping the thread when we end tracing, thread_.Stop() will be called on the
UI thread. It will fail the check to allow IO. See the stack below:

#0 0x7f71320151be base::debug::StackTrace::StackTrace()
#1 0x7f713206f17f logging::LogMessage::~LogMessage()
#2 0x7f713216c76f base::ThreadRestrictions::AssertIOAllowed()
#3 0x7f713214f7d4 base::PlatformThread::Join()
#4 0x7f7132161fca base::Thread::Stop()
#5 0x7f7137fa9e8b content::PowerTracingAgent::OnStopTracingDone()

Is there a way to get around this? I see EtwSystemEventConsumer stops the thread
on the UI thread, why can it do that?
https://code.google.com/p/chromium/codesearch#chromium/src/content/browser/tr...

 }
 
 PowerTracingAgent::~PowerTracingAgent() {}
@@ -39,45 +40,44 @@ std::string PowerTracingAgent::GetTraceEventLabel() {
 
 bool PowerTracingAgent::StartAgentTracing(
     const base::trace_event::TraceConfig& trace_config) {
-  // Tracing session already in progress.
-  if (is_tracing_)
-    return false;
-
-  // TODO(prabhur) Start tracing probably needs to be done in a
-  // separate thread since it involves talking to the h/w.
-  // Revisit once battor h/w communication is enabled.
-  is_tracing_ = battor_trace_provider_->StartTracing();
-  return is_tracing_;
+  DCHECK_CURRENTLY_ON(BrowserThread::UI);
+  DCHECK(thread_.IsRunning());
+
+  thread_.task_runner()->PostTask(
+      FROM_HERE,
+      base::Bind(&PowerTracingAgent::TraceOnThread, base::Unretained(this)));
+  return true;
 }
 
 void PowerTracingAgent::StopAgentTracing(
     const StopAgentTracingCallback& callback) {
-  // No tracing session in progress.
-  if (!is_tracing_)
-    return;
+  DCHECK_CURRENTLY_ON(BrowserThread::UI);
+  DCHECK(thread_.IsRunning());
 
-  // Stop tracing & collect logs.
-  BrowserThread::PostTask(
-      BrowserThread::UI, FROM_HERE,
-      base::Bind(&PowerTracingAgent::FlushOnThread,
-                 base::Unretained(this),
+  thread_.task_runner()->PostTask(
+      FROM_HERE,
+      base::Bind(&PowerTracingAgent::FlushOnThread, base::Unretained(this),
                  callback));
 }
 
 void PowerTracingAgent::OnStopTracingDone(
     const StopAgentTracingCallback& callback,
     const scoped_refptr<base::RefCountedString>& result) {
-  is_tracing_ = false;
+  DCHECK_CURRENTLY_ON(BrowserThread::UI);
+
   // Pass the serialized events.
   callback.Run(GetTracingAgentName(), GetTraceEventLabel(), result);
 }
 
+void PowerTracingAgent::TraceOnThread() {
+  DCHECK(thread_.task_runner()->BelongsToCurrentThread());
+  battor_trace_provider_->StartTracing();
+}
+
 void PowerTracingAgent::FlushOnThread(
     const StopAgentTracingCallback& callback) {
-  // Pass the result to the UI Thread.
+  DCHECK(thread_.task_runner()->BelongsToCurrentThread());
 
-  // TODO(prabhur) StopTracing & GetLog need to be called on a
-  // separate thread depending on how BattorPowerTraceProvider is implemented.
   battor_trace_provider_->StopTracing();
   std::string battor_logs;
   battor_trace_provider_->GetLog(&battor_logs);
@@ -92,15 +92,36 @@ void PowerTracingAgent::FlushOnThread(
 }
 
 bool PowerTracingAgent::SupportsExplicitClockSync() {
-  // TODO(zhenw): return true after implementing explicit clock sync.
-  return false;
+  return true;
 }
 
 void PowerTracingAgent::RecordClockSyncMarker(
     int sync_id,
     const RecordClockSyncMarkerCallback& callback) {
+  DCHECK_CURRENTLY_ON(BrowserThread::UI);
   DCHECK(SupportsExplicitClockSync());
-  // TODO(zhenw): implement explicit clock sync.
+
+  thread_.task_runner()->PostTask(
+      FROM_HERE,
+      base::Bind(&PowerTracingAgent::RecordClockSyncMarkerOnThread,
+                 base::Unretained(this),
+                 sync_id,
+                 callback));
+}
+
+void PowerTracingAgent::RecordClockSyncMarkerOnThread(
+    int sync_id,
+    const RecordClockSyncMarkerCallback& callback) {
+  DCHECK(thread_.task_runner()->BelongsToCurrentThread());
+  DCHECK(SupportsExplicitClockSync());
+
+  base::TimeTicks issue_ts = base::TimeTicks::Now();
+  battor_trace_provider_->RecordClockSyncMarker(sync_id);
+  base::TimeTicks issue_end_ts = base::TimeTicks::Now();
+
+  BrowserThread::PostTask(
+      BrowserThread::UI, FROM_HERE,
+      base::Bind(callback, sync_id, issue_ts, issue_end_ts));
 }
 
 }  // namespace content