Make apply_issue.py much more verbose about what it's doing.

checkout.py

 # coding=utf8
 # Copyright (c) 2012 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.
 """Manages a project checkout.
 
 Includes support for svn, git-svn and git.
 """
 
 import ConfigParser
@@ skipping 29 matching lines @@
           return None
         k, v = line.split(':', 1)
         settings[k.strip()] = v.strip()
     finally:
       settings_file.close()
   except IOError:
     return None
   return settings.get(key, None)
 
 
+def align_stdout(stdout):
+  """Returns the aligned output of multiple stdouts."""
+  output = ''
+  for item in stdout:
+    item = item.strip()
+    if not item:
+      continue
+    output += ''.join('  %s\n' % line for line in item.splitlines())
+  return output
+
+
 class PatchApplicationFailed(Exception):
   """Patch failed to be applied."""
   def __init__(self, p, status):
     super(PatchApplicationFailed, self).__init__(p, status)
     self.patch = p
     self.status = status
 
   @property
   def filename(self):
     if self.patch:
       return self.patch.filename
 
   def __str__(self):
     out = []
     if self.filename:
       out.append('Failed to apply patch for %s:' % self.filename)
     if self.status:
       out.append(self.status)
+    out.append('Patch: %s' % self.patch.dump())
     return '\n'.join(out)
 
 
 class CheckoutBase(object):
   # Set to None to have verbose output.
   VOID = subprocess2.VOID
 
   def __init__(self, root_dir, project_name, post_processors):
     """
     Args:
@@ skipping 20 matching lines @@
     """Checks out a clean copy of the tree and removes any local modification.
 
     This function shouldn't throw unless the remote repository is inaccessible,
     there is no free disk space or hard issues like that.
 
     Args:
       revision: The revision it should sync to, SCM specific.
     """
     raise NotImplementedError()
 
-  def apply_patch(self, patches, post_processors=None):
+  def apply_patch(self, patches, post_processors=None, verbose=False):
     """Applies a patch and returns the list of modified files.
 
     This function should throw patch.UnsupportedPatchFormat or
     PatchApplicationFailed when relevant.
 
     Args:
       patches: patch.PatchSet object.
     """
     raise NotImplementedError()
 
@@ skipping 13 matching lines @@
 
 class RawCheckout(CheckoutBase):
   """Used to apply a patch locally without any intent to commit it.
 
   To be used by the try server.
   """
   def prepare(self, revision):
     """Stubbed out."""
     pass
 
-  def apply_patch(self, patches, post_processors=None):
+  def apply_patch(self, patches, post_processors=None, verbose=False):
     """Ignores svn properties."""
     post_processors = post_processors or self.post_processors or []
     for p in patches:
-      logging.debug('Applying %s' % p.filename)
+      stdout = []
       try:
-        stdout = ''
-        filename = os.path.join(self.project_path, p.filename)
+        filepath = os.path.join(self.project_path, p.filename)
         if p.is_delete:
-          os.remove(filename)
+          os.remove(filepath)
+          stdout.append('Deleted.')
         else:
           dirname = os.path.dirname(p.filename)
           full_dir = os.path.join(self.project_path, dirname)
           if dirname and not os.path.isdir(full_dir):
             os.makedirs(full_dir)
+            stdout.append('Created missing directory %s.' % dirname)
 
-          filepath = os.path.join(self.project_path, p.filename)
           if p.is_binary:
+            content = p.get()
             with open(filepath, 'wb') as f:
-              f.write(p.get())
+              f.write(content)
+            stdout.append('Added binary file %d bytes.' % len(content))
           else:
             if p.source_filename:
               if not p.is_new:
                 raise PatchApplicationFailed(
                     p,
                     'File has a source filename specified but is not new')
               # Copy the file first.
               if os.path.isfile(filepath):
                 raise PatchApplicationFailed(
                     p, 'File exist but was about to be overwriten')
               shutil.copy2(
                   os.path.join(self.project_path, p.source_filename), filepath)
+              stdout.append('Copied %s -> %s' % (p.source_filename, p.filename))
             if p.diff_hunks:
-              stdout = subprocess2.check_output(
-                  ['patch', '-u', '--binary', '-p%s' % p.patchlevel],
-                  stdin=p.get(False),
-                  stderr=subprocess2.STDOUT,
-                  cwd=self.project_path)
+              cmd = ['patch', '-u', '--binary', '-p%s' % p.patchlevel]
+              if verbose:
+                cmd.append('--verbose')
+              stdout.append(
+                  subprocess2.check_output(
+                      cmd,
+                      stdin=p.get(False),
+                      stderr=subprocess2.STDOUT,
+                      cwd=self.project_path))
             elif p.is_new and not os.path.exists(filepath):
               # There is only a header. Just create the file.
               open(filepath, 'w').close()
+              stdout.append('Created an empty file.')
         for post in post_processors:
           post(self, p)
+        if verbose:
+          print p.filename
+          print align_stdout(stdout)
       except OSError, e:
-        raise PatchApplicationFailed(p, '%s%s' % (stdout, e))
+        raise PatchApplicationFailed(p, '%s%s' % (align_stdout(stdout), e))
       except subprocess.CalledProcessError, e:
         raise PatchApplicationFailed(
-            p, '%s%s' % (stdout, getattr(e, 'stdout', None)))
+            p,
+            'While running %s;\n%s%s' % (
+              ' '.join(e.cmd),
+              align_stdout(stdout),
+              align_stdout([getattr(e, 'stdout', '')])))
 
   def commit(self, commit_message, user):
     """Stubbed out."""
     raise NotImplementedError('RawCheckout can\'t commit')
 
   def revisions(self, _rev1, _rev2):
     return None
 
 
 class SvnConfig(object):
@@ skipping 92 matching lines @@
     assert bool(self.commit_user) >= bool(self.commit_pwd)
 
   def prepare(self, revision):
     # Will checkout if the directory is not present.
     assert self.svn_url
     if not os.path.isdir(self.project_path):
       logging.info('Checking out %s in %s' %
           (self.project_name, self.project_path))
     return self._revert(revision)
 
-  def apply_patch(self, patches, post_processors=None):
+  def apply_patch(self, patches, post_processors=None, verbose=False):
     post_processors = post_processors or self.post_processors or []
     for p in patches:
-      logging.debug('Applying %s' % p.filename)
+      stdout = []
       try:
+        filepath = os.path.join(self.project_path, p.filename)
         # It is important to use credentials=False otherwise credentials could
         # leak in the error message. Credentials are not necessary here for the
         # following commands anyway.
-        stdout = ''
         if p.is_delete:
-          stdout += self._check_output_svn(
-              ['delete', p.filename, '--force'], credentials=False)
+          stdout.append(self._check_output_svn(
+              ['delete', p.filename, '--force'], credentials=False))
+          stdout.append('Deleted.')
         else:
           # svn add while creating directories otherwise svn add on the
           # contained files will silently fail.
           # First, find the root directory that exists.
           dirname = os.path.dirname(p.filename)
           dirs_to_create = []
           while (dirname and
               not os.path.isdir(os.path.join(self.project_path, dirname))):
             dirs_to_create.append(dirname)
             dirname = os.path.dirname(dirname)
           for dir_to_create in reversed(dirs_to_create):
             os.mkdir(os.path.join(self.project_path, dir_to_create))
-            stdout += self._check_output_svn(
-                ['add', dir_to_create, '--force'], credentials=False)
+            stdout.append(
+                self._check_output_svn(
+                  ['add', dir_to_create, '--force'], credentials=False))
+            stdout.append('Created missing directory %s.' % dir_to_create)
 
-          filepath = os.path.join(self.project_path, p.filename)
           if p.is_binary:
+            content = p.get()
             with open(filepath, 'wb') as f:
-              f.write(p.get())
+              f.write(content)
+            stdout.append('Added binary file %d bytes.' % len(content))
           else:
             if p.source_filename:
               if not p.is_new:
                 raise PatchApplicationFailed(
                     p,
                     'File has a source filename specified but is not new')
               # Copy the file first.
               if os.path.isfile(filepath):
                 raise PatchApplicationFailed(
                     p, 'File exist but was about to be overwriten')
-              self._check_output_svn(
-                  ['copy', p.source_filename, p.filename])
+              stdout.append(
+                  self._check_output_svn(
+                    ['copy', p.source_filename, p.filename]))
+              stdout.append('Copied %s -> %s' % (p.source_filename, p.filename))
             if p.diff_hunks:
               cmd = [
                 'patch',
                 '-p%s' % p.patchlevel,
                 '--forward',
                 '--force',
                 '--no-backup-if-mismatch',
               ]
-              stdout += subprocess2.check_output(
-                  cmd, stdin=p.get(False), cwd=self.project_path)
+              stdout.append(
+                  subprocess2.check_output(
+                    cmd, stdin=p.get(False), cwd=self.project_path))
             elif p.is_new and not os.path.exists(filepath):
               # There is only a header. Just create the file if it doesn't
               # exist.
               open(filepath, 'w').close()
+              stdout.append('Created an empty file.')
           if p.is_new and not p.source_filename:
             # Do not run it if p.source_filename is defined, since svn copy was
             # using above.
-            stdout += self._check_output_svn(
-                ['add', p.filename, '--force'], credentials=False)
+            stdout.append(
+                self._check_output_svn(
+                  ['add', p.filename, '--force'], credentials=False))
           for name, value in p.svn_properties:
             if value is None:
-              stdout += self._check_output_svn(
-                  ['propdel', '--quiet', name, p.filename], credentials=False)
+              stdout.append(
+                  self._check_output_svn(
+                    ['propdel', '--quiet', name, p.filename],
+                    credentials=False))
+              stdout.append('Property %s deleted.' % name)
             else:
-              stdout += self._check_output_svn(
-                  ['propset', name, value, p.filename], credentials=False)
+              stdout.append(
+                  self._check_output_svn(
+                    ['propset', name, value, p.filename], credentials=False))
+              stdout.append('Property %s=%s' % (name, value))
           for prop, values in self.svn_config.auto_props.iteritems():
             if fnmatch.fnmatch(p.filename, prop):
               for value in values.split(';'):
                 if '=' not in value:
                   params = [value, '.']
                 else:
                   params = value.split('=', 1)
                 if params[1] == '*':
                   # Works around crbug.com/150960 on Windows.
                   params[1] = '.'
-                stdout += self._check_output_svn(
-                    ['propset'] + params + [p.filename], credentials=False)
+                stdout.append(
+                    self._check_output_svn(
+                      ['propset'] + params + [p.filename], credentials=False))
+                stdout.append('Property (auto) %s' % '='.join(params))
         for post in post_processors:
           post(self, p)
+        if verbose:
+          print p.filename
+          print align_stdout(stdout)
       except OSError, e:
-        raise PatchApplicationFailed(p, '%s%s' % (stdout, e))
+        raise PatchApplicationFailed(p, '%s%s' % (align_stdout(stdout), e))
       except subprocess.CalledProcessError, e:
         raise PatchApplicationFailed(
             p,
             'While running %s;\n%s%s' % (
-              ' '.join(e.cmd), stdout, getattr(e, 'stdout', '')))
+              ' '.join(e.cmd),
+              align_stdout(stdout),
+              align_stdout([getattr(e, 'stdout', '')])))
 
   def commit(self, commit_message, user):
     logging.info('Committing patch for %s' % user)
     assert self.commit_user
     assert isinstance(commit_message, unicode)
     handle, commit_filename = tempfile.mkstemp(text=True)
     try:
       # Shouldn't assume default encoding is UTF-8. But really, if you are using
       # anything else, you are living in another world.
       os.write(handle, commit_message.encode('utf-8'))
@@ skipping 90 matching lines @@
         revision = self._check_output_git(['rev-parse', revision])
       self._check_call_git(['checkout', '--force', '--quiet', revision])
     else:
       branches, active = self._branches()
       if active != 'master':
         self._check_call_git(['checkout', '--force', '--quiet', 'master'])
       self._check_call_git(['pull', self.remote, self.remote_branch, '--quiet'])
       if self.working_branch in branches:
         self._call_git(['branch', '-D', self.working_branch])
 
-  def apply_patch(self, patches, post_processors=None):
+  def apply_patch(self, patches, post_processors=None, verbose=False):
     """Applies a patch on 'working_branch' and switch to it.
 
     Also commits the changes on the local branch.
 
     Ignores svn properties and raise an exception on unexpected ones.
     """
     post_processors = post_processors or self.post_processors or []
     # It this throws, the checkout is corrupted. Maybe worth deleting it and
     # trying again?
     if self.remote_branch:
       self._check_call_git(
           ['checkout', '-b', self.working_branch,
             '%s/%s' % (self.remote, self.remote_branch), '--quiet'])
     for index, p in enumerate(patches):
-      logging.debug('Applying %s' % p.filename)
+      stdout = []
       try:
-        stdout = ''
+        filepath = os.path.join(self.project_path, p.filename)
         if p.is_delete:
-          if (not os.path.exists(p.filename) and
+          if (not os.path.exists(filepath) and
               any(p1.source_filename == p.filename for p1 in patches[0:index])):
-            # The file could already be deleted if a prior patch with file
-            # rename was already processed. To be sure, look at all the previous
-            # patches to see if they were a file rename.
+            # The file was already deleted if a prior patch with file rename
+            # was already processed because 'git apply' did it for us.
             pass
           else:
-            stdout += self._check_output_git(['rm', p.filename])
+            stdout.append(self._check_output_git(['rm', p.filename]))
+            stdout.append('Deleted.')
         else:
           dirname = os.path.dirname(p.filename)
           full_dir = os.path.join(self.project_path, dirname)
           if dirname and not os.path.isdir(full_dir):
             os.makedirs(full_dir)
+            stdout.append('Created missing directory %s.' % dirname)
           if p.is_binary:
-            with open(os.path.join(self.project_path, p.filename), 'wb') as f:
-              f.write(p.get())
-            stdout += self._check_output_git(['add', p.filename])
+            content = p.get()
+            with open(filepath, 'wb') as f:
+              f.write(content)
+            stdout.append('Added binary file %d bytes' % len(content))
+            cmd = ['add', p.filename]
+            if verbose:
+              cmd.append('--verbose')
+            stdout.append(self._check_output_git(cmd))
           else:
             # No need to do anything special with p.is_new or if not
             # p.diff_hunks. git apply manages all that already.
-            stdout += self._check_output_git(
-                ['apply', '--index', '-p%s' % p.patchlevel], stdin=p.get(True))
-          for name, _ in p.svn_properties:
+            cmd = ['apply', '--index', '-p%s' % p.patchlevel]
+            if verbose:
+              cmd.append('--verbose')
+            stdout.append(self._check_output_git(cmd, stdin=p.get(True)))
+          for name, value in p.svn_properties:
             # Ignore some known auto-props flags through .subversion/config,
             # bails out on the other ones.
             # TODO(maruel): Read ~/.subversion/config and detect the rules that
             # applies here to figure out if the property will be correctly
             # handled.
+            stdout.append('Property %s=%s' % (name, value))
             if not name in (
                 'svn:eol-style', 'svn:executable', 'svn:mime-type'):
               raise patch.UnsupportedPatchFormat(
                   p.filename,
                   'Cannot apply svn property %s to file %s.' % (
                         name, p.filename))
         for post in post_processors:
           post(self, p)
+        if verbose:
+          print p.filename
+          print align_stdout(stdout)
       except OSError, e:
-        raise PatchApplicationFailed(p, '%s%s' % (stdout, e))
+        raise PatchApplicationFailed(p, '%s%s' % (align_stdout(stdout), e))
       except subprocess.CalledProcessError, e:
         raise PatchApplicationFailed(
-            p, '%s%s' % (stdout, getattr(e, 'stdout', None)))
+            p,
+            'While running %s;\n%s%s' % (
+              ' '.join(e.cmd),
+              align_stdout(stdout),
+              align_stdout([getattr(e, 'stdout', '')])))
     # Once all the patches are processed and added to the index, commit the
     # index.
-    self._check_call_git(['commit', '-m', 'Committed patch'])
+    cmd = ['commit', '-m', 'Committed patch']
+    if verbose:
+      cmd.append('--verbose')
+    self._check_call_git(cmd)
     # TODO(maruel): Weirdly enough they don't match, need to investigate.
     #found_files = self._check_output_git(
     #    ['diff', 'master', '--name-only']).splitlines(False)
     #assert sorted(patches.filenames) == sorted(found_files), (
     #    sorted(out), sorted(found_files))
 
   def commit(self, commit_message, user):
     """Updates the commit message.
 
     Subclass needs to dcommit or push.
@@ skipping 61 matching lines @@
     self.checkout = checkout
     self.post_processors = (post_processors or []) + (
         self.checkout.post_processors or [])
 
   def prepare(self, revision):
     return self.checkout.prepare(revision)
 
   def get_settings(self, key):
     return self.checkout.get_settings(key)
 
-  def apply_patch(self, patches, post_processors=None):
+  def apply_patch(self, patches, post_processors=None, verbose=False):
     return self.checkout.apply_patch(
-        patches, post_processors or self.post_processors)
+        patches, post_processors or self.post_processors, verbose)
 
   def commit(self, message, user):  # pylint: disable=R0201
     logging.info('Would have committed for %s with message: %s' % (
         user, message))
     return 'FAKE'
 
   def revisions(self, rev1, rev2):
     return self.checkout.revisions(rev1, rev2)
 
   @property
   def project_name(self):
     return self.checkout.project_name
 
   @property
   def project_path(self):
     return self.checkout.project_path