Added 'git-retry' bootstrap

git_retry.py

Index: git_retry.py
diff --git a/git_retry.py b/git_retry.py
new file mode 100755
index 0000000000000000000000000000000000000000..7a88ac9a5c0e36804db3bf93423f04d4f22e05b4
--- /dev/null
+++ b/git_retry.py
@@ -0,0 +1,144 @@
+#!/usr/bin/env python
+# Copyright 2014 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 datetime
+import logging
+import optparse
+import subprocess
+import sys
+import threading
+import time
+
+from git_common import GIT_EXE, GIT_TRANSIENT_ERRORS_RE
+
+
+class TeeThread(threading.Thread):
+
+  def __init__(self, fd, out_fd, name):
+    super(TeeThread, self).__init__(name='git-retry.tee.%s' % (name,))
+    self.chunks = []
+    self.data = None
+    self.fd = fd
+    self.out_fd = out_fd
+
+  def run(self):

[Peter Mayo, 2014/07/22 22:34:36]

why not chunks = [] and replace self.chunks with chunks below?

[dnj, 2014/07/22 23:16:20]

Done.

+    for line in self.fd:
+      self.chunks.append(line)
+      self.out_fd.write(line)
+    self.data = ''.join(self.chunks)
+
+
+class GitRetry(object):
+
+  logger = logging.getLogger('git-retry')
+  DEFAULT_RETRY_COUNT = 5
+
+  def __init__(self, retry_count=None, accepted_return_codes=None, delay=None,
+               delay_exponential=False):
+    self.retry_count = retry_count or self.DEFAULT_RETRY_COUNT
+    self.accepted_return_codes = accepted_return_codes or [0]
+    self.delay = delay or datetime.timedelta(0)
+    self.delay_exponential = delay_exponential
+
+  def shouldRetry(self, stderr):
+    m = GIT_TRANSIENT_ERRORS_RE.search(stderr)
+    if not m:
+      return False
+    if self.logger.isEnabledFor(logging.INFO):
+      start, end = m.span()
+      self.logger.info("Encountered known transient error: [%s]",
+                       stderr[start:end])

[Peter Mayo, 2014/07/22 22:34:36]

why not just 
self.logger.info("Encountered known transient error: [%s]",
  stderr[m.start():m.end()])
?

[dnj, 2014/07/22 23:16:20]

I liked one call vs. 2, but it does look better. Done.

[Peter Mayo, 2014/07/22 23:39:54]

The "if" can disappear now too. Taking the side-effect variance of turning up
logging with it.

+    return True
+
+  def execute(self, *args):
+    args = (GIT_EXE,) + args
+    proc = subprocess.Popen(
+        args,

[Peter Mayo, 2014/07/22 22:34:36]

This potentially desynchronizes stdout & stderr.
! bang
may now come out as 
! bang

Actually seems OK, but I don't know the git discipline.

[dnj, 2014/07/22 23:16:20]

You're completely correct. However, AFAIK any assumptions about STDOUT and
STDERR being synchronized are bad assumptions. The two serve different purposes
and carry independent data streams.

As things stand, all of the transient errors that we're looking for are
currently in STDERR, so I'm taking the lighter-weight approach and only tee-ing
it. If we need to ever examine STDOUT, we can add it later pretty painlessly.

+        stderr=subprocess.PIPE,
+    )
+    stderr_tee = TeeThread(proc.stderr, sys.stderr, 'stderr')
+
+    # Start our process. Collect/tee 'stdout' and 'stderr'.
+    stderr_tee.start()
+    try:
+      proc.wait()
+    except KeyboardInterrupt:
+      proc.kill()
+      raise
+    finally:
+      stderr_tee.join()
+    return proc.returncode, None, stderr_tee.data

[Peter Mayo, 2014/07/22 22:34:36]

returning stdout as None because we left it on sys.stdout seems wierd

[dnj, 2014/07/22 23:16:20]

Just leaving room in case we need to filter on STDOUT later. It feels more
Pythonic to return them as a tuple, just like 'proc.communicate()' does.

+
+  def __call__(self, *args):
+    delay = self.delay
+
+    returncode = 0
+    for i in xrange(self.retry_count):
+      self.logger.info("Executing subprocess (%d/%d) with arguments: %s",
+                       (i+1), self.retry_count, args)
+      returncode, stdout, stderr = self.execute(*args)
+
+      self.logger.debug("Process terminated with return code: %d", returncode)
+      if returncode == 0:
+        break
+
+      if not self.shouldRetry(stderr):
+        self.logger.error("Process failure was not known to be transient; "
+                          "terminating with return code %d", returncode)
+        break
+
+      # Delay (if requested)

[Peter Mayo, 2014/07/22 22:34:36]

- Doesn't make sense to delay after last (failed) attempt.
- I would prefer the delay, and the evolution of delay be at least as separated
as execute.
- I would prefer an exponential delay be the default
- I would prefer factors other than 2 be supported.

suggest adding line 78.5:
delay = self.compute_delay(i)
if delay > 0:
  self.logger.debug("Delaying for %s until next retry", delay)
  time.sleep(delay.total_seconds())

[dnj, 2014/07/22 23:16:20]

Done.

+      if delay:
+        self.logger.debug("Delaying for %s until next retry", delay)
+        time.sleep(delay.total_seconds())
+        if self.delay_exponential:
+          delay *= 2
+    return returncode
+
+
+def main(args):
+  parser = optparse.OptionParser()
+  parser.disable_interspersed_args()
+  parser.add_option('-v', '--verbose',
+                    action='count', default=0,
+                    help="Increase verbosity; can be specified multiple times")
+  parser.add_option('-c', '--retry-count', metavar='COUNT',
+                    type=int, default=GitRetry.DEFAULT_RETRY_COUNT,
+                    help="Number of times to retry (default=%default)")
+  parser.add_option('-d', '--delay', metavar='SECONDS',
+                    type=int, default=0,
+                    help="Specifies the amount of time (in milliseconds) to "
+                         "wait between successive retries.")
+  parser.add_option('-e', '--delay-exponential',
+                    action='store_true',
+                    help="If specified, the amount of delay between successive "
+                         "retries will double with each retry.")
+
+  opts, args = parser.parse_args(args)
+
+  # Configure logging verbosity
+  if opts.verbose == 0:
+    logging.getLogger().setLevel(logging.WARNING)
+  elif opts.verbose == 1:
+    logging.getLogger().setLevel(logging.INFO)
+  else:
+    logging.getLogger().setLevel(logging.DEBUG)
+
+  # Convert 'delay' to timedelta
+  delay = datetime.timedelta(seconds=opts.delay) if opts.delay else None
+
+  # Execute retries
+  retry = GitRetry(
+      retry_count=opts.retry_count,
+      delay=delay,
+      delay_exponential=opts.delay_exponential,
+  )
+  return retry(*args)
+
+
+if __name__ == '__main__':
+  logging.basicConfig()
+  logging.getLogger().setLevel(logging.WARNING)
+  sys.exit(main(sys.argv[2:]))