Add logging to fetch, retry if gitiles gives us weird unicode

recipe_engine/fetch.py

 # Copyright 2016 The LUCI Authors. All rights reserved.
 # Use of this source code is governed under the Apache License, Version 2.0
 # that can be found in the LICENSE file.
 
 import base64
 import functools
 import json
 import logging
 import os
 import random
 import shutil
 import sys
 import tarfile
 import tempfile
 import time
 
 # Add third party paths.
 from . import env
 from . import requests_ssl
 from .requests_ssl import requests
 
 import subprocess42
 from google.protobuf import text_format
 
 from . import package_pb2
 
+class RetryFetch(Exception):
+  """Raised to indicate that the fetch operation should be retried"""
+  def __init__(self, e):
+    super(RetryFetch, self).__init__(
+        'Retrying fetch because of exception: %r' % e)
+    self.exc = e
 
 class FetchError(Exception):
   pass
 
 
 class UncleanFilesystemError(FetchError):
   pass
 
 
 class FetchNotAllowedError(FetchError):
@@ skipping 15 matching lines @@
 
 
 def _retry(f):
   @functools.wraps(f)
   def wrapper(*args, **kwargs):
     delay = random.uniform(2, 5)
     for _ in range(5):
       try:
         return f(*args, **kwargs)
       except (requests.exceptions.RequestException,
-              subprocess42.CalledProcessError):
+              subprocess42.CalledProcessError,
+              RetryFetch) as e:
         # Only retry specific errors that may be transient.
-        logging.exception('retrying')
+        logging.warning('retrying because of %s', e)
         time.sleep(delay)
         delay *= 2
     return f(*args, **kwargs)
   return wrapper
 
 
 class Backend(object):
   @property
   def repo_type(self):
     """Returns repo type (see package_pb2.DepSpec)."""
@@ skipping 108 matching lines @@
           'need to download %s from gitiles but fetch not allowed' % repo)
 
     revision = self._resolve_revision(repo, revision)
 
     shutil.rmtree(checkout_dir, ignore_errors=True)
 
     recipes_cfg_url = '%s/+/%s/infra/config/recipes.cfg?format=TEXT' % (
         repo, requests.utils.quote(revision))
     logging.info('fetching %s' % recipes_cfg_url)
     recipes_cfg_request = requests.get(recipes_cfg_url)
-    recipes_cfg_text = base64.b64decode(recipes_cfg_request.text)
+    try:
+      recipes_cfg_text = base64.b64decode(recipes_cfg_request.text)
+    except UnicodeEncodeError as e:
+      # UnicodeEncodeError can happen sometimes, if gitiles gives us some weird
+      # response. Just retry the whole thing.
+      logging.exception(
+          "got strange response from gitiles: %s", recipes_cfg_request.text)
+      raise RetryFetch(e)
+
     recipes_cfg_proto = package_pb2.Package()
     text_format.Merge(recipes_cfg_text, recipes_cfg_proto)
     recipes_path_rel = recipes_cfg_proto.recipes_path
 
     # Re-create recipes.cfg in |checkout_dir| so that the repo's recipes.py
     # can look it up.
     recipes_cfg_path = os.path.join(
         checkout_dir, 'infra', 'config', 'recipes.cfg')
     os.makedirs(os.path.dirname(recipes_cfg_path))
     with open(recipes_cfg_path, 'w') as f:
@@ skipping 66 matching lines @@
     """Returns a git sha corresponding to given revision.
 
     Examples of non-sha revision: origin/master, HEAD."""
     rev_json = self._revision_metadata(repo, revision)
     logging.info('resolved %s to %s', revision, rev_json['commit'])
     return rev_json['commit']
 
   def _fetch_gitiles_json(self, url):
     """Fetches JSON from Gitiles and returns parsed result."""
     logging.info('fetching %s', url)
-    raw = requests.get(url).text
+    resp = requests.get(url)
+    raw = resp.text
     if not raw.startswith(')]}\'\n'):
-      raise FetchError('Unexpected gitiles response: %s' % raw)
+      logging.warning("Unexpected gitiles response: %s", raw)
+      raise FetchError(

[martiniss, 2016/09/23 00:42:58]

A (maybe unfounded) hypothesis is that the exception printing logic in python
doesn't like printing out gigantic text, which raw might be. So, I'm printing a
truncated text in the exception, and logging the full thing above.

+          'Unexpected gitiles response (code %d): %s... (truncated, see log for'
+          'full details)' % (resp.status_code, raw[:100]))
+
     return json.loads(raw.split('\n', 1)[1])