Repository: jboss-dockerfiles/dogen

Issue:
Add colored logging output
To make it easier to see important messages (especially when verbose output is turned on) - we should add color to log messages.

Discussion:

Patch:
diff --git a/dogen/cli.py b/dogen/cli.py
index 6540695..c70984c 100644
--- a/dogen/cli.py
+++ b/dogen/cli.py
@@ -14,6 +14,7 @@ from dogen.version import version
 from dogen.errors import Error
 from dogen.plugin import Plugin
 
+import colorlog
 
 class MyParser(argparse.ArgumentParser):
 
@@ -25,14 +26,15 @@ class MyParser(argparse.ArgumentParser):
 class CLI(object):
 
     def __init__(self):
-        self.log = logging.getLogger("dogen")
+        formatter = colorlog.ColoredFormatter(
+            '%(log_color)s%(asctime)s %(name)-12s %(levelname)-8s %(message)s')
         handler = logging.StreamHandler()
-        formatter = logging.Formatter(
-            '%(asctime)s %(name)-12s %(levelname)-8s %(message)s')
         handler.setFormatter(formatter)
+
+        self.log = logging.getLogger("dogen")
         self.log.addHandler(handler)
 
-        for package in ["requests.packages.urllib3", "pykwalify.core", "pykwalify.rule"]:
+        for package in ["requests.packages.urllib3", "pykwalify.rule"]:
             log = logging.getLogger(package)
             log.setLevel(logging.INFO)
 
@@ -86,7 +88,10 @@ class CLI(object):
         except KeyboardInterrupt as e:
             pass
         except Error as e:
-            self.log.exception(e)
+            if args.verbose:
+                self.log.exception(e)
+            else:
+                self.log.error(str(e))
             sys.exit(1)
 
     def get_plugins(self):
diff --git a/dogen/generator.py b/dogen/generator.py
index 335db99..0562cd8 100644
--- a/dogen/generator.py
+++ b/dogen/generator.py
@@ -48,12 +48,12 @@ class Generator(object):
         self.ssl_verify to False.
         """
 
-        self.log.info("Fetching '%s' file..." % location)
+        self.log.debug("Fetching '%s' file..." % location)
 
         if not output:
             output = tempfile.mktemp("-dogen")
 
-        self.log.info("Fetched file will be saved as '%s'..." % os.path.basename(output))
+        self.log.debug("Fetched file will be saved as '%s'..." % os.path.basename(output))
 
         r = requests.get(location, verify=self.ssl_verify, stream=True)
 
@@ -261,8 +261,12 @@ class Generator(object):
         if 'sources' not in self.cfg or self.without_sources:
             return []
 
+        self.log.info("Handling artifacts...")
         self.cfg['artifacts'] = {}
 
+        sources_cache = os.environ.get("DOGEN_SOURCES_CACHE")
+        self.log.debug("Source cache will be used for all artifacts")
+
         for source in self.cfg['sources']:
             url = source.get('url')
             artifact = source.get('artifact')
@@ -279,6 +283,8 @@ class Generator(object):
             if not artifact:
                 raise Error("Artifact location for one or more sources was not provided, please check your image descriptor!")
 
+            self.log.info("Handling artifact '%s'" % artifact)
+
             basename = os.path.basename(artifact)
             target = source.get('target')
 
@@ -312,24 +318,28 @@ class Generator(object):
                         self.check_sum(filename, source[algorithm], algorithm)
                     passed = True
             except Exception as e:
-                self.log.warn(str(e))
+                self.log.debug(str(e))
+                self.log.warn("Local file doesn't match provided checksum, artifact '%s' will be downloaded again" % artifact)
                 passed = False
 
             if not passed:
-                sources_cache = os.environ.get("DOGEN_SOURCES_CACHE")
 
                 if sources_cache:
-                    artifact = sources_cache.replace('#filename#', basename)
+                    cached_artifact = sources_cache.replace('#filename#', basename)
 
                     if algorithms:
                         if len(algorithms) > 1:
                             self.log.warn("You specified multiple algorithms for '%s' artifact, but only '%s' will be used to fetch it from cache" % (artifact, algorithms[0]))
 
-                        artifact = artifact.replace('#hash#', source[algorithms[0]]).replace('#algorithm#', algorithms[0])
-
-                    self.log.info("Using '%s' as cached location for artifact" % artifact)
+                        cached_artifact = cached_artifact.replace('#hash#', source[algorithms[0]]).replace('#algorithm#', algorithms[0])
 
-                self._fetch_file(artifact, filename)
+                    try:
+                        self._fetch_file(cached_artifact, filename)
+                    except Exception as e:
+                        self.log.warn("Could not download artifact from cached location: '%s': %s. Please make sure you set the correct value for DOGEN_SOURCES_CACHE (currently: '%s')." % (cached_artifact, str(e), sources_cache))
+                        self._download_source(artifact, filename, source.get('hint'))
+                else:
+                    self._download_source(artifact, filename, source.get('hint'))
 
                 if algorithms:
                     for algorithm in algorithms:
@@ -338,10 +348,24 @@ class Generator(object):
             if algorithms:
                 self.cfg['artifacts'][target] = "%s:%s" % (algorithms[0], source[algorithms[0]])
             else:
+                self.log.warn("No checksum was specified for artifact '%s'!" % artifact)
                 self.cfg['artifacts'][target] = None
 
+    def _download_source(self, artifact, filename, hint=None):
+        if Tools.is_url(artifact):
+            self.log.warn("Trying to download the '%s' artifact from original location" % artifact)
+            try:
+                self._fetch_file(artifact, filename)
+            except Exception as e:
+                raise Error("Could not download artifact from orignal location, reason: %s" % str(e))
+        else:
+            if hint:
+                self.log.info(hint)
+                self.log.info("Please download the '%s' artifact manually and save it as '%s'" % (artifact, filename))
+            raise Error("Artifact '%s' could not be fetched!" % artifact)
+
     def check_sum(self, filename, checksum, algorithm):
-        self.log.info("Checking '%s' %s hash..." % (os.path.basename(filename), algorithm))
+        self.log.debug("Checking '%s' %s hash..." % (os.path.basename(filename), algorithm))
 
         hash = getattr(hashlib, algorithm)()
 
diff --git a/dogen/schema/kwalify_schema.yaml b/dogen/schema/kwalify_schema.yaml
index 05069f3..82c400d 100644
--- a/dogen/schema/kwalify_schema.yaml
+++ b/dogen/schema/kwalify_schema.yaml
@@ -64,6 +64,7 @@ map:
           sha1: {type: str}
           sha256: {type: str}
           target: {type: str}
+          hint: {type: str}
   packages:
     seq:
       - {type: str}
diff --git a/requirements.txt b/requirements.txt
index f7e4f1f..43c4660 100644
--- a/requirements.txt
+++ b/requirements.txt
@@ -3,3 +3,4 @@ Jinja2>=2.8
 requests>=2.8.1
 six>=1.10.0
 pykwalify>=1.5.1
+colorlog>=2.10.0


Test patch:
diff --git a/tests/test_unit_generate_handle_files.py b/tests/test_unit_generate_handle_files.py
index eb85ab9..daf240a 100644
--- a/tests/test_unit_generate_handle_files.py
+++ b/tests/test_unit_generate_handle_files.py
@@ -1,6 +1,7 @@
 import argparse
 import unittest
 import mock
+import os
 import six
 
 from dogen.generator import Generator
@@ -45,8 +46,8 @@ class TestFetchFile(unittest.TestCase):
             mock_requests.assert_called_with('https://host/file.tmp', verify=None, stream=True)
             mock_file().write.assert_called_once_with("file-content")
 
-        self.log.info.assert_any_call("Fetching 'https://host/file.tmp' file...")
-        self.log.info.assert_any_call("Fetched file will be saved as 'some-file'...")
+        self.log.debug.assert_any_call("Fetching 'https://host/file.tmp' file...")
+        self.log.debug.assert_any_call("Fetched file will be saved as 'some-file'...")
 
 
     @mock.patch('dogen.generator.tempfile.mktemp', return_value="tmpfile")
@@ -64,8 +65,8 @@ class TestFetchFile(unittest.TestCase):
             mock_requests.assert_called_with('https://host/file.tmp', verify=None, stream=True)
             mock_file().write.assert_called_once_with("file-content")
 
-        self.log.info.assert_any_call("Fetching 'https://host/file.tmp' file...")
-        self.log.info.assert_any_call("Fetched file will be saved as 'tmpfile'...")
+        self.log.debug.assert_any_call("Fetching 'https://host/file.tmp' file...")
+        self.log.debug.assert_any_call("Fetched file will be saved as 'tmpfile'...")
 
 class TestCustomTemplateHandling(unittest.TestCase):
     def setUp(self):
@@ -113,3 +114,76 @@ class TestCustomTemplateHandling(unittest.TestCase):
 
         fetch_file_mock.assert_called_with("http://host/custom-template")
         self.assertEqual(self.generator.template, "some-tmp-file")
+
+class TestHandleSources(unittest.TestCase):
+    def setUp(self):
+        self.log = mock.Mock()
+        args = argparse.Namespace(path="image.yaml", output="target", without_sources=None,
+                                  template="http://host/custom-template", scripts_path=None,
+                                  additional_script=None, skip_ssl_verification=None)
+        self.generator = Generator(self.log, args)
+
+    def test_fetch_artifact_without_url_should_fail(self):
+        self.generator.cfg = {'sources': [{'artifact': 'jboss-eap.zip'}]}
+
+        with self.assertRaises(Error) as cm:
+            self.generator.handle_sources()
+
+        self.assertEquals(str(cm.exception), "Artifact 'jboss-eap.zip' could not be fetched!")
+
+    @mock.patch('dogen.generator.Generator._fetch_file', side_effect=Error("Blah"))
+    def test_fetch_artifact_should_fail_when_fetching_fails(self, mock_fetch_file):
+        self.generator.cfg = {'sources': [{'artifact': 'http://jboss-eap.zip'}]}
+
+        with self.assertRaises(Error) as cm:
+            self.generator.handle_sources()
+
+        self.assertEquals(str(cm.exception), "Could not download artifact from orignal location, reason: Blah")
+
+    @mock.patch('dogen.generator.Generator._fetch_file', side_effect=[Error("cached"), Error("original")])
+    def test_fetch_artifact_should_fail_when_cached_download_failed_and_original_failed_too(self, mock_fetch_file):
+        self.generator.cfg = {'sources': [{'artifact': 'http://host.com/jboss-eap.zip'}]}
+
+        k = mock.patch.dict(os.environ, {'DOGEN_SOURCES_CACHE':'http://cache/get?#algorithm#=#hash#'})
+        k.start()
+
+        with self.assertRaises(Error) as cm:
+            self.generator.handle_sources()
+
+        k.stop()
+
+        self.assertEquals(str(cm.exception), "Could not download artifact from orignal location, reason: original")
+        mock_fetch_file.assert_has_calls([mock.call('http://cache/get?#algorithm#=#hash#', 'target/jboss-eap.zip'), mock.call('http://host.com/jboss-eap.zip', 'target/jboss-eap.zip')])
+
+    @mock.patch('dogen.generator.Generator._fetch_file')
+    def test_fetch_artifact_should_fetch_file_from_cache(self, mock_fetch_file):
+        self.generator.cfg = {'sources': [{'artifact': 'http://host.com/jboss-eap.zip'}]}
+
+        k = mock.patch.dict(os.environ, {'DOGEN_SOURCES_CACHE':'http://cache/get?#filename#'})
+        k.start()
+        self.generator.handle_sources()
+        k.stop()
+
+        # No checksum provided and computed
+        self.assertEquals(self.generator.cfg['artifacts'], {'jboss-eap.zip': None})
+        mock_fetch_file.assert_called_with('http://cache/get?jboss-eap.zip', 'target/jboss-eap.zip')
+
+    @mock.patch('dogen.generator.Generator._fetch_file')
+    def test_fetch_artifact_should_fetch_file(self, mock_fetch_file):
+        self.generator.cfg = {'sources': [{'artifact': 'http://host.com/jboss-eap.zip'}]}
+        self.generator.handle_sources()
+        # No checksum provided and computed
+        self.assertEquals(self.generator.cfg['artifacts'], {'jboss-eap.zip': None})
+        mock_fetch_file.assert_called_with('http://host.com/jboss-eap.zip', 'target/jboss-eap.zip')
+
+    @mock.patch('dogen.generator.Generator._fetch_file', side_effect=[Error("cached"), None])
+    def test_fetch_artifact_should_download_from_original_location_if_cached_location_failed(self, mock_fetch_file):
+        self.generator.cfg = {'sources': [{'artifact': 'http://host.com/jboss-eap.zip'}]}
+
+        k = mock.patch.dict(os.environ, {'DOGEN_SOURCES_CACHE':'http://cache/get?#algorithm#=#hash#'})
+        k.start()
+        self.generator.handle_sources()
+        k.stop()
+
+        self.assertEquals(self.generator.cfg['artifacts'], {'jboss-eap.zip': None})
+        mock_fetch_file.assert_has_calls([mock.call('http://cache/get?#algorithm#=#hash#', 'target/jboss-eap.zip'), mock.call('http://host.com/jboss-eap.zip', 'target/jboss-eap.zip')])