Added 'git-retry' bootstrap

git_retry.py

+#!/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 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.data = None
+    self.fd = fd
+    self.out_fd = out_fd
+
+  def run(self):
+    chunks = []
+    for line in self.fd:
+      chunks.append(line)
+      self.out_fd.write(line)
+    self.data = ''.join(chunks)
+
+
+class GitRetry(object):
+
+  logger = logging.getLogger('git-retry')
+  DEFAULT_DELAY_SECS = 3.0
+  DEFAULT_RETRY_COUNT = 5
+
+  def __init__(self, retry_count=None, accepted_return_codes=None, delay=None,
+               delay_factor=False):
+    self.retry_count = retry_count or self.DEFAULT_RETRY_COUNT
+    self.accepted_return_codes = accepted_return_codes or [0]
+    self.delay = delay
+    self.delay_factor = delay_factor
+
+  def shouldRetry(self, stderr):
+    m = GIT_TRANSIENT_ERRORS_RE.search(stderr)
+    if not m:
+      return False
+    if self.logger.isEnabledFor(logging.INFO):
+      self.logger.info("Encountered known transient error: [%s]",
+                       stderr[m.start(): m.end()])
+    return True
+
+  @staticmethod
+  def execute(*args):
+    args = (GIT_EXE,) + args
+    proc = subprocess.Popen(
+        args,
+        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
+
+  def computeDelay(self, iteration):
+    """Returns: the delay (in seconds) for a given iteration
+
+    The first iteration has a delay of '0'.
+
+    Args:
+      iteration: (int) The iteration index (starting with zero as the first
+          iteration)
+    """
+    if (not self.delay) or (iteration == 0):
+      return 0
+    if self.delay_factor <= 0:
+      # Linear delay
+      return iteration * self.delay

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

won't this be negative in the usual case?

[dnj, 2014/07/23 00:04:52]

The negative was more of a catch-all; the usual case here is '0'. I'm going to
just constrain this value to a positive (>=0) integer in the constructor.

+    # Exponential delay
+    return (self.delay_factor ** (iteration - 1)) * self.delay

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

Consider dividing and using (count - iteration) instead (delay becomes maximum
instead of minimum delay)

or perhaps choosing this when delay < 0

[dnj, 2014/07/23 00:04:52]

I don't want to make this 'factor' number too complicated. It already chooses
between linear and non-linear delays. I'd like the default to be a good common
option choice. Right now, the default goes: 0, 3, 6, 12, 24.

Chromite uses a linear scaling (iteration * factor), which is why that was
default in the previous patch set. However, I think the above numbers ride a
nice line between giving ample retry time and failing bots semi-fast. Thoughts?

+
+  def __call__(self, *args):
+    returncode = 0
+    for i in xrange(self.retry_count):
+      # If the previous run failed and a delay is configured, delay before the
+      # next run.
+      delay = self.computeDelay(i)
+      if delay > 0:
+        self.logger.info("Delaying for [%s second(s)] until next retry", delay)
+        time.sleep(delay)
+
+      self.logger.debug("Executing subprocess (%d/%d) with arguments: %s",
+                        (i+1), self.retry_count, args)
+      returncode, _, 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
+    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=float, default=GitRetry.DEFAULT_DELAY_SECS,
+                    help="Specifies the amount of time (in seconds) to wait "
+                         "between successive retries (default=%default). This "
+                         "can be zero.")
+  parser.add_option('-D', '--delay-factor', metavar='FACTOR',
+                    type=int, default=2,
+                    help="The exponential factor to apply to delays in between "
+                         "successive failures (default=%default). If this is "
+                         "zero, delays will increase linearly. Set this to "
+                         "one to have a constant (non-increasing) delay.")
+
+  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)
+
+  # Execute retries
+  retry = GitRetry(
+      retry_count=opts.retry_count,
+      delay=opts.delay,
+      delay_factor=opts.delay_factor,
+  )
+  return retry(*args)
+
+
+if __name__ == '__main__':
+  logging.basicConfig()
+  logging.getLogger().setLevel(logging.WARNING)
+  sys.exit(main(sys.argv[2:]))