diagnose_bloat.py: update logging and general clean up.

tools/binary_size/diagnose_bloat.py

 #!/usr/bin/env python
 # 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.
 
 """Tool for finding the cause of APK bloat.
 
 Run diagnose_apk_bloat.py -h for detailed usage help.
 """
 
+import atexit
 import argparse
 import collections
 from contextlib import contextmanager
 import distutils.spawn
 import json
+import logging
 import multiprocessing
 import os
 import re
 import shutil
 import subprocess
 import sys
 import tempfile
 import zipfile
 
 _COMMIT_COUNT_WARN_THRESHOLD = 15
 _ALLOWED_CONSECUTIVE_FAILURES = 2
 _DIFF_DETAILS_LINES_THRESHOLD = 100
 _BUILDER_URL = \
     'https://build.chromium.org/p/chromium.perf/builders/Android%20Builder'
 _SRC_ROOT = os.path.abspath(
     os.path.join(os.path.dirname(__file__), os.pardir, os.pardir))
 _DEFAULT_ARCHIVE_DIR = os.path.join(_SRC_ROOT, 'binary-size-bloat')
 _DEFAULT_OUT_DIR = os.path.join(_SRC_ROOT, 'out', 'diagnose-apk-bloat')
 _DEFAULT_ANDROID_TARGET = 'monochrome_public_apk'
 
-_global_restore_checkout_func = None
-
-
-def _SetRestoreFunc(subrepo):
-  branch = _GitCmd(['rev-parse', '--abbrev-ref', 'HEAD'], subrepo)
-  global _global_restore_checkout_func
-  _global_restore_checkout_func = lambda: _GitCmd(['checkout', branch], subrepo)
-
 
 _DiffResult = collections.namedtuple('DiffResult', ['name', 'value', 'units'])
 
 
 class BaseDiff(object):
   """Base class capturing binary size diffs."""
   def __init__(self, name):
     self.name = name
     self.banner = '\n' + '*' * 30 + name + '*' * 30
 
@@ skipping 15 matching lines @@
 
   def DetailedResults(self):
     """An iterable description of the cause of binary size bloat."""
     raise NotImplementedError()
 
   def ProduceDiff(self, before_dir, after_dir):
     """Prepare a binary size diff with ready to print results."""
     raise NotImplementedError()
 
   def RunDiff(self, logfile, before_dir, after_dir):
+    logging.info('Creating: %s', self.name)
     self.ProduceDiff(before_dir, after_dir)
     self.AppendResults(logfile)
 
 
 class NativeDiff(BaseDiff):
   _RE_SUMMARY = re.compile(
       r'.*(Section Sizes .*? object files added, \d+ removed).*',
       flags=re.DOTALL)
   _RE_SUMMARY_STAT = re.compile(
       r'Section Sizes \(Total=(?P<value>\d+) (?P<units>\w+)\)')
@@ skipping 54 matching lines @@
   def ProduceDiff(self, before_dir, after_dir):
     before = self._RunResourceSizes(before_dir)
     after = self._RunResourceSizes(after_dir)
     diff = []
     for section, section_dict in after.iteritems():
       for subsection, v in section_dict.iteritems():
         # Ignore entries when resource_sizes.py chartjson format has changed.
         if (section not in before or
             subsection not in before[section] or
             v['units'] != before[section][subsection]['units']):
-          _Print('Found differing dict structures for resource_sizes.py, '
-                 'skipping {} {}', section, subsection)
+          logging.warning(
+              'Found differing dict structures for resource_sizes.py, '
+              'skipping %s %s', section, subsection)
         else:
           diff.append(
               _DiffResult(
                   '%s %s' % (section, subsection),
                   v['value'] - before[section][subsection]['value'],
                   v['units']))
     self._diff = sorted(diff, key=lambda x: abs(x.value), reverse=True)
 
   def _RunResourceSizes(self, archive_dir):
     apk_path = os.path.join(archive_dir, self._apk_name)
@@ skipping 94 matching lines @@
 
   def _GenNinjaCmd(self):
     cmd = ['ninja', '-C', self.output_directory]
     cmd += ['-j', self.max_jobs] if self.max_jobs else []
     cmd += ['-l', self.max_load_average] if self.max_load_average else []
     cmd += [self.target]
     return cmd
 
   def Run(self):
     """Run GN gen/ninja build and return the process returncode."""
-    _Print('Building: {}.', self.target)
+    logging.info('Building: %s.', self.target)
     retcode = _RunCmd(
-        self._GenGnCmd(), print_stdout=True, exit_on_failure=False)[1]
+        self._GenGnCmd(), verbose=True, exit_on_failure=False)[1]
     if retcode:
       return retcode
     return _RunCmd(
-        self._GenNinjaCmd(), print_stdout=True, exit_on_failure=False)[1]
+        self._GenNinjaCmd(), verbose=True, exit_on_failure=False)[1]
 
   def DownloadUrl(self, rev):
     return self.download_bucket + 'full-build-linux_%s.zip' % rev
 
   def IsAndroid(self):
     return self.target_os == 'android'
 
   def IsLinux(self):
     return self.target_os == 'linux'
 
   def IsCloud(self):
     return self.cloud
 
 
 class _BuildArchive(object):
   """Class for managing a directory with build results and build metadata."""
   def __init__(self, rev, base_archive_dir, build, subrepo):
     self.build = build
     self.dir = os.path.join(base_archive_dir, rev)
     metadata_path = os.path.join(self.dir, 'metadata.txt')
     self.rev = rev
-    self.metadata = _GenerateMetadata([self], build, metadata_path, subrepo)
+    self.metadata = _Metadata([self], build, metadata_path, subrepo)
 
   def ArchiveBuildResults(self, supersize_path):
     """Save build artifacts necessary for diffing."""
-    _Print('Saving build results to: {}', self.dir)
+    logging.info('Saving build results to: %s', self.dir)
     _EnsureDirsExist(self.dir)
     build = self.build
     self._ArchiveFile(build.abs_main_lib_path)
     tool_prefix = _FindToolPrefix(build.output_directory)
     size_path = os.path.join(self.dir, build.size_name)
     supersize_cmd = [supersize_path, 'archive', size_path, '--elf-file',
                      build.abs_main_lib_path, '--tool-prefix', tool_prefix,
                      '--output-directory', build.output_directory,
                      '--no-source-paths']
     if build.IsAndroid():
       supersize_cmd += ['--apk-file', build.abs_apk_path]
       self._ArchiveFile(build.abs_apk_path)
 
+    logging.info('Creating .size file')
     _RunCmd(supersize_cmd)
-    _WriteMetadata(self.metadata)
+    self.metadata.Write()
 
   def Exists(self):
-    return _MetadataExists(self.metadata)
+    return self.metadata.Exists()
 
   def _ArchiveFile(self, filename):
     if not os.path.exists(filename):
-      _Die('missing expected file: {}', filename)
+      _Die('missing expected file: %s', filename)
     shutil.copy(filename, self.dir)
 
 
 class _DiffArchiveManager(object):
   """Class for maintaining BuildArchives and their related diff artifacts."""
   def __init__(self, revs, archive_dir, diffs, build, subrepo):
     self.archive_dir = archive_dir
     self.build = build
     self.build_archives = [_BuildArchive(rev, archive_dir, build, subrepo)
                            for rev in revs]
     self.diffs = diffs
     self.subrepo = subrepo
     self._summary_stats = []
 
   def IterArchives(self):
     return iter(self.build_archives)
 
   def MaybeDiff(self, before_id, after_id):
     """Perform diffs given two build archives."""
     before = self.build_archives[before_id]
     after = self.build_archives[after_id]
     diff_path = self._DiffFilePath(before, after)
     if not self._CanDiff(before, after):
-      _Print('Skipping diff for {} due to missing build archives.', diff_path)
+      logging.info(
+          'Skipping diff for %s due to missing build archives.', diff_path)
       return
 
     metadata_path = self._DiffMetadataPath(before, after)
-    metadata = _GenerateMetadata(
+    metadata = _Metadata(
         [before, after], self.build, metadata_path, self.subrepo)
-    if _MetadataExists(metadata):
-      _Print('Skipping diff for {} and {}. Matching diff already exists: {}',
-             before.rev, after.rev, diff_path)
+    if metadata.Exists():
+      logging.info(
+          'Skipping diff for %s and %s. Matching diff already exists: %s',
+          before.rev, after.rev, diff_path)
     else:
       if os.path.exists(diff_path):
         os.remove(diff_path)
       with open(diff_path, 'a') as diff_file:
         for d in self.diffs:
           d.RunDiff(diff_file, before.dir, after.dir)
-        _Print('\nSee detailed diff results here: {}.', diff_path)
-      _WriteMetadata(metadata)
+        logging.info('See detailed diff results here: %s.', diff_path)
+      metadata.Write()
       self._AddDiffSummaryStat(before, after)
 
   def Summarize(self):
     if self._summary_stats:
       path = os.path.join(self.archive_dir, 'last_diff_summary.txt')
       with open(path, 'w') as f:
         stats = sorted(
             self._summary_stats, key=lambda x: x[0].value, reverse=True)
         _PrintAndWriteToFile(f, '\nDiff Summary')
         for s, before, after in stats:
@@ skipping 21 matching lines @@
   def _DiffMetadataPath(self, before, after):
     return os.path.join(self._DiffDir(before, after), 'metadata.txt')
 
   def _DiffDir(self, before, after):
     archive_range = '%s..%s' % (before.rev, after.rev)
     diff_path = os.path.join(self.archive_dir, 'diffs', archive_range)
     _EnsureDirsExist(diff_path)
     return diff_path
 
 
+class _Metadata(object):
+
+  def __init__(self, archives, build, path, subrepo):
+    self.is_cloud = build.IsCloud()
+    self.data = {
+      'revs': [a.rev for a in archives],
+      'archive_dirs': [a.dir for a in archives],
+      'target': build.target,
+      'target_os': build.target_os,
+      'is_cloud': build.IsCloud(),
+      'subrepo': subrepo,
+      'path': path,
+      'gn_args': {
+        'extra_gn_args_str': build.extra_gn_args_str,
+        'enable_chrome_android_internal': build.enable_chrome_android_internal,
+      }
+    }
+
+  def Exists(self):
+    old_metadata = {}
+    path = self.data['path']
+    if os.path.exists(path):
+      with open(path, 'r') as f:
+        old_metadata = json.load(f)
+        # For local builds, all keys need to be the same. Differing GN args will
+        # make diffs noisy and inaccurate. GN args do not matter for --cloud
+        # since we download prebuilt build artifacts.
+        keys = self.data.keys()
+        if self.is_cloud:
+          keys.remove('gn_args')
+        return all(v == old_metadata[k]
+                   for k, v in self.data.iteritems() if k in keys)
+
+  def Write(self):
+    with open(self.data['path'], 'w') as f:
+      json.dump(self.data, f)
+
+
 def _EnsureDirsExist(path):
   if not os.path.exists(path):
     os.makedirs(path)
 
 
-def _GenerateMetadata(archives, build, path, subrepo):
-  return {
-    'revs': [a.rev for a in archives],
-    'archive_dirs': [a.dir for a in archives],
-    'target': build.target,
-    'target_os': build.target_os,
-    'is_cloud': build.IsCloud(),
-    'subrepo': subrepo,
-    'path': path,
-    'gn_args': {
-      'extra_gn_args_str': build.extra_gn_args_str,
-      'enable_chrome_android_internal': build.enable_chrome_android_internal,
-    }
-  }
-
-
-def _WriteMetadata(metadata):
-  with open(metadata['path'], 'w') as f:
-    json.dump(metadata, f)
-
-
-def _MetadataExists(metadata):
-  old_metadata = {}
-  path = metadata['path']
-  if os.path.exists(path):
-    with open(path, 'r') as f:
-      old_metadata = json.load(f)
-      ret = len(metadata) == len(old_metadata)
-      ret &= all(v == old_metadata[k]
-                 for k, v in metadata.items() if k != 'gn_args')
-      # GN args don't matter when artifacts are downloaded. For local builds
-      # they need to be the same so that diffs are accurate (differing GN args
-      # will change the final APK/native library).
-      if not metadata['is_cloud']:
-        ret &= metadata['gn_args'] == old_metadata['gn_args']
-      return ret
-  return False
-
-
-def _RunCmd(cmd, print_stdout=False, exit_on_failure=True):
+def _RunCmd(cmd, verbose=False, exit_on_failure=True):
   """Convenience function for running commands.
 
   Args:
     cmd: the command to run.
-    print_stdout: if this is True, then the stdout of the process will be
-        printed instead of returned.
+    verbose: if this is True, then the stdout and stderr of the process will be
+        printed. If it's false, the stdout will be returned.
     exit_on_failure: die if an error occurs when this is True.
 
   Returns:
     Tuple of (process stdout, process returncode).
   """
+  assert not (verbose and exit_on_failure)
   cmd_str = ' '.join(c for c in cmd)
-  _Print('Running: {}', cmd_str)
-  proc_stdout = sys.stdout if print_stdout else subprocess.PIPE
+  logging.debug('Running: %s', cmd_str)
+  proc_stdout = proc_stderr = subprocess.PIPE
+  if verbose and logging.getLogger().getEffectiveLevel() < logging.INFO:
+    proc_stdout, proc_stderr = sys.stdout, subprocess.STDOUT
 
-  proc = subprocess.Popen(cmd, stdout=proc_stdout, stderr=subprocess.PIPE)
+  proc = subprocess.Popen(cmd, stdout=proc_stdout, stderr=proc_stderr)
   stdout, stderr = proc.communicate()
 
   if proc.returncode and exit_on_failure:
-    _Die('command failed: {}\nstderr:\n{}', cmd_str, stderr)
+    _Die('command failed: %s\nstderr:\n%s', cmd_str, stderr)
 
   stdout = stdout.strip() if stdout else ''
   return stdout, proc.returncode
 
 
 def _GitCmd(args, subrepo):
   return _RunCmd(['git', '-C', subrepo] + args)[0]
 
 
 def _GclientSyncCmd(rev, subrepo):
   cwd = os.getcwd()
   os.chdir(subrepo)
-  _RunCmd(['gclient', 'sync', '-r', 'src@' + rev], print_stdout=True)
+  _, retcode = _RunCmd(['gclient', 'sync', '-r', 'src@' + rev],
+                       verbose=True, exit_on_failure=False)
   os.chdir(cwd)
+  return retcode
 
 
 def _FindToolPrefix(output_directory):
   build_vars_path = os.path.join(output_directory, 'build_vars.txt')
   if os.path.exists(build_vars_path):
     with open(build_vars_path) as f:
       build_vars = dict(l.rstrip().split('=', 1) for l in f if '=' in l)
     # Tool prefix is relative to output dir, rebase to source root.
     tool_prefix = build_vars['android_tool_prefix']
     while os.path.sep in tool_prefix:
       rebased_tool_prefix = os.path.join(_SRC_ROOT, tool_prefix)
       if os.path.exists(rebased_tool_prefix + 'readelf'):
         return rebased_tool_prefix
       tool_prefix = tool_prefix[tool_prefix.find(os.path.sep) + 1:]
   return ''
 
 
 def _SyncAndBuild(archive, build, subrepo):
+  """Sync, build and return non 0 if any commands failed."""
   # Simply do a checkout if subrepo is used.
   if subrepo != _SRC_ROOT:
     _GitCmd(['checkout',  archive.rev], subrepo)
+    return 0
   else:
     # Move to a detached state since gclient sync doesn't work with local
     # commits on a branch.
     _GitCmd(['checkout', '--detach'], subrepo)
-    _GclientSyncCmd(archive.rev, subrepo)
-  retcode = build.Run()
-  return retcode == 0
+    logging.info('Syncing to %s', archive.rev)
+    return _GclientSyncCmd(archive.rev, subrepo) or build.Run()
 
 
 def _GenerateRevList(rev, reference_rev, all_in_range, subrepo):
   """Normalize and optionally generate a list of commits in the given range.
 
   Returns:
     A list of revisions ordered from oldest to newest.
   """
   rev_seq = '%s^..%s' % (reference_rev, rev)
   stdout = _GitCmd(['rev-list', rev_seq], subrepo)
@@ skipping 21 matching lines @@
   no_obj_message = ('%s either doesn\'t exist or your local repo is out of '
                     'date, try "git fetch origin master"')
   git_fatal(['cat-file', '-e', rev], no_obj_message % rev)
   git_fatal(['cat-file', '-e', reference_rev], no_obj_message % reference_rev)
   git_fatal(['merge-base', '--is-ancestor', reference_rev, rev],
             'reference-rev is newer than rev')
   return rev, reference_rev
 
 
 def _VerifyUserAccepts(message):
-  _Print(message + 'Do you want to proceed? [y/n]')
+  print message + 'Do you want to proceed? [y/n]'
   if raw_input('> ').lower() != 'y':
-    _global_restore_checkout_func()
     sys.exit()
 
 
 def _EnsureDirectoryClean(subrepo):
-  _Print('Checking source directory')
+  logging.info('Checking source directory')
   stdout = _GitCmd(['status', '--porcelain'], subrepo)
   # Ignore untracked files.
   if stdout and stdout[:2] != '??':
-    _Print('Failure: please ensure working directory is clean.')
+    logging.error('Failure: please ensure working directory is clean.')
     sys.exit()
 
 
-def _Die(s, *args, **kwargs):
-  _Print('Failure: ' + s, *args, **kwargs)
-  _global_restore_checkout_func()
+def _Die(s, *args):
+  logging.error('Failure: ' + s, *args)
   sys.exit(1)
 
 
 def _DownloadBuildArtifacts(archive, build, supersize_path, depot_tools_path):
   """Download artifacts from arm32 chromium perf builder."""
   if depot_tools_path:
     gsutil_path = os.path.join(depot_tools_path, 'gsutil.py')
   else:
     gsutil_path = distutils.spawn.find_executable('gsutil.py')
 
   if not gsutil_path:
     _Die('gsutil.py not found, please provide path to depot_tools via '
          '--depot-tools-path or add it to your PATH')
 
   download_dir = tempfile.mkdtemp(dir=_SRC_ROOT)
   try:
     _DownloadAndArchive(
         gsutil_path, archive, download_dir, build, supersize_path)
   finally:
     shutil.rmtree(download_dir)
 
 
 def _DownloadAndArchive(gsutil_path, archive, dl_dir, build, supersize_path):
   dl_dst = os.path.join(dl_dir, archive.rev)
-  _Print('Downloading build artifacts for {}', archive.rev)
+  logging.info('Downloading build artifacts for %s', archive.rev)
   # gsutil writes stdout and stderr to stderr, so pipe stdout and stderr to
   # sys.stdout.
   retcode = subprocess.call(
       [gsutil_path, 'cp', build.DownloadUrl(archive.rev), dl_dst],
       stdout=sys.stdout, stderr=subprocess.STDOUT)
   if retcode:
-      _Die('unexpected error while downloading {}. It may no longer exist on '
-           'the server or it may not have been uploaded yet (check {}). '
+      _Die('unexpected error while downloading %s. It may no longer exist on '
+           'the server or it may not have been uploaded yet (check %s). '
            'Otherwise, you may not have the correct access permissions.',
            build.DownloadUrl(archive.rev), _BUILDER_URL)
 
   # Files needed for supersize and resource_sizes. Paths relative to out dir.
   to_extract = [build.main_lib_path, build.map_file_path, 'args.gn']
   if build.IsAndroid():
     to_extract += ['build_vars.txt', build.apk_path]
   extract_dir = dl_dst + '_' + 'unzipped'
   # Storage bucket stores entire output directory including out/Release prefix.
-  _Print('Extracting build artifacts')
+  logging.info('Extracting build artifacts')
   with zipfile.ZipFile(dl_dst, 'r') as z:
     _ExtractFiles(to_extract, build.download_output_dir, extract_dir, z)
     dl_out = os.path.join(extract_dir, build.download_output_dir)
     build.output_directory, output_directory = dl_out, build.output_directory
     archive.ArchiveBuildResults(supersize_path)
     build.output_directory = output_directory
 
 
 def _ExtractFiles(to_extract, prefix, dst, z):
   zip_infos = z.infolist()
   assert all(info.filename.startswith(prefix) for info in zip_infos), (
       'Storage bucket folder structure doesn\'t start with %s' % prefix)
   to_extract = [os.path.join(prefix, f) for f in to_extract]
   for f in to_extract:
     z.extract(f, path=dst)
 
 
-def _Print(s, *args, **kwargs):
-  print s.format(*args, **kwargs)
-
-
 def _PrintAndWriteToFile(logfile, s, *args, **kwargs):
   """Write and print |s| thottling output if |s| is a large list."""
   if isinstance(s, basestring):
     s = s.format(*args, **kwargs)
-    _Print(s)
+    print s
     logfile.write('%s\n' % s)
   else:
     for l in s[:_DIFF_DETAILS_LINES_THRESHOLD]:
-      _Print(l)
+      print l
     if len(s) > _DIFF_DETAILS_LINES_THRESHOLD:
-      _Print('\nOutput truncated, see {} for more.', logfile.name)
+      print '\nOutput truncated, see %s for more.' % logfile.name
     logfile.write('\n'.join(s))
 
 
 @contextmanager
 def _TmpCopyBinarySizeDir():
   """Recursively copy files to a temp dir and yield supersize path."""
   # Needs to be at same level of nesting as the real //tools/binary_size
   # since supersize uses this to find d3 in //third_party.
   tmp_dir = tempfile.mkdtemp(dir=_SRC_ROOT)
   try:
     bs_dir = os.path.join(tmp_dir, 'binary_size')
     shutil.copytree(os.path.join(_SRC_ROOT, 'tools', 'binary_size'), bs_dir)
     yield os.path.join(bs_dir, 'supersize')
   finally:
     shutil.rmtree(tmp_dir)
 
 
+def _SetRestoreFunc(subrepo):
+  branch = _GitCmd(['rev-parse', '--abbrev-ref', 'HEAD'], subrepo)
+  atexit.register(lambda: _GitCmd(['checkout', branch], subrepo))
+
+
 def main():
   parser = argparse.ArgumentParser(
       description='Find the cause of APK size bloat.')
   parser.add_argument('--archive-directory',
                       default=_DEFAULT_ARCHIVE_DIR,
                       help='Where results are stored.')
   parser.add_argument('rev',
                       help='Find binary size bloat for this commit.')
   parser.add_argument('--reference-rev',
                       help='Older rev to diff against. If not supplied, '
@@ skipping 12 matching lines @@
                       help='Download build artifacts from perf builders '
                       '(Android only, Googlers only).')
   parser.add_argument('--depot-tools-path',
                       help='Custom path to depot tools. Needed for --cloud if '
                       'depot tools isn\'t in your PATH.')
   parser.add_argument('--subrepo',
                       help='Specify a subrepo directory to use. Gclient sync '
                       'will be skipped if this option is used and all git '
                       'commands will be executed from the subrepo directory. '
                       'This option doesn\'t work with --cloud.')
+  parser.add_argument('--silent',
+                      action='store_true',
+                      help='Less logging, no Ninja/GN output.')
 
   build_group = parser.add_argument_group('ninja', 'Args to use with ninja/gn')
   build_group.add_argument('-j',
                            dest='max_jobs',
                            help='Run N jobs in parallel.')
   build_group.add_argument('-l',
                            dest='max_load_average',
                            help='Do not start new jobs if the load average is '
                            'greater than N.')
   build_group.add_argument('--no-goma',
@@ skipping 13 matching lines @@
                            action='store_true',
                            help='Allow downstream targets to be built.')
   build_group.add_argument('--target',
                            default=_DEFAULT_ANDROID_TARGET,
                            help='GN APK target to build. Ignored for Linux. '
                            'Default %s.' % _DEFAULT_ANDROID_TARGET)
   if len(sys.argv) == 1:
     parser.print_help()
     sys.exit()
   args = parser.parse_args()
+  log_level = logging.INFO if args.silent else logging.DEBUG
+  logging.basicConfig(level=log_level,
+                      format='%(levelname).1s %(relativeCreated)6d %(message)s')
   build = _BuildHelper(args)
   if build.IsCloud() and args.subrepo:
       parser.error('--subrepo doesn\'t work with --cloud')
 
   subrepo = args.subrepo or _SRC_ROOT
   _EnsureDirectoryClean(subrepo)
   _SetRestoreFunc(subrepo)
   if build.IsLinux():
     _VerifyUserAccepts('Linux diffs have known deficiencies (crbug/717550).')
 
   rev, reference_rev = _ValidateRevs(
       args.rev, args.reference_rev or args.rev + '^', subrepo)
   revs = _GenerateRevList(rev, reference_rev, args.all, subrepo)
   with _TmpCopyBinarySizeDir() as supersize_path:
     diffs = [NativeDiff(build.size_name, supersize_path)]
     if build.IsAndroid():
       diffs +=  [
           ResourceSizesDiff(
               build.apk_name, slow_options=args.include_slow_options)
       ]
     diff_mngr = _DiffArchiveManager(
         revs, args.archive_directory, diffs, build, subrepo)
     consecutive_failures = 0
     for i, archive in enumerate(diff_mngr.IterArchives()):
       if archive.Exists():
-        _Print('Found matching metadata for {}, skipping build step.',
-               archive.rev)
+        step = 'download' if build.IsCloud() else 'build'
+        logging.info('Found matching metadata for %s, skipping %s step.',
+                     archive.rev, step)
       else:
         if build.IsCloud():
           _DownloadBuildArtifacts(
               archive, build, supersize_path, args.depot_tools_path)
         else:
-          build_success = _SyncAndBuild(archive, build, subrepo)
-          if not build_success:
+          build_failure = _SyncAndBuild(archive, build, subrepo)
+          if build_failure:
+            logging.info(
+                'Build failed for %s, diffs using this rev will be skipped.',
+                archive.rev)
             consecutive_failures += 1
             if consecutive_failures > _ALLOWED_CONSECUTIVE_FAILURES:
-              _Die('{} builds failed in a row, last failure was {}.',
+              _Die('%d builds failed in a row, last failure was %s.',
                    consecutive_failures, archive.rev)
           else:
             archive.ArchiveBuildResults(supersize_path)
             consecutive_failures = 0
 
       if i != 0:
         diff_mngr.MaybeDiff(i - 1, i)
 
     diff_mngr.Summarize()
 
-  _global_restore_checkout_func()
 
 if __name__ == '__main__':
   sys.exit(main())