[Tracing Clock Sync] Implement clock sync in Chrome

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"
@@ skipping 130 matching lines @@
 }
 
 TracingControllerImpl::TracingControllerImpl()
     : 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) {
   base::trace_event::MemoryDumpManager::GetInstance()->Initialize(
       this /* delegate */, true /* is_coordinator */);
 
   // Deliberately leaked, like this class.
   base::FileTracing::SetProvider(new FileTracingProviderImpl);
 }
 
 TracingControllerImpl::~TracingControllerImpl() {
@@ skipping 119 matching lines @@
             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() {
+  DCHECK_CURRENTLY_ON(BrowserThread::UI);
   // Disable local trace early to avoid traces during end-tracing process from
   // interfering with the process.
   base::Closure on_stop_tracing_done_callback = base::Bind(
       &TracingControllerImpl::OnStopTracingDone, base::Unretained(this));
   BrowserThread::PostTask(BrowserThread::FILE, FROM_HERE,
       base::Bind(&TracingControllerImpl::SetDisabledOnFileThread,
                  base::Unretained(this),
                  on_stop_tracing_done_callback));
-  return true;
 }
 
 void TracingControllerImpl::OnStopTracingDone() {
   DCHECK_CURRENTLY_ON(BrowserThread::UI);
 
 #if defined(OS_ANDROID)
   if (pending_get_categories_done_callback_.is_null())
     TraceLog::GetInstance()->AddClockSyncMetadataEvent();
 #endif
 
@@ skipping 597 matching lines @@
   // Notify all child processes.
   for (auto it : trace_message_filters_) {
     if (trace_data_sink_)
       it->SendEndTracing();
     else
       it->SendCancelTracing();
   }
 }
 
 bool TracingControllerImpl::SupportsExplicitClockSync() {
-  // TODO(zhenw): return true after implementing explicit clock sync.
-  return false;
+  return true;
 }
 
 void TracingControllerImpl::RecordClockSyncMarker(
     int sync_id,
     const RecordClockSyncMarkerCallback& callback) {
   DCHECK(SupportsExplicitClockSync());
-  // TODO(zhenw): implement explicit clock sync.
+
+  TRACE_EVENT_CLOCK_SYNC_RECEIVER(sync_id);
+}
+
+int TracingControllerImpl::GetUniqueClockSyncID() {
+  DCHECK_CURRENTLY_ON(BrowserThread::UI);
+  // There is no need to lock because this function only runs on UI thread.
+  clock_sync_id_ += 1;
+  return clock_sync_id_;

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

nit: return ++clock_sync_id_;

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

Done. Is there any reason to prefer combining those two statements into one?

 }
 
 void TracingControllerImpl::IssueClockSyncMarker() {
-  // TODO(zhenw): implement explicit clock sync.
+  DCHECK_CURRENTLY_ON(BrowserThread::UI);
+
+  pending_clock_sync_ack_count_ = 0;

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

Can this be != 0 at this point? Would we ever have overlapping clock sync
requests? Should we DCHECK for this?

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

Updated to CHECK. But how about the following scenario?
1. During the last tracing session, one agent disappeared (e.g., due to USB
disconnection for battor device).
2. So in the last tracing session, it timed out to stop tracing and
pending_clock_sync_ack_count_ never goes back to 0 because BattOrAgent never
reports back.
3. Now in the new tracing session, the DCHECK/CHECK will fail here.

+  for (auto it : additional_tracing_agents_) {

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

nit: const auto& it

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

Done.

+    if (it->SupportsExplicitClockSync()) {
+      it->RecordClockSyncMarker(
+          GetUniqueClockSyncID(),
+          base::Bind(&TracingControllerImpl::OnClockSyncMarkerRecordedByAgent,
+                     base::Unretained(this)));
+      pending_clock_sync_ack_count_++;
+    }
+  }
+
+  // No clock sync is needed, stop tracing right away.
+  if (pending_clock_sync_ack_count_ == 0)
+    StopTracingAfterClockSync();
+}
+
+void TracingControllerImpl::OnClockSyncMarkerRecordedByAgent(
+    int sync_id,
+    const base::TimeTicks& issue_ts,
+    const base::TimeTicks& issue_end_ts) {
+  DCHECK_CURRENTLY_ON(BrowserThread::UI);
+
+  TRACE_EVENT_CLOCK_SYNC_ISSUER(sync_id, issue_ts, issue_end_ts);
+
+  pending_clock_sync_ack_count_--;

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

nit: if(--pending_clock_sync_ack_count_ == 0).

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

Done.

+  if (pending_clock_sync_ack_count_ == 0)

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

I feel like this makes the API a little bit fragile; it'll break if the list of
agents changes or if one doesn't report back. Maybe we should add a timeout, at
least?

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

Done.

+    StopTracingAfterClockSync();
 }
 
 void TracingControllerImpl::RequestGlobalMemoryDump(
     const base::trace_event::MemoryDumpRequestArgs& args,
     const base::trace_event::MemoryDumpCallback& callback) {
   if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) {
     BrowserThread::PostTask(
         BrowserThread::UI, FROM_HERE,
         base::Bind(&TracingControllerImpl::RequestGlobalMemoryDump,
                    base::Unretained(this), args, callback));
@@ skipping 118 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