[DO NOT COMMIT] Refactor systrace to support new clock sync design

systrace/systrace/tracing_controller.py

Index: systrace/systrace/tracing_controller.py
diff --git a/systrace/systrace/tracing_controller.py b/systrace/systrace/tracing_controller.py
new file mode 100644
index 0000000000000000000000000000000000000000..768255d6f66313a9f2e521c4156ce9f301539021
--- /dev/null
+++ b/systrace/systrace/tracing_controller.py
@@ -0,0 +1,167 @@
+#!/usr/bin/env python
+
+# Copyright (c) 2016 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.
+
+'''Tracing controller class. This class manages
+multiple tracing agents and collects data from all of them. It also
+manages the clock sync process.
+'''
+
+import ast
+import tempfile
+import uuid
+
+import trace_event
+from devil.utils import reraiser_thread
+from systrace.tracing_agents import TracingAgent
+from systrace.tracing_agents import TraceResults
+
+
+class TracingController(TracingAgent):
+  def __init__(self, agents):
+    """Create tracing controller.
+
+    Create a tracing controller object. Note that the tracing
+    controller is also a tracing agent.
+
+    Args:
+       agents: List of tracing agents for this controller.
+    """
+    super(TracingController, self).__init__(None, None)
+    self._agents = agents
+    self._trace_in_progress = False
+    self._clock_sync_markers = []
+    self._log_path = None
+    self._all_results = None
+
+  def StartAgentTracing(self):
+    """Start tracing for the controller tracing agent.
+
+    Start tracing for the controller tracing agent. Note that
+    the tracing controller records the "controller side"
+    of the clock sync records, and nothing else.
+    """
+    if not trace_event.trace_can_enable():
+      raise RuntimeError, ('Cannot enable trace_event;'
+                           ' ensure catapult_base is in PYTHONPATH')
+
+    controller_log_file = tempfile.NamedTemporaryFile(delete=False)
+    self._log_path = controller_log_file.name
+    controller_log_file.close()
+    trace_event.trace_enable(self._log_path)
+    return True
+
+  @property
+  def trace_in_progress(self):
+    return self._trace_in_progress
+
+  def StopAgentTracing(self):
+    """Stops tracing for the controller tracing agent.
+    """
+    trace_event.trace_disable()
+    return True
+
+  def GetResults(self):
+    """Gets the log output from the controller tracing agent.
+
+    This output only contains the "controller side" of the clock sync records.
+    """
+    if self._trace_in_progress:
+      raise RuntimeError, 'Cannot get results while trace is in progress'
+    with open(self._log_path, 'r') as outfile:
+      result = outfile.read() + ']'
+    return TraceResults('traceEvents', ast.literal_eval(result))
+
+  def StartTracing(self):
+    """Start tracing for all tracing agents.
+
+    This function starts tracing for both the controller tracing agent
+    and the child tracing agents.
+
+    Returns:
+        Boolean indicating whether or not the start tracing succeeded
+        for all agents.
+    """
+    assert not self._trace_in_progress, 'Trace already in progress.'
+    self._trace_in_progress = True
+    if not self.StartAgentTracing():
+      print 'Unable to start controller tracing agent.'
+      return False
+    succ_agents = []
+    for agent in self._agents:
+      if agent.StartAgentTracing():
+        succ_agents.append(agent)
+    na = len(self._agents)
+    ns = len(succ_agents)
+    if ns < na:
+      print 'Warning: Only %d of %d tracing agents started.' % (na, ns)

[Zhen Wang, 2016/03/29 18:53:40]

Can we also print which agent is not started?

[alexandermont, 2016/03/30 01:04:25]

Done

+      self._agents = succ_agents
+
+  def StopTracing(self):
+    """Issue clock sync marker and stop tracing for all tracing agents.
+
+    This function stops both the controller tracing agent
+    and the child tracing agents. It issues a clock sync marker prior
+    to stopping tracing.
+
+    Returns:
+        Boolean indicating whether or not the stop tracing succeeded
+        for all agents.
+    """
+    assert self._trace_in_progress, 'No trace in progress.'
+    self._trace_in_progress = False
+    self._IssueClockSyncMarker()
+    succ_agents = []
+    for agent in self._agents:
+      if agent.StopAgentTracing():
+        succ_agents.append(agent)
+    if not self.StopAgentTracing():
+      print 'Unable to stop controller tracing agent.'
+      return False
+    na = len(self._agents)
+    ns = len(succ_agents)
+    if ns < na:
+      print 'Warning: Only %d of %d tracing agents stopped.' % (na, ns)

[Zhen Wang, 2016/03/29 18:53:40]

Can we also print which agent is not started?

[alexandermont, 2016/03/30 01:04:25]

Done

+      self._agents = succ_agents
+    self._all_results = {}
+    for agent in self._agents + [self]:
+      try:
+        (key, value) = agent.GetResults()
+        if key in self._all_results:
+          print 'Warning: Duplicate tracing agents'
+        self._all_results[key] = value
+      except reraiser_thread.TimeoutError:

[Zhen Wang, 2016/03/29 18:53:40]

Since not every agent will use timeout_retry, you will then need to add one more
catch for Exception.

[alexandermont, 2016/03/30 01:04:25]

Done. Note that it re-raises the exception if it's not a TimeoutError, since it
doesn't know whether the other exception represents a timeout or something more
serious.

+        print 'Warning: Timeout when getting results.'
+    return True
+
+  def SupportsExplicitClockSync(self):
+    '''Returns whether this supports explicit clock sync.
+
+    Although the tracing controller conceptually supports explicit clock
+    sync, it is not an agent controlled by other controllers so it does not
+    define RecordClockSyncMarker (rather, the recording of the "controller
+    side" of the clock sync marker is done in _IssueClockSyncMarker). Thus,
+    SupportsExplicitClockSync must return false.
+    '''
+    return False
+
+  def RecordClockSyncMarker(self, sync_id, callback):
+    raise NotImplementedError
+
+  def _IssueClockSyncMarker(self):
+    """Issue clock sync markers to all the child tracing agents."""
+    for agent in self._agents:
+      if agent.SupportsExplicitClockSync():
+        sync_id = GetUniqueSyncID()
+        callback = lambda t, s: trace_event.clock_sync(s, issue_ts=t)
+        agent.RecordClockSyncMarker(sync_id, callback)
+
+def GetUniqueSyncID():
+  """Get a unique sync ID.
+
+  Gets a unique sync ID by generating a UUID and converting it to a string
+  (since UUIDs are not JSON serializable)
+  """
+  return str(uuid.uuid4())