Head First Systrace

python systrace.py [options] [category1] [category2] ... [categoryN]

➜  ~ adb shell atrace -h
atrace: invalid option -- h

usage: atrace [options] [categories...]
options include:
  -a appname      enable app-level tracing for a comma separated list of cmdlines
  -b N            use a trace buffer size of N KB
  -c              trace into a circular buffer
  -k fname,...    trace the listed kernel functions
  -n              ignore signals
  -s N            sleep for N seconds before tracing [default 0]
  -t N            trace for N seconds [defualt 5]
  -z              compress the trace dump
  --async_start   start circular trace and return immediatly
  --async_dump    dump the current contents of circular trace buffer
  --async_stop    stop tracing and dump the current contents of circular
                    trace buffer
  --list_categories
                  list the available tracing categories

➜  systrace tree
.
├── AUTHORS
├── LICENSE
├── NOTICE
├── UPSTREAM_REVISION
├── agents
│   ├── __init__.py
│   └── atrace_agent.py
├── prefix.html
├── suffix.html
├── systrace-legacy.py
├── systrace.py
├── systrace_agent.py
├── systrace_trace_viewer.html
├── trace.html
└── util.py

1 directory, 14 files

# Make sure we're using a new enough version of Python.
# The flags= parameter of re.sub() is new in Python 2.7. And Systrace does not
# support Python 3 yet.
version = sys.version_info[:2]
if version != (2, 7):
  sys.stderr.write('This script does not support Python %d.%d. '
                   'Please use Python 2.7.\n' % version)
  sys.exit(1)

def main():
  options, categories = parse_options(sys.argv)
  agents = create_agents(options, categories)

  if not agents:
    dirs = DEFAULT_AGENT_DIR
    if options.agent_dirs:
      dirs += ',' + options.agent_dirs
    sys.stderr.write('No systrace agent is available in directories |%s|.\n' %
                     dirs)
    sys.exit(1)

  try:
    update_systrace_trace_viewer = __import__('update_systrace_trace_viewer')
  except ImportError:
    pass
  else:
    update_systrace_trace_viewer.update()

  for a in agents:
    a.start()

  for a in agents:
    a.collect_result()
    if not a.expect_trace():
      # Nothing more to do.
      return

  script_dir = os.path.dirname(os.path.abspath(sys.argv[0]))
  write_trace_html(options.output_file, script_dir, agents)

def parse_options(argv):
  """Parses and checks the command-line options.

  Returns:
    A tuple containing the options structure and a list of categories to
    be traced.
  """
  usage = 'Usage: %prog [options] [category1 [category2 ...]]'
  desc = 'Example: %prog -b 32768 -t 15 gfx input view sched freq'
  parser = optparse.OptionParser(usage=usage, description=desc)
  parser.add_option('-o', dest='output_file', help='write HTML to FILE',
                    default='trace.html', metavar='FILE')
  parser.add_option('-t', '--time', dest='trace_time', type='int',
                    help='trace for N seconds', metavar='N')
  parser.add_option('-b', '--buf-size', dest='trace_buf_size', type='int',
                    help='use a trace buffer size of N KB', metavar='N')
  ...... more options ......
  options, categories = parser.parse_args(argv[1:])

  if options.link_assets or options.asset_dir != 'trace-viewer':
    parser.error('--link-assets and --asset-dir are deprecated.')

  if (options.trace_time is not None) and (options.trace_time <= 0):
    parser.error('the trace time must be a positive number')

  if (options.trace_buf_size is not None) and (options.trace_buf_size <= 0):
    parser.error('the trace buffer size must be a positive number')

  return (options, categories)

def create_agents(options, categories):
  """Create systrace agents.

  This function will search systrace agent modules in agent directories and
  create the corresponding systrace agents.
  Args:
    options: The command-line options.
categories: "The"
  Returns:
    The list of systrace agents.
  """
  agent_dirs = [os.path.join(os.path.dirname(__file__), DEFAULT_AGENT_DIR)]
  if options.agent_dirs:
    agent_dirs.extend(options.agent_dirs.split(','))

  agents = []
  for agent_dir in agent_dirs:
    if not agent_dir:
      continue
    for filename in os.listdir(agent_dir):
      (module_name, ext) = os.path.splitext(filename)
      if (ext != '.py' or module_name == '__init__'
          or module_name.endswith('_unittest')):
        continue
      (f, pathname, data) = imp.find_module(module_name, [agent_dir])
      try:
        module = imp.load_module(module_name, f, pathname, data)
      finally:
        if f:
          f.close()
      if module:
        agent = module.try_create_agent(options, categories)
        if not agent:
          continue
        agents.append(agent)
  return agents

def write_trace_html(html_filename, script_dir, agents):
  """Writes out a trace html file.

  Args:
    html_filename: The name of the file to write.
    script_dir: The directory containing this script.
    agents: The systrace agents.
  """
  systrace_dir = os.path.abspath(os.path.dirname(__file__))
  html_prefix = read_asset(systrace_dir, 'prefix.html')
  html_suffix = read_asset(systrace_dir, 'suffix.html')
  trace_viewer_html = read_asset(script_dir, 'systrace_trace_viewer.html')

  # Open the file in binary mode to prevent python from changing the
  # line endings.
  html_file = open(html_filename, 'wb')
  html_file.write(html_prefix.replace('{{SYSTRACE_TRACE_VIEWER_HTML}}',
                                      trace_viewer_html))

  html_file.write('<!-- BEGIN TRACE -->\n')
  for a in agents:
    html_file.write('  <script class="')
    html_file.write(a.get_class_name())
    html_file.write('" type="application/text">\n')
    html_file.write(a.get_trace_data())
    html_file.write('  </script>\n')
  html_file.write('<!-- END TRACE -->\n')

  html_file.write(html_suffix)
  html_file.close()
  print('\n    wrote file://%s\n' % os.path.abspath(html_filename))

def run_adb_shell(shell_args, device_serial):
  """Runs "adb shell" with the given arguments.

  Args:
    shell_args: array of arguments to pass to adb shell.
    device_serial: if not empty, will add the appropriate command-line
        parameters so that adb targets the given device.
  Returns:
    A tuple containing the adb output (stdout & stderr) and the return code
    from adb.  Will exit if adb fails to start.
  """
  adb_command = construct_adb_shell_command(shell_args, device_serial)

  adb_output = []
  adb_return_code = 0
  try:
    adb_output = subprocess.check_output(adb_command, stderr=subprocess.STDOUT,
                                         shell=False, universal_newlines=True)
  except OSError as error:
    # This usually means that the adb executable was not found in the path.
    print >> sys.stderr, ('\nThe command "%s" failed with the following error:'
                          % ' '.join(adb_command))
    print >> sys.stderr, '    %s' % str(error)
    print >> sys.stderr, 'Is adb in your path?'
    adb_return_code = error.errno
    adb_output = error
  except subprocess.CalledProcessError as error:
    # The process exited with an error.
    adb_return_code = error.returncode
    adb_output = error.output

  return (adb_output, adb_return_code)

def get_device_sdk_version():
  """Uses adb to attempt to determine the SDK version of a running device."""

  getprop_args = ['getprop', 'ro.build.version.sdk']

  # get_device_sdk_version() is called before we even parse our command-line
  # args.  Therefore, parse just the device serial number part of the
  # command-line so we can send the adb command to the correct device.
  parser = OptionParserIgnoreErrors()
  parser.add_option('-e', '--serial', dest='device_serial', type='string')
  options, unused_args = parser.parse_args() # pylint: disable=unused-variable

  success = False

  adb_output, adb_return_code = run_adb_shell(getprop_args,
                                              options.device_serial)

  if adb_return_code == 0:
    # ADB may print output other than the version number (e.g. it chould
    # print a message about starting the ADB server).
    # Break the ADB output into white-space delimited segments.
    parsed_output = str.split(adb_output)
    if parsed_output:
      # Assume that the version number is the last thing printed by ADB.
      version_string = parsed_output[-1]
      if version_string:
        try:
          # Try to convert the text into an integer.
          version = int(version_string)
        except ValueError:
          version = -1
        else:
          success = True

  if not success:
    print >> sys.stderr, (
        '\nThe command "%s" failed with the following message:'
        % ' '.join(getprop_args))
    print >> sys.stderr, adb_output
    sys.exit(1)

  return version

class SystraceAgent(object):
  """The base class for systrace agents.

  A systrace agent contains the command-line options and trace categories to
  capture. Each systrace agent has its own tracing implementation.
  """

  def __init__(self, options, categories):
    """Initialize a systrace agent.

    Args:
      options: The command-line options.
categories: "The"
    """
    self._options = options
    self._categories = categories

  def start(self):
    """Start tracing.
    """
    raise NotImplementedError()

  def collect_result(self):
    """Collect the result of tracing.

    This function will block while collecting the result. For sync mode, it
    reads the data, e.g., from stdout, until it finishes. For async mode, it
    blocks until the agent is stopped and the data is ready.
    """
    raise NotImplementedError()

  def expect_trace(self):
    """Check if the agent is returning a trace or not.

    This will be determined in collect_result().
    Returns:
      Whether the agent is expecting a trace or not.
    """
    raise NotImplementedError()

  def get_trace_data(self):
    """Get the trace data.

    Returns:
      The trace data.
    """
    raise NotImplementedError()

  def get_class_name(self):
    """Get the class name

    The class name is used to identify the trace type when the trace is written
    to the html file
    Returns:
      The class name.
    """
    raise NotImplementedError()

def try_create_agent(options, categories):
  if options.target != 'android':
    return False
  if options.from_file is not None:
    return AtraceAgent(options, categories)

  device_sdk_version = util.get_device_sdk_version()
  if device_sdk_version >= 18:
    if options.boot:
      # atrace --async_stop, which is used by BootAgent, does not work properly
      # on the device SDK version 22 or before.
      if device_sdk_version <= 22:
        print >> sys.stderr, ('--boot option does not work on the device SDK '
                              'version 22 or before.\nYour device SDK version '
                              'is %d.' % device_sdk_version)
        sys.exit(1)
      return BootAgent(options, categories)
    else:
      return AtraceAgent(options, categories)
  elif device_sdk_version >= 16:
    return AtraceLegacyAgent(options, categories)

LEGACY_TRACE_TAG_BITS = (
  ('gfx',       1<<1),
  ('input',     1<<2),
  ('view',      1<<3),
  ('webview',   1<<4),
  ('wm',        1<<5),
  ('am',        1<<6),
  ('sm',        1<<7),
  ('audio',     1<<8),
  ('video',     1<<9),
  ('camera',    1<<10),
)

class FileReaderThread(threading.Thread):
  """Reads data from a file/pipe on a worker thread.

  Use the standard threading. Thread object API to start and interact with the
  thread (start(), join(), etc.).
  """

  def __init__(self, file_object, output_queue, text_file, chunk_size=-1):
    """Initializes a FileReaderThread.

    Args:
      file_object: The file or pipe to read from.
      output_queue: A Queue.Queue object that will receive the data
      text_file: If True, the file will be read one line at a time, and
          chunk_size will be ignored.  If False, line breaks are ignored and
          chunk_size must be set to a positive integer.
      chunk_size: When processing a non-text file (text_file = False),
          chunk_size is the amount of data to copy into the queue with each
          read operation.  For text files, this parameter is ignored.
    """
    threading.Thread.__init__(self)
    self._file_object = file_object
    self._output_queue = output_queue
    self._text_file = text_file
    self._chunk_size = chunk_size
    assert text_file or chunk_size > 0

  def run(self):
    """Overrides Thread's run() function.

    Returns when an EOF is encountered.
    """
    if self._text_file:
      # Read a text file one line at a time.
      for line in self._file_object:
        self._output_queue.put(line)
    else:
      # Read binary or text data until we get to EOF.
      while True:
        chunk = self._file_object.read(self._chunk_size)
        if not chunk:
          break
        self._output_queue.put(chunk)

  def set_chunk_size(self, chunk_size):
    """Change the read chunk size.

    This function can only be called if the FileReaderThread object was
    created with an initial chunk_size > 0.
    Args:
      chunk_size: the new chunk size for this file.  Must be > 0.
    """
    # The chunk size can be changed asynchronously while a file is being read
    # in a worker thread.  However, type of file can not be changed after the
    # the FileReaderThread has been created.  These asserts verify that we are
    # only changing the chunk size, and not the type of file.
    assert not self._text_file
    assert chunk_size > 0
    self._chunk_size = chunk_size

class AtraceAgent(systrace_agent.SystraceAgent):
  def __init__(self, options, categories):
    super(AtraceAgent, self).__init__(options, categories)
    self._expect_trace = False
    self._adb = None
    self._trace_data = None
    self._tracer_args = None
    if not self._categories:
      self._categories = get_default_categories(self._options.device_serial)

  def start(self):
    self._tracer_args = self._construct_trace_command()

    self._adb = do_popen(self._tracer_args)

  def collect_result(self):
    trace_data = self._collect_trace_data()
    if self._expect_trace:
      self._trace_data = self._preprocess_trace_data(trace_data)

  def expect_trace(self):
    return self._expect_trace

  def get_trace_data(self):
    return self._trace_data

  def get_class_name(self):
    return 'trace-data'

def _construct_trace_command(self):
"""Builds a command-line used to invoke a trace process.

Returns:
 A tuple where the first element is an array of command-line arguments, and
 the second element is a boolean which will be true if the commend will
 stream trace data.
"""
if self._options.list_categories:
 tracer_args = self._construct_list_categories_command()
 self._expect_trace = False
elif self._options.from_file is not None:
 tracer_args = ['cat', self._options.from_file]
 self._expect_trace = True
else:
 atrace_args = ATRACE_BASE_ARGS[:]
 self._expect_trace = True
 if self._options.compress_trace_data:
   atrace_args.extend(['-z'])

 if ((self._options.trace_time is not None)
     and (self._options.trace_time > 0)):
   atrace_args.extend(['-t', str(self._options.trace_time)])

 if ((self._options.trace_buf_size is not None)
     and (self._options.trace_buf_size > 0)):
   atrace_args.extend(['-b', str(self._options.trace_buf_size)])
 elif 'sched' in self._categories:
   # 'sched' is a high-volume tag, double the default buffer size
   # to accommodate that
   atrace_args.extend(['-b', '4096'])
 extra_args = self._construct_extra_trace_command()
 atrace_args.extend(extra_args)

 tracer_args = util.construct_adb_shell_command(
     atrace_args, self._options.device_serial)

return tracer_args

def _collect_trace_data(self):
  # Read the output from ADB in a worker thread.  This allows us to monitor
  # the progress of ADB and bail if ADB becomes unresponsive for any reason.

  # Limit the stdout_queue to 128 entries because we will initially be reading
  # one byte at a time.  When the queue fills up, the reader thread will
  # block until there is room in the queue.  Once we start downloading the
  # trace data, we will switch to reading data in larger chunks, and 128
  # entries should be plenty for that purpose.
  stdout_queue = Queue.Queue(maxsize=128)
  stderr_queue = Queue.Queue()

  if self._expect_trace:
    # Use stdout.write() (here and for the rest of this function) instead
    # of print() to avoid extra newlines.
    sys.stdout.write('Capturing trace...')

  # Use a chunk_size of 1 for stdout so we can display the output to
  # the user without waiting for a full line to be sent.
  stdout_thread = FileReaderThread(self._adb.stdout, stdout_queue,
                                   text_file=False, chunk_size=1)
  stderr_thread = FileReaderThread(self._adb.stderr, stderr_queue,
                                   text_file=True)
  stdout_thread.start()
  stderr_thread.start()

  # Holds the trace data returned by ADB.
  trace_data = []
  # Keep track of the current line so we can find the TRACE_START_REGEXP.
  current_line = ''
  # Set to True once we've received the TRACE_START_REGEXP.
  reading_trace_data = False

  last_status_update_time = time.time()

  while (stdout_thread.isAlive() or stderr_thread.isAlive() or
         not stdout_queue.empty() or not stderr_queue.empty()):
    if self._expect_trace:
      last_status_update_time = status_update(last_status_update_time)

    while not stderr_queue.empty():
      # Pass along errors from adb.
      line = stderr_queue.get()
      sys.stderr.write(line)

    # Read stdout from adb.  The loop exits if we don't get any data for
    # ADB_STDOUT_READ_TIMEOUT seconds.
    while True:
      try:
        chunk = stdout_queue.get(True, ADB_STDOUT_READ_TIMEOUT)
      except Queue.Empty:
        # Didn't get any data, so exit the loop to check that ADB is still
        # alive and print anything sent to stderr.
        break

      if reading_trace_data:
        # Save, but don't print, the trace data.
        trace_data.append(chunk)
      else:
        if not self._expect_trace:
          sys.stdout.write(chunk)
        else:
          # Buffer the output from ADB so we can remove some strings that
          # don't need to be shown to the user.
          current_line += chunk
          if re.match(TRACE_START_REGEXP, current_line):
            # We are done capturing the trace.
            sys.stdout.write('Done.\n')
            # Now we start downloading the trace data.
            sys.stdout.write('Downloading trace...')

            current_line = ''
            # Use a larger chunk size for efficiency since we no longer
            # need to worry about parsing the stream.
            stdout_thread.set_chunk_size(4096)
            reading_trace_data = True
          elif chunk == '\n' or chunk == '\r':
            # Remove ADB output that we don't care about.
            current_line = re.sub(ADB_IGNORE_REGEXP, '', current_line)
            if len(current_line) > 1:
              # ADB printed something that we didn't understand, so show it
              # it to the user (might be helpful for debugging).
              sys.stdout.write(current_line)
            # Reset our current line.
            current_line = ''

  if self._expect_trace:
    if reading_trace_data:
      # Indicate to the user that the data download is complete.
      sys.stdout.write('Done.\n')
    else:
      # We didn't receive the trace start tag, so something went wrong.
      sys.stdout.write('ERROR.\n')
      # Show any buffered ADB output to the user.
      current_line = re.sub(ADB_IGNORE_REGEXP, '', current_line)
      if current_line:
        sys.stdout.write(current_line)
        sys.stdout.write('\n')

  # The threads should already have stopped, so this is just for cleanup.
  stdout_thread.join()
  stderr_thread.join()

  self._adb.stdout.close()
  self._adb.stderr.close()

  # The adb process should be done since it's io pipes are closed.  Call
  # poll() to set the return code.
  self._adb.poll()

  if self._adb.returncode != 0:
    print >> sys.stderr, ('The command "%s" returned error code %d.' %
                          (' '.join(self._tracer_args), self._adb.returncode))
    sys.exit(1)

  return trace_data

  def _preprocess_trace_data(self, trace_data):
    """Performs various processing on atrace data.

    Args:
      trace_data: The raw trace data.
    Returns:
      The processed trace data.
    """
    trace_data = ''.join(trace_data)
    if trace_data:
      trace_data = strip_and_decompress_trace(trace_data)

    if not trace_data:
      print >> sys.stderr, ('No data was captured.  Output file was not '
                            'written.')
      sys.exit(1)

    if self._options.fix_threads:
      # Issue ps command to device and patch thread names
      ps_dump = do_preprocess_adb_cmd('ps -t', self._options.device_serial)
      if ps_dump is not None:
        thread_names = extract_thread_list(ps_dump)
        trace_data = fix_thread_names(trace_data, thread_names)

    if self._options.fix_tgids:
      # Issue printf command to device and patch tgids
      procfs_dump = do_preprocess_adb_cmd('printf "%s\n" ' +
                                          '/proc/[0-9]*/task/[0-9]*',
                                          self._options.device_serial)
      if procfs_dump is not None:
        pid2_tgid = extract_tgids(procfs_dump)
        trace_data = fix_missing_tgids(trace_data, pid2_tgid)

    if self._options.fix_circular:
      trace_data = fix_circular_traces(trace_data)

    return trace_data

class AtraceLegacyAgent(AtraceAgent):
  def _construct_list_categories_command(self):
    LEGACY_CATEGORIES = """       sched - CPU Scheduling
        freq - CPU Frequency
        idle - CPU Idle
        load - CPU Load
        disk - Disk I/O (requires root)
         bus - Bus utilization (requires root)
   workqueue - Kernel workqueues (requires root)"""
    return ["echo", LEGACY_CATEGORIES]

  def start(self):
    super(AtraceLegacyAgent, self).start()
    if self.expect_trace():
      SHELL_ARGS = ['getprop', 'debug.atrace.tags.enableflags']
      output, return_code = util.run_adb_shell(SHELL_ARGS,
                                               self._options.device_serial)
      if return_code != 0:
        print >> sys.stderr, (
            '\nThe command "%s" failed with the following message:'
            % ' '.join(SHELL_ARGS))
        print >> sys.stderr, str(output)
        sys.exit(1)

      flags = 0
      try:
        if output.startswith('0x'):
          flags = int(output, 16)
        elif output.startswith('0'):
          flags = int(output, 8)
        else:
          flags = int(output)
      except ValueError:
        pass

      if flags:
        tags = []
        for desc, bit in LEGACY_TRACE_TAG_BITS:
          if bit & flags:
            tags.append(desc)
        categories = tags + self._categories
        print 'Collecting data with following categories:', ' '.join(categories)

  def _construct_extra_trace_command(self):
    extra_args = []
    if not self._categories:
      self._categories = ['sched', ]
    if 'sched' in self._categories:
      extra_args.append('-s')
    if 'freq' in self._categories:
      extra_args.append('-f')
    if 'idle' in self._categories:
      extra_args.append('-i')
    if 'load' in self._categories:
      extra_args.append('-l')
    if 'disk' in self._categories:
      extra_args.append('-d')
    if 'bus' in self._categories:
      extra_args.append('-u')
    if 'workqueue' in self._categories:
      extra_args.append('-w')

    return extra_args

class BootAgent(AtraceAgent):
  """AtraceAgent that specializes in tracing the boot sequence."""

  def __init__(self, options, categories):
    super(BootAgent, self).__init__(options, categories)

  def start(self):
    try:
      setup_args = self._construct_setup_command()
      try:
        subprocess.check_call(setup_args)
        print 'Hit Ctrl+C once the device has booted up.'
        while True:
          time.sleep(1)
      except KeyboardInterrupt:
        pass
      tracer_args = self._construct_trace_command()
      self._adb = subprocess.Popen(tracer_args, stdout=subprocess.PIPE,
                                   stderr=subprocess.PIPE)
    except OSError as error:
      print >> sys.stderr, (
          'The command "%s" failed with the following error:' %
          ' '.join(tracer_args))
      print >> sys.stderr, '    ', error
      sys.exit(1)

  def _construct_setup_command(self):
    echo_args = ['echo'] + self._categories + ['>', BOOTTRACE_CATEGORIES]
    setprop_args = ['setprop', BOOTTRACE_PROP, '1']
    reboot_args = ['reboot']
    return util.construct_adb_shell_command(
        echo_args + ['&&'] + setprop_args + ['&&'] + reboot_args,
        self._options.device_serial)

  def _construct_trace_command(self):
    self._expect_trace = True
    atrace_args = ['atrace', '--async_stop']
    setprop_args = ['setprop', BOOTTRACE_PROP, '0']
    rm_args = ['rm', BOOTTRACE_CATEGORIES]
    return util.construct_adb_shell_command(
          atrace_args + ['&&'] + setprop_args + ['&&'] + rm_args,
          self._options.device_serial)