Deobfuscate instrumentation test output

Adds a new GN arg "enable_proguard_obfuscation_for_tests", which enables
obfuscation for chrome instrumentation tests even when
enable_proguard_obfuscation = false.

Updates test_runner.py to filter instrumentation output through
java_deobfuscate (but not yet logcat).

Updates java_deobfuscate's regex to match:
  INSTRUMENTATION_STATUS: class=bNs

Bug: 713710
Change-Id: I569dd62f051a041be2ec16664c5f714cb9857453
Reviewed-on: https://chromium-review.googlesource.com/614988
Commit-Queue: Andrew Grieve <agrieve@chromium.org>
Reviewed-by: John Budorick <jbudorick@chromium.org>
Cr-Original-Commit-Position: refs/heads/master@{#499714}
Cr-Mirrored-From: https://chromium.googlesource.com/chromium/src
Cr-Mirrored-Commit: 3f1d7a79c6b4596f664b259dbebb294a1b65a30e

android/gyp/proguard.py

@@ -31,6 +31,11 @@ def _ParseOptions(args):
   parser.add_option('--output-path', help='Path to the generated .jar file.')
   parser.add_option('--proguard-configs', action='append',
                     help='Paths to proguard configuration files.')
+  parser.add_option('--proguard-config-exclusions',
+                    default='',
+                    help='GN list of paths to proguard configuration files '
+                         'included by --proguard-configs, but that should '
+                         'not actually be included.')
   parser.add_option('--mapping', help='Path to proguard mapping to apply.')
   parser.add_option('--is-test', action='store_true',
       help='If true, extra proguard options for instrumentation tests will be '
@@ -56,6 +61,8 @@ def _ParseOptions(args):
   for arg in options.proguard_configs:
     configs += build_utils.ParseGnList(arg)
   options.proguard_configs = configs
+  options.proguard_config_exclusions = (
+      build_utils.ParseGnList(options.proguard_config_exclusions))
 
   options.input_paths = build_utils.ParseGnList(options.input_paths)
 
@@ -81,6 +88,7 @@ def main(args):
   proguard = proguard_util.ProguardCmdBuilder(options.proguard_path)
   proguard.injars(options.input_paths)
   proguard.configs(options.proguard_configs)
+  proguard.config_exclusions(options.proguard_config_exclusions)
   proguard.outjar(options.output_path)
 
   if options.mapping:

android/gyp/util/proguard_util.py

@@ -52,6 +52,7 @@ class ProguardCmdBuilder(object):
     self._libraries = None
     self._injars = None
     self._configs = None
+    self._config_exclusions = None
     self._outjar = None
     self._cmd = None
     self._verbose = False
@@ -90,9 +91,14 @@ class ProguardCmdBuilder(object):
   def configs(self, paths):
     assert self._cmd is None
     assert self._configs is None
-    for p in paths:
-      assert os.path.exists(p), p
     self._configs = paths
+    for p in self._configs:
+      assert os.path.exists(p), p
+
+  def config_exclusions(self, paths):
+    assert self._cmd is None
+    assert self._config_exclusions is None
+    self._config_exclusions = paths
 
   def verbose(self, verbose):
     assert self._cmd is None
@@ -116,6 +122,9 @@ class ProguardCmdBuilder(object):
       tested_apk_info = build_utils.ReadJson(self._tested_apk_info_path)
       self._configs += tested_apk_info['configs']
 
+    for path in self._config_exclusions:
+      self._configs.remove(path)
+
     if self._mapping:
       cmd += [
         '-applymapping', self._mapping,

android/pylib/instrumentation/instrumentation_test_instance.py

@@ -17,6 +17,7 @@ from pylib.base import test_instance
 from pylib.constants import host_paths
 from pylib.instrumentation import test_result
 from pylib.instrumentation import instrumentation_parser
+from pylib.symbols import deobfuscator
 from pylib.symbols import stack_symbolizer
 from pylib.utils import dexdump
 from pylib.utils import instrumentation_tracing
@@ -497,8 +498,8 @@ class InstrumentationTestInstance(test_instance.TestInstance):
 
     self._store_tombstones = False
     self._symbolizer = None
-    self._initializeTombstonesAttributes(args)
-
+    self._enable_java_deobfuscation = False
+    self._deobfuscator = None
     self._gs_results_bucket = None
     self._should_save_logcat = None
     self._initializeLogAttributes(args)
@@ -678,13 +679,13 @@ class InstrumentationTestInstance(test_instance.TestInstance):
   def _initializeTestCoverageAttributes(self, args):
     self._coverage_directory = args.coverage_dir
 
-  def _initializeTombstonesAttributes(self, args):
+  def _initializeLogAttributes(self, args):
+    self._enable_java_deobfuscation = args.enable_java_deobfuscation
     self._store_tombstones = args.store_tombstones
     self._symbolizer = stack_symbolizer.Symbolizer(
         self.apk_under_test.path if self.apk_under_test else None,
         args.enable_relocation_packing)
 
-  def _initializeLogAttributes(self, args):
     self._gs_results_bucket = args.gs_results_bucket
     self._should_save_logcat = bool(args.json_results_file)
 
@@ -827,6 +828,9 @@ class InstrumentationTestInstance(test_instance.TestInstance):
   def SetUp(self):
     self._data_deps.extend(
         self._data_deps_delegate(self._runtime_deps_path))
+    if self._enable_java_deobfuscation:
+      self._deobfuscator = deobfuscator.DeobfuscatorPool(
+          self.test_apk.path + '.mapping')
 
   def GetDataDependencies(self):
     return self._data_deps
@@ -838,6 +842,11 @@ class InstrumentationTestInstance(test_instance.TestInstance):
       raw_tests = GetAllTestsFromApk(self.test_apk.path)
     return self.ProcessRawTests(raw_tests)
 
+  def MaybeDeobfuscateLines(self, lines):
+    if not self._deobfuscator:
+      return lines
+    return self._deobfuscator.TransformLines(lines)
+
   def ProcessRawTests(self, raw_tests):
     inflated_tests = self._ParameterizeTestsWithFlags(
         self._InflateTests(raw_tests))
@@ -915,3 +924,6 @@ class InstrumentationTestInstance(test_instance.TestInstance):
   #override
   def TearDown(self):
     self.symbolizer.CleanUp()
+    if self._deobfuscator:
+      self._deobfuscator.Close()
+      self._deobfuscator = None

android/pylib/local/device/local_device_instrumentation_test_run.py

@@ -459,17 +459,21 @@ class LocalDeviceInstrumentationTestRun(
     logcat_url = logmon.GetLogcatURL()
     duration_ms = time_ms() - start_ms
 
+    with contextlib_ext.Optional(
+        trace_event.trace('ProcessResults'),
+        self._env.trace_output):
+      output = self._test_instance.MaybeDeobfuscateLines(output)
+      # TODO(jbudorick): Make instrumentation tests output a JSON so this
+      # doesn't have to parse the output.
+      result_code, result_bundle, statuses = (
+          self._test_instance.ParseAmInstrumentRawOutput(output))
+      results = self._test_instance.GenerateTestResults(
+          result_code, result_bundle, statuses, start_ms, duration_ms,
+          device.product_cpu_abi, self._test_instance.symbolizer)
+
     if self._env.trace_output:
       self._SaveTraceData(trace_device_file, device, test['class'])
 
-    # TODO(jbudorick): Make instrumentation tests output a JSON so this
-    # doesn't have to parse the output.
-    result_code, result_bundle, statuses = (
-        self._test_instance.ParseAmInstrumentRawOutput(output))
-    results = self._test_instance.GenerateTestResults(
-        result_code, result_bundle, statuses, start_ms, duration_ms,
-        device.product_cpu_abi, self._test_instance.symbolizer)
-
     def restore_flags():
       if flags_to_add:
         self._flag_changers[str(device)].Restore()

android/pylib/symbols/deobfuscator.py

@@ -0,0 +1,133 @@
+# Copyright 2017 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.
+
+import logging
+import os
+import subprocess
+import uuid
+
+from devil.utils import reraiser_thread
+from pylib import constants
+
+
+_MINIUMUM_TIMEOUT = 5.0  # Large enough to account for process start-up.
+_PER_LINE_TIMEOUT = .002  # Should be able to process 500 lines per second.
+
+
+class Deobfuscator(object):
+  def __init__(self, mapping_path):
+    self._reader_thread = None
+    script_path = os.path.join(
+        constants.GetOutDirectory(), 'bin', 'java_deobfuscate')
+    cmd = [script_path, mapping_path]
+    # Start process eagerly to hide start-up latency.
+    self._proc = subprocess.Popen(
+        cmd, bufsize=1, stdin=subprocess.PIPE, stdout=subprocess.PIPE,
+        close_fds=True)
+    self._logged_error = False
+
+  def IsClosed(self):
+    return self._proc.returncode is not None
+
+  def IsBusy(self):
+    return bool(self._reader_thread)
+
+  def IsReady(self):
+    return not self.IsClosed() and not self.IsBusy()
+
+  def TransformLines(self, lines):
+    """Deobfuscates obfuscated names found in the given lines.
+
+    If anything goes wrong (process crashes, timeout, etc), returns |lines|.
+
+    Args:
+      lines: A list of strings without trailing newlines.
+
+    Returns:
+      A list of strings without trailing newlines.
+    """
+    if not lines:
+      return []
+
+    # Allow only one thread to communicate with the subprocess at a time.
+    if self._reader_thread:
+      logging.warning('Having to wait for Java deobfuscation.')
+      self._reader_thread.join()
+
+    if self._proc.returncode is not None:
+      if not self._logged_error:
+        logging.warning('java_deobfuscate process exited with code=%d.',
+                        self._proc.returncode)
+        self._logged_error = True
+      return lines
+
+    out_lines = []
+    eof_line = uuid.uuid4().hex
+
+    def deobfuscate_reader():
+      while True:
+        line = self._proc.stdout.readline()[:-1]
+        # Due to inlining, deobfuscated stacks may contain more frames than
+        # obfuscated ones. To account for the variable number of lines, keep
+        # reading until eof_line.
+        if line == eof_line:
+          break
+        out_lines.append(line)
+
+    # TODO(agrieve): Can probably speed this up by only sending lines through
+    #     that might contain an obfuscated name.
+    self._reader_thread = reraiser_thread.ReraiserThread(deobfuscate_reader)
+    self._reader_thread.start()
+    try:
+      self._proc.stdin.write('\n'.join(lines))
+      self._proc.stdin.write('\n{}\n'.format(eof_line))
+      self._proc.stdin.flush()
+      timeout = max(_MINIUMUM_TIMEOUT, len(lines) * _PER_LINE_TIMEOUT)
+      self._reader_thread.join(timeout)
+      if self._reader_thread.is_alive():
+        logging.error('java_deobfuscate timed out.')
+        self.Close()
+      self._reader_thread = None
+      return out_lines
+    except IOError:
+      logging.exception('Exception during java_deobfuscate')
+      self.Close()
+      return lines
+
+  def Close(self):
+    if not self.IsClosed():
+      self._proc.stdin.close()
+      self._proc.kill()
+      self._proc.wait()
+    self._reader_thread = None
+
+  def __del__(self):
+    if not self.IsClosed():
+      logging.error('Forgot to Close() deobfuscator')
+
+
+class DeobfuscatorPool(object):
+  def __init__(self, mapping_path, pool_size=4):
+    self._mapping_path = mapping_path
+    self._pool = [Deobfuscator(mapping_path) for _ in xrange(pool_size)]
+
+  def TransformLines(self, lines):
+    target_instance = next((x for x in self._pool if x.IsReady()), None)
+
+    # Restart any closed ones.
+    for i, d in enumerate(self._pool):
+      if d.IsClosed():
+        logging.warning('Restarting closed Deobfuscator instance.')
+        self._pool[i] = Deobfuscator(self._mapping_path)
+
+    if not target_instance:
+      # No idle ones. Use the first one and cycle so as to not choose it again.
+      target_instance = self._pool[0]
+      self._pool.append(self._pool.pop(0))
+
+    return target_instance.TransformLines(lines)
+
+  def Close(self):
+    for d in self._pool:
+      d.Close()

android/stacktrace/README.md

@@ -7,7 +7,7 @@ A wrapper around ProGuard's ReTrace tool, which:
 
 The second point here is what allows you to run:
 
-    adb logcat | out/Default/bin/java_deobfuscate
+    adb logcat | out/Default/bin/java_deobfuscate out/Default/apks/ChromePublic.apk.mapping
 
 And have it actually show output without logcat terminating.
 

android/stacktrace/java/org/chromium/build/FlushingReTrace.java

@@ -24,16 +24,20 @@ public class FlushingReTrace {
     // http://proguard.sourceforge.net/manual/retrace/usage.html.
     // But with the "at" part changed to "(?::|\bat)", to account for lines like:
     //     06-22 13:58:02.895  4674  4674 E THREAD_STATE:     bLA.a(PG:173)
+    // And .*=%c\s* added as the second subpattern to account for lines like:
+    //     INSTRUMENTATION_STATUS: class=bNs
     // Normal stack trace lines look like:
     // java.lang.RuntimeException: Intentional Java Crash
     //     at org.chromium.chrome.browser.tab.Tab.handleJavaCrash(Tab.java:682)
     //     at org.chromium.chrome.browser.tab.Tab.loadUrl(Tab.java:644)
     private static final String LINE_PARSE_REGEX =
-            "(?:.*?(?::|\\bat)\\s+%c\\.%m\\s*\\(%s(?::%l)?\\)\\s*)|(?:(?:.*?[:\"]\\s+)?%c(?::.*)?)";
+            "(?:.*?(?::|\\bat)\\s+%c\\.%m\\s*\\(%s(?::%l)?\\)\\s*)|"
+            + "(?:.*=%c\\s*)|"
+            + "(?:(?:.*?[:\"]\\s+)?%c(?::.*)?)";
 
     public static void main(String[] args) {
         if (args.length != 1) {
-            System.err.println("Usage: retrace Foo.apk.map < foo.log > bar.log");
+            System.err.println("Usage: java_deobfuscate Foo.apk.map < foo.log > bar.log");
             System.exit(1);
         }
 

android/test_runner.py

@@ -332,7 +332,7 @@ def AddGTestOptions(parser):
   parser.add_argument(
       '--test-apk-incremental-install-json',
       type=os.path.realpath,
-      help='Path to install script for the test apk.')
+      help='Path to install json for the test apk.')
 
   filter_group = parser.add_mutually_exclusive_group()
   filter_group.add_argument(
@@ -382,6 +382,10 @@ def AddInstrumentationTestOptions(parser):
       '--disable-dalvik-asserts',
       dest='set_asserts', action='store_false', default=True,
       help='Removes the dalvik.vm.enableassertions property')
+  parser.add_argument(
+      '--enable-java-deobfuscation',
+      action='store_true',
+      help='Deobfuscate java stack traces in test output and logcat.')
   parser.add_argument(
       '-E', '--exclude-annotation',
       dest='exclude_annotation_str',

android/test_runner.pydeps

@@ -174,6 +174,7 @@ pylib/results/flakiness_dashboard/results_uploader.py
 pylib/results/json_results.py
 pylib/results/report_results.py
 pylib/symbols/__init__.py
+pylib/symbols/deobfuscator.py
 pylib/symbols/stack_symbolizer.py
 pylib/utils/__init__.py
 pylib/utils/decorators.py

config/android/internal_rules.gni

@@ -572,6 +572,9 @@ template("test_runner_script") {
           "@FileArg($_rebased_apk_under_test_build_config:deps_info:enable_relocation_packing)",
         ]
       }
+      if (defined(invoker.proguard_enabled) && invoker.proguard_enabled) {
+        test_runner_args += [ "--enable-java-deobfuscation" ]
+      }
       if (emma_coverage) {
         # Set a default coverage output directory (can be overridden by user
         # passing the same flag).

config/android/rules.gni

@@ -1638,11 +1638,10 @@ if (enable_java_templates) {
     }
     final_dex_target_name = "${_template_name}__final_dex"
 
-    _final_apk_path = ""
     if (defined(invoker.final_apk_path)) {
       _final_apk_path = invoker.final_apk_path
-    } else if (defined(invoker.apk_name)) {
-      _final_apk_path = "$root_build_dir/apks/" + invoker.apk_name + ".apk"
+    } else {
+      _final_apk_path = "$root_build_dir/apks/${invoker.apk_name}.apk"
     }
     _final_apk_path_no_ext_list =
         process_file_template([ _final_apk_path ],
@@ -2138,6 +2137,12 @@ if (enable_java_templates) {
           "--input-paths=@FileArg($_rebased_build_config:proguard:input_paths)",
           "--classpath=@FileArg($_rebased_build_config:proguard:lib_paths)",
         ]
+        if (defined(invoker.proguard_config_exclusions)) {
+          _rebased_proguard_config_exclusions =
+              rebase_path(invoker.proguard_config_exclusions, root_build_dir)
+          args += [ "--proguard-config-exclusions=$_rebased_proguard_config_exclusions" ]
+        }
+
         if (defined(invoker.apk_under_test)) {
           deps += [
             "${invoker.apk_under_test}__build_config",
@@ -2630,6 +2635,7 @@ if (enable_java_templates) {
                                  "data_deps",
                                  "deps",
                                  "ignore_all_data_deps",
+                                 "proguard_enabled",
                                  "public_deps",
                                ])
         test_name = invoker.target_name
@@ -2680,6 +2686,15 @@ if (enable_java_templates) {
           proguard_configs = []
         }
         proguard_configs += [ "//testing/android/proguard_for_test.flags" ]
+        data_deps += [ "//build/android/stacktrace:java_deobfuscate" ]
+        if (defined(final_apk_path)) {
+          _final_apk_path = final_apk_path
+        } else {
+          _final_apk_path = "$root_build_dir/apks/${apk_name}.apk"
+        }
+        data = [
+          "$_final_apk_path.mapping",
+        ]
       }
 
       dist_ijar_path = _dist_ijar_path