Merge pull request #24 from jacebrowning/add-logging

Add logging for error conditions

coveragespace/cache.py

@@ -1,5 +1,9 @@
 import os
 import pickle
+import logging
+
+
+log = logging.getLogger(__name__)
 
 
 class Cache(object):
@@ -36,12 +40,17 @@ def _store(self):
 
     def set(self, url, data, response):
         slug = self._slugify(url, data)
+        log.debug("Setting cache for %s: %s", url, data)
         self._data[slug] = response
+        log.debug("Cached value: %s", response)
         self._store()
 
     def get(self, url, data):
+        log.debug("Getting cache for %s: %s", url, data)
         slug = self._slugify(url, data)
-        return self._data.get(slug)
+        value = self._data.get(slug)
+        log.debug("Cached value: %s", value)
+        return value
 
     @staticmethod
     def _slugify(url, data):

coveragespace/cli.py

@@ -9,14 +9,16 @@
   -h --help         Show this help screen.
   -V --version      Show the program version.
   -v --verbose      Always display the coverage metrics.
-  --exit-code       Return non-zero exit code on failures.
+  -x --exit-code    Return non-zero exit code on failures.
 
 """
 
 from __future__ import unicode_literals
 
 import sys
+import time
 import json
+import logging
 
 import six
 from docopt import docopt
@@ -30,6 +32,7 @@
 from .cache import Cache
 
 
+log = logging.getLogger(__name__)
 cache = Cache()
 
 
@@ -44,6 +47,12 @@ def main():
     verbose = arguments['--verbose']
     hardfail = arguments['--exit-code']
 
+    if verbose:
+        logging.basicConfig(
+            level=logging.DEBUG,
+            format="%(levelname)s: %(name)s: %(message)s",
+        )
+
     success = call(slug, metric, value, verbose, hardfail)
 
     if not success and hardfail:
@@ -54,11 +63,7 @@ def call(slug, metric, value, verbose=False, hardfail=False):
     """Call the API and display errors."""
     url = "{}/{}".format(API, slug)
     data = {metric: value}
-
-    response = cache.get(url, data)
-    if response is None:
-        response = requests.put(url, data=data)
-        cache.set(url, data, response)
+    response = request(url, data)
 
     if response.status_code == 200:
         if verbose:
@@ -71,10 +76,35 @@ def call(slug, metric, value, verbose=False, hardfail=False):
         return False
 
     else:
-        display("coverage unknown", response.json(), colorama.Fore.RED)
+        try:
+            data = response.json()
+            display("coverage unknown", data, colorama.Fore.RED)
+        except (TypeError, ValueError) as exc:
+            data = response.data.decode('utf-8')
+            log.error("%s\n\nwhen decoding response:\n\n%s\n", exc, data)
         return False
 
 
+def request(url, data):
+    """Make request to external API."""
+    log.info("Updating %s: %s", url, data)
+
+    response = cache.get(url, data)
+    if response is None:
+        for _ in range(2):
+            response = requests.put(url, data=data)
+            if response.status_code == 500:
+                time.sleep(1)
+                continue
+            else:
+                break
+        cache.set(url, data, response)
+
+    log.info("Response: %s", response)
+
+    return response
+
+
 def display(title, data, color=""):
     """Write colored text to the console."""
     color += colorama.Style.BRIGHT

coveragespace/tests/conftest.py

@@ -1,8 +1,15 @@
 """Unit tests configuration file."""
 
+import logging
+
 
 def pytest_configure(config):
     """Disable verbose output when running tests."""
+    logging.basicConfig(
+        level=logging.DEBUG,
+        format="%(levelname)s: %(name)s: %(message)s",
+    )
+
     terminal = config.pluginmanager.getplugin('terminal')
     base = terminal.TerminalReporter
 

coveragespace/tests/test_cli.py

@@ -0,0 +1,24 @@
+# pylint: disable=unused-variable,expression-not-assigned,singleton-comparison
+
+from mock import patch, Mock
+from expecter import expect
+
+from coveragespace import cli
+
+
+def describe_call():
+
+    @patch('coveragespace.cache.Cache.get', Mock())
+    def it_handles_invalid_response():
+        expect(cli.call('slug', 'metric', 42)) == False
+
+    @patch('coveragespace.cache.Cache.get', Mock(return_value=None))
+    @patch('coveragespace.cache.Cache.set', Mock(return_value=None))
+    @patch('time.sleep', Mock())
+    @patch('requests.put')
+    def it_retries_500s(requests_put):
+        requests_put.return_value = Mock(status_code=500)
+
+        cli.call('slug', 'metric', 42)
+
+        expect(requests_put.call_count) == 2

tests/test_cli.py

@@ -59,5 +59,5 @@ def it_always_display_metrics_when_verbose(env):
         cmd = cli(env, SLUG, 'unit', '100', '--verbose')
 
         expect(cmd.returncode) == 0
-        expect(cmd.stderr) == ""
+        expect(cmd.stderr) != ""  # expect lots of logging
         expect(cmd.stdout).contains("coverage increased")