[fuchsia] Modify runner scripts and build files to use new symbolizer.

* Modify the stream-merging code to output to a pipe instead of a
  Python generator, so that the "symbolize" tool can read both app
  and kernel logs.
* Rename "build_manifest.py" to "prepare_package_inputs.py" to better
  capture the broader scope of that script.
* Add ids.txt generation logic to prepare_package_inputs.py.
* Remove dead codepath for disabling symbolization. Symbolization has
  been forced-on by the build scripts with no issues so far, so having
  an opt-out is unnecessary.


Bug: 772252
Change-Id: I4e01d0fc5ce96521efa6d0d394e629cb5c7985ff
Reviewed-on: https://chromium-review.googlesource.com/c/1474032
Commit-Queue: Wez <wez@chromium.org>
Reviewed-by: Wez <wez@chromium.org>
Cr-Commit-Position: refs/heads/master@{#634879}

build/config/fuchsia/package.gni

@@ -38,6 +38,7 @@ template("fuchsia_package") {
   _pkg_out_dir = "${target_gen_dir}/${pkg.package_name}"
   _runtime_deps_file = "$_pkg_out_dir/${pkg.package_name}.runtime_deps"
   _archive_manifest = "$_pkg_out_dir/${pkg.package_name}.archive_manifest"
+  _build_ids_file = "$_pkg_out_dir/ids.txt"
   _component_manifest = "$_pkg_out_dir/${pkg.package_name}.cmx"
   _key_file = "$_pkg_out_dir/signing-key"
   _meta_far_file = "$_pkg_out_dir/meta.far"
@@ -61,7 +62,7 @@ template("fuchsia_package") {
                              "testonly",
                            ])
 
-    script = "//build/config/fuchsia/build_manifest.py"
+    script = "//build/config/fuchsia/prepare_package_inputs.py"
 
     inputs = [
       _runtime_deps_file,
@@ -70,6 +71,7 @@ template("fuchsia_package") {
 
     outputs = [
       _archive_manifest,
+      _build_ids_file,
       _component_manifest,
     ]
 
@@ -98,8 +100,10 @@ template("fuchsia_package") {
       rebase_path(_runtime_deps_file, root_build_dir),
       "--depfile-path",
       rebase_path(_depfile, root_build_dir),
-      "--output-path",
+      "--manifest-path",
       rebase_path(_archive_manifest, root_build_dir),
+      "--build-ids-file",
+      rebase_path(_build_ids_file, root_build_dir),
     ]
 
     if (defined(pkg.excluded_files)) {
@@ -215,6 +219,7 @@ template("fuchsia_package") {
     data = [
       _final_far_file,
       _package_info_path,
+      _build_ids_file,
     ]
 
     sources = [

build/config/fuchsia/build_manifest.py → build/config/fuchsia/prepare_package_inputs.py

@@ -66,8 +66,48 @@ def _IsBinary(path):
   return file_tag == '\x7fELF'
 
 
+def _WriteBuildIdsTxt(binary_paths, ids_txt_path):
+  """Writes an index text file that maps build IDs to the paths of unstripped
+  binaries."""
+
+  READELF_FILE_PREFIX = 'File: '
+  READELF_BUILD_ID_PREFIX = 'Build ID: '
+
+  # List of binaries whose build IDs are awaiting processing by readelf.
+  # Entries are removed as readelf's output is parsed.
+  unprocessed_binary_paths = {os.path.basename(p): p for p in binary_paths}
+
+  with open(ids_txt_path, 'w') as ids_file:
+    readelf_stdout = subprocess.check_output(
+        ['readelf', '-n'] + map(_GetStrippedPath, binary_paths))
+
+    if len(binary_paths) == 1:
+      # Readelf won't report a binary's path if only one was provided to the
+      # tool.
+      binary_shortname = binary_paths[0]
+    else:
+      binary_shortname = None
+
+    for line in readelf_stdout.split('\n'):
+      line = line.strip()
+
+      if line.startswith(READELF_FILE_PREFIX):
+        binary_shortname = os.path.basename(line[len(READELF_FILE_PREFIX):])
+        assert binary_shortname in unprocessed_binary_paths
+
+      elif line.startswith(READELF_BUILD_ID_PREFIX):
+        build_id = line[len(READELF_BUILD_ID_PREFIX):]
+        ids_file.write(build_id + ' ' +
+                       unprocessed_binary_paths[binary_shortname])
+        del unprocessed_binary_paths[binary_shortname]
+
+  # Did readelf forget anything? Make sure that all binaries are accounted for.
+  assert not unprocessed_binary_paths
+
+
 def BuildManifest(args):
-  with open(args.output_path, 'w') as manifest, \
+  binaries = []
+  with open(args.manifest_path, 'w') as manifest, \
        open(args.depfile_path, 'w') as depfile:
     # Process the runtime deps file for file paths, recursively walking
     # directories as needed.
@@ -94,6 +134,7 @@ def BuildManifest(args):
     excluded_files_set = set(args.exclude_file)
     for current_file in expanded_files:
       if _IsBinary(current_file):
+        binaries.append(current_file)
         current_file = _GetStrippedPath(current_file)
 
       in_package_path = MakePackagePath(current_file,
@@ -116,14 +157,14 @@ def BuildManifest(args):
       raise Exception('Could not locate executable inside runtime_deps.')
 
     # Write meta/package manifest file.
-    with open(os.path.join(os.path.dirname(args.output_path), 'package'), 'w') \
-        as package_json:
+    with open(os.path.join(os.path.dirname(args.manifest_path), 'package'),
+              'w') as package_json:
       json.dump({'version': '0', 'name': args.app_name}, package_json)
       manifest.write('meta/package=%s\n' %
                    os.path.relpath(package_json.name, args.out_dir))
 
     # Write component manifest file.
-    cmx_file_path = os.path.join(os.path.dirname(args.output_path),
+    cmx_file_path = os.path.join(os.path.dirname(args.manifest_path),
                                  args.app_name + '.cmx')
     with open(cmx_file_path, 'w') as component_manifest_file:
       component_manifest = {
@@ -137,11 +178,15 @@ def BuildManifest(args):
                       os.path.relpath(cmx_file_path, args.out_dir)))
 
     depfile.write(
-        "%s: %s" % (os.path.relpath(args.output_path, args.out_dir),
+        "%s: %s" % (os.path.relpath(args.manifest_path, args.out_dir),
                     " ".join([os.path.relpath(f, args.out_dir)
                               for f in expanded_files])))
+
+    _WriteBuildIdsTxt(binaries, args.build_ids_file)
+
   return 0
 
+
 def main():
   parser = argparse.ArgumentParser()
   parser.add_argument('--root-dir', required=True, help='Build root directory')
@@ -157,7 +202,10 @@ def main():
       help='Path to write GN deps file.')
   parser.add_argument('--exclude-file', action='append', default=[],
       help='Package-relative file path to exclude from the package.')
-  parser.add_argument('--output-path', required=True, help='Output file path.')
+  parser.add_argument('--manifest-path', required=True,
+                      help='Manifest output path.')
+  parser.add_argument('--build-ids-file', required=True,
+                      help='Debug symbol index path.')
 
   args = parser.parse_args()
 

build/config/fuchsia/rules.gni

@@ -86,6 +86,7 @@ template("fuchsia_package_runner") {
         _manifest_path,
         "//build/fuchsia/",
         "//build/util/lib/",
+        "//third_party/llvm-build/Release+Asserts/bin/llvm-symbolizer",
         "${qemu_root}/",
         "${fuchsia_sdk}/",
       ]
@@ -129,8 +130,6 @@ template("fuchsia_package_runner") {
         rebase_path(_package_path, root_build_dir),
         "--package-name",
         _pkg_shortname,
-        "--package-manifest",
-        rebase_path(_manifest_path, root_build_dir),
       ]
 
       if (defined(install_only) && install_only) {

build/fuchsia/common_args.py

@@ -21,9 +21,6 @@ def AddCommonArgs(arg_parser):
   common_args.add_argument('--package-name', required=True,
                            help='Name of the package to execute, defined in ' +
                                 'package metadata.')
-  common_args.add_argument('--package-manifest',
-                           type=os.path.realpath, required=True,
-                           help='Path to the Fuchsia package manifest file.')
   common_args.add_argument('--package-dep', action='append', default=[],
                            help='Path to an additional package to install.')
   common_args.add_argument('--install-only', action='store_true', default=False,

build/fuchsia/create_runner_script.py

@@ -56,7 +56,6 @@ def main(args):
   group.add_argument('--output-directory')
   group.add_argument('--package')
   group.add_argument('--package-dep', action='append', default=[])
-  group.add_argument('--package-manifest')
   args, runner_args = parser.parse_known_args(args)
 
   def RelativizePathToScript(path):
@@ -75,8 +74,6 @@ def main(args):
   for next_package_dep in args.package_dep:
     runner_path_args.append(
         ('--package-dep', RelativizePathToScript(next_package_dep)))
-  runner_path_args.append(
-      ('--package-manifest', RelativizePathToScript(args.package_manifest)))
 
   with open(args.script_output_path, 'w') as script:
     script.write(SCRIPT_TEMPLATE.format(

build/fuchsia/run_package.py

@@ -21,7 +21,7 @@ import time
 import threading
 import uuid
 
-from symbolizer import FilterStream
+from symbolizer import SymbolizerFilter
 
 FAR = os.path.join(common.SDK_ROOT, 'tools', 'far')
 PM = os.path.join(common.SDK_ROOT, 'tools', 'pm')
@@ -43,25 +43,70 @@ def _AttachKernelLogReader(target):
                                 stdout=subprocess.PIPE)
 
 
-def _ReadMergedLines(streams):
-  """Creates a generator which merges the buffered line output from |streams|.
-  The generator is terminated when the primary (first in sequence) stream
-  signals EOF. Absolute output ordering is not guaranteed."""
+class MergedInputStream(object):
+  """Merges a number of input streams into a UNIX pipe on a dedicated thread.
+  Terminates when the file descriptor of the primary stream (the first in
+  the sequence) is closed."""
 
+  def __init__(self, streams):
     assert len(streams) > 0
+    self._streams = streams
+    self._read_pipe, write_pipe = os.pipe()
+    self._output_stream = os.fdopen(write_pipe, 'w')
+    self._thread = threading.Thread(target=self._Run)
+
+  def Start(self):
+    """Returns a file descriptor to the merged output stream."""
+
+    self._thread.start();
+    return self._read_pipe
+
+  def _Run(self):
     streams_by_fd = {}
-  primary_fd = streams[0].fileno()
-  for s in streams:
+    primary_fd = self._streams[0].fileno()
+    for s in self._streams:
       streams_by_fd[s.fileno()] = s
 
-  while primary_fd != None:
-    rlist, _, _ = select.select(streams_by_fd, [], [], 0.1)
+    # Set when the primary FD is closed. Input from other FDs will continue to
+    # be processed until select() runs dry.
+    flush = False
+
+    # The lifetime of the MergedInputStream is bound to the lifetime of
+    # |primary_fd|.
+    while primary_fd:
+      # When not flushing: block until data is read or an exception occurs.
+      rlist, _, xlist = select.select(streams_by_fd, [], streams_by_fd)
+
+      if len(rlist) == 0 and flush:
+        break
+
+      for fileno in xlist:
+        del streams_by_fd[fileno]
+        if fileno == primary_fd:
+          primary_fd = None
+
       for fileno in rlist:
         line = streams_by_fd[fileno].readline()
         if line:
-        yield line
-      elif fileno == primary_fd:
+          self._output_stream.write(line + '\n')
+        else:
+          del streams_by_fd[fileno]
+          if fileno == primary_fd:
             primary_fd = None
+
+    # Flush the streams by executing nonblocking reads from the input file
+    # descriptors until no more data is available,  or all the streams are
+    # closed.
+    while streams_by_fd:
+      rlist, _, _ = select.select(streams_by_fd, [], [], 0)
+
+      if not rlist:
+        break
+
+      for fileno in rlist:
+        line = streams_by_fd[fileno].readline()
+        if line:
+          self._output_stream.write(line + '\n')
         else:
           del streams_by_fd[fileno]
 
@@ -161,7 +206,6 @@ class RunPackageArgs:
   def FromCommonArgs(args):
     run_package_args = RunPackageArgs()
     run_package_args.install_only = args.install_only
-    run_package_args.symbolizer_config = args.package_manifest
     run_package_args.system_logging = args.include_system_logs
     run_package_args.target_staging_path = args.target_staging_path
     return run_package_args
@@ -184,8 +228,8 @@ def PublishPackage(tuf_root, package_path):
       stderr=subprocess.STDOUT)
 
 
-def RunPackage(output_dir, target, package_path, package_name, package_deps,
-               package_args, args):
+def RunPackage(output_dir, target, package_path, package_name,
+               package_deps, package_args, args):
   """Copies the Fuchsia package at |package_path| to the target,
   executes it with |package_args|, and symbolizes its output.
 
@@ -260,19 +304,16 @@ def RunPackage(output_dir, target, package_path, package_name, package_deps,
                                      stderr=subprocess.STDOUT)
 
     if system_logger:
-      task_output = _ReadMergedLines([process.stdout, system_logger.stdout])
+      output_fd = MergedInputStream([process.stdout,
+                                       system_logger.stdout]).Start()
     else:
-      task_output = process.stdout
+      output_fd = process.stdout.fileno()
 
-    if args.symbolizer_config:
-      # Decorate the process output stream with the symbolizer.
-      output = FilterStream(task_output, package_name, args.symbolizer_config,
-                            output_dir)
-    else:
-      logging.warn('Symbolization is DISABLED.')
-      output = process.stdout
+    # Run the log data through the symbolizer process.
+    build_ids_path = os.path.join(os.path.dirname(package_path), 'ids.txt')
+    output_stream = SymbolizerFilter(output_fd, build_ids_path)
 
-    for next_line in output:
+    for next_line in output_stream:
       print next_line.rstrip()
 
     process.wait()

build/fuchsia/symbolizer.py

@@ -4,227 +4,34 @@
 
 import logging
 import os
-import re
 import subprocess
 
-# Matches the coarse syntax of a backtrace entry.
-_BACKTRACE_PREFIX_RE = re.compile(r'(\[[0-9.]+\] )?bt#(?P<frame_id>\d+): ')
+from common import SDK_ROOT
 
-# Matches the specific fields of a backtrace entry.
-# Back-trace line matcher/parser assumes that 'pc' is always present, and
-# expects that 'sp' and ('binary','pc_offset') may also be provided.
-_BACKTRACE_ENTRY_RE = re.compile(
-    r'pc 0(?:x[0-9a-f]+)?' +
-    r'(?: sp 0x[0-9a-f]+)?' +
-    r'(?: \((?P<binary>\S+),(?P<pc_offset>0x[0-9a-f]+)\))?$')
 
+def SymbolizerFilter(input_fd, build_ids_file):
+  """Symbolizes an output stream from a process.
 
-def _GetUnstrippedPath(path):
-  """If there is a binary located at |path|, returns a path to its unstripped
-  source.
+  input_fd: A file descriptor of the stream to be symbolized.
+  build_ids_file: Path to the ids.txt file which maps build IDs to
+                  unstripped binaries on the filesystem.
+  Returns a generator that yields symbolized process output."""
 
-  Returns None if |path| isn't a binary or doesn't exist in the lib.unstripped
-  or exe.unstripped directories."""
+  llvm_symbolizer_path = os.path.join(SDK_ROOT, os.pardir, os.pardir,
+                                      'llvm-build', 'Release+Asserts', 'bin',
+                                      'llvm-symbolizer')
+  symbolizer = os.path.join(SDK_ROOT, 'tools', 'symbolize')
+  symbolizer_cmd = [symbolizer, '-ids', build_ids_file,
+                    '-ids-rel', '-llvm-symbolizer', llvm_symbolizer_path]
 
-  if path.endswith('.so'):
-    maybe_unstripped_path = os.path.normpath(
-        os.path.join(path, os.path.pardir, 'lib.unstripped',
-                     os.path.basename(path)))
-  else:
-    maybe_unstripped_path = os.path.normpath(
-        os.path.join(path, os.path.pardir, 'exe.unstripped',
-                     os.path.basename(path)))
+  logging.info('Running "%s".' % ' '.join(symbolizer_cmd))
+  symbolizer_proc = subprocess.Popen(
+      symbolizer_cmd,
+      stdout=subprocess.PIPE,
+      stdin=input_fd,
+      close_fds=True)
 
-  if not os.path.exists(maybe_unstripped_path):
-    return None
-
-  with open(maybe_unstripped_path, 'rb') as f:
-    file_tag = f.read(4)
-  if file_tag != '\x7fELF':
-    logging.warn('Expected an ELF binary: ' + maybe_unstripped_path)
-    return None
-
-  return maybe_unstripped_path
-
-
-def FilterStream(stream, package_name, manifest_path, output_dir):
-  """Looks for backtrace lines from an iterable |stream| and symbolizes them.
-  Yields a stream of strings with symbolized entries replaced."""
-
-  return _SymbolizerFilter(package_name,
-                           manifest_path,
-                           output_dir).SymbolizeStream(stream)
-
-
-class _SymbolizerFilter(object):
-  """Adds backtrace symbolization capabilities to a process output stream."""
-
-  def __init__(self, package_name, manifest_path, output_dir):
-    self._symbols_mapping = {}
-    self._output_dir = output_dir
-    self._package_name = package_name
-
-    # Compute remote/local path mappings using the manifest data.
-    for next_line in open(manifest_path):
-      target, source = next_line.strip().split('=')
-      stripped_binary_path = _GetUnstrippedPath(os.path.join(output_dir,
-                                                             source))
-      if not stripped_binary_path:
-        continue
-
-      self._symbols_mapping[os.path.basename(target)] = stripped_binary_path
-      self._symbols_mapping[target] = stripped_binary_path
-      if target == 'bin/app':
-        self._symbols_mapping[package_name] = stripped_binary_path
-      logging.debug('Symbols: %s -> %s' % (source, target))
-
-  def _SymbolizeEntries(self, entries):
-    """Symbolizes the parsed backtrace |entries| by calling addr2line.
-
-    Returns a set of (frame_id, result) pairs."""
-
-    filename_re = re.compile(r'at ([-._a-zA-Z0-9/+]+):(\d+)')
-
-    # Use addr2line to symbolize all the |pc_offset|s in |entries| in one go.
-    # Entries with no |debug_binary| are also processed here, so that we get
-    # consistent output in that case, with the cannot-symbolize case.
-    addr2line_output = None
-    if entries[0].has_key('debug_binary'):
-      addr2line_args = (['addr2line', '-Cipf', '-p',
-                        '--exe=' + entries[0]['debug_binary']] +
-                        map(lambda entry: entry['pc_offset'], entries))
-      addr2line_output = subprocess.check_output(addr2line_args).splitlines()
-      assert addr2line_output
-
-    results = {}
-    for entry in entries:
-      raw, frame_id = entry['raw'], entry['frame_id']
-      prefix = '#%s: ' % frame_id
-
-      if not addr2line_output:
-        # Either there was no addr2line output, or too little of it.
-        filtered_line = raw
-      else:
-        output_line = addr2line_output.pop(0)
-
-        # Relativize path to the current working (output) directory if we see
-        # a filename.
-        def RelativizePath(m):
-          relpath = os.path.relpath(os.path.normpath(m.group(1)))
-          return 'at ' + relpath + ':' + m.group(2)
-        filtered_line = filename_re.sub(RelativizePath, output_line)
-
-        if '??' in filtered_line.split():
-          # If symbolization fails just output the raw backtrace.
-          filtered_line = raw
-        else:
-          # Release builds may inline things, resulting in "(inlined by)" lines.
-          inlined_by_prefix = " (inlined by)"
-          while (addr2line_output and
-                 addr2line_output[0].startswith(inlined_by_prefix)):
-            inlined_by_line = \
-                '\n' + (' ' * len(prefix)) + addr2line_output.pop(0)
-            filtered_line += filename_re.sub(RelativizePath, inlined_by_line)
-
-      results[entry['frame_id']] = prefix + filtered_line
-
-    return results
-
-  def _LookupDebugBinary(self, entry):
-    """Looks up the binary listed in |entry| in the |_symbols_mapping|.
-    Returns the corresponding host-side binary's filename, or None."""
-
-    binary = entry['binary']
-    if not binary:
-      return None
-
-    app_prefix = 'app:'
-    if binary.startswith(app_prefix):
-      binary = binary[len(app_prefix):]
-
-    # We change directory into /system/ before running the target executable, so
-    # all paths are relative to "/system/", and will typically start with "./".
-    # Some crashes still uses the full filesystem path, so cope with that, too.
-    pkg_prefix = '/pkg/'
-    cwd_prefix = './'
-    if binary.startswith(cwd_prefix):
-      binary = binary[len(cwd_prefix):]
-    elif binary.startswith(pkg_prefix):
-      binary = binary[len(pkg_prefix):]
-    # Allow other paths to pass-through; sometimes neither prefix is present.
-
-    if binary in self._symbols_mapping:
-      return self._symbols_mapping[binary]
-
-    # |binary| may be truncated by the crashlogger, so if there is a unique
-    # match for the truncated name in |symbols_mapping|, use that instead.
-    matches = filter(lambda x: x.startswith(binary),
-                               self._symbols_mapping.keys())
-    if len(matches) == 1:
-      return self._symbols_mapping[matches[0]]
-
-    return None
-
-  def _SymbolizeBacktrace(self, backtrace):
-    """Group |backtrace| entries according to the associated binary, and locate
-    the path to the debug symbols for that binary, if any."""
-
-    batches = {}
-
-    for entry in backtrace:
-      debug_binary = self._LookupDebugBinary(entry)
-      if debug_binary:
-        entry['debug_binary'] = debug_binary
-      batches.setdefault(debug_binary, []).append(entry)
-
-    # Run _SymbolizeEntries on each batch and collate the results.
-    symbolized = {}
-    for batch in batches.itervalues():
-      symbolized.update(self._SymbolizeEntries(batch))
-
-    # Map each entry to its symbolized form, by frame-id, and return the list.
-    return map(lambda entry: symbolized[entry['frame_id']], backtrace)
-
-  def SymbolizeStream(self, stream):
-    """Creates a symbolized logging stream object using the output from
-    |stream|."""
-
-    # A buffer of backtrace entries awaiting symbolization, stored as dicts:
-    # raw: The original back-trace line that followed the prefix.
-    # frame_id: backtrace frame number (starting at 0).
-    # binary: path to executable code corresponding to the current frame.
-    # pc_offset: memory offset within the executable.
-    backtrace_entries = []
-
-    # Read from the stream until we hit EOF.
-    for line in stream:
-      line = line.rstrip()
-
-      # Look for the back-trace prefix, otherwise just emit the line.
-      matched = _BACKTRACE_PREFIX_RE.match(line)
-      if not matched:
+  for line in symbolizer_proc.stdout:
     yield line
-        continue
-      backtrace_line = line[matched.end():]
-
-      # If this was the end of a back-trace then symbolize and emit it.
-      frame_id = matched.group('frame_id')
-      if backtrace_line == 'end':
-        if backtrace_entries:
-          for processed in self._SymbolizeBacktrace(backtrace_entries):
-            yield processed
-        backtrace_entries = []
-        continue
 
-      # Parse the program-counter offset, etc into |backtrace_entries|.
-      matched = _BACKTRACE_ENTRY_RE.match(backtrace_line)
-      if matched:
-        # |binary| and |pc_offset| will be None if not present.
-        backtrace_entries.append(
-            {'raw': backtrace_line, 'frame_id': frame_id,
-             'binary': matched.group('binary'),
-             'pc_offset': matched.group('pc_offset')})
-      else:
-        backtrace_entries.append(
-            {'raw': backtrace_line, 'frame_id': frame_id,
-             'binary': None, 'pc_offset': None})
+  symbolizer_proc.wait()