Quieter init script

Piped output of subprocess commands to log.

Set default log level to INFO.

Change-Id: I583af3f6812195a9061a76b611714aced7c8861f

tests/basic-test.sh

@@ -16,7 +16,7 @@
 ##############################################################################
 
 # Configuration and checks
-set -ex
+set -e
 
 export PATH=/snap/bin:$PATH
 

tools/init/init/config.py

@@ -21,7 +21,16 @@ limitations under the License.
 """
 import logging
 import os
-import sys
+
+
+# Setup logging
+log = logging.getLogger("microstack_init")
+log.setLevel(logging.INFO)
+stream = logging.StreamHandler()
+formatter = logging.Formatter(
+    '%(asctime)s - %(name)s - %(levelname)s - %(message)s')
+stream.setFormatter(formatter)
+log.addHandler(stream)
 
 
 class Env():
@@ -40,13 +49,3 @@ class Env():
     def get_env(self):
         """Get a mapping friendly dict."""
         return self.__dict__
-
-
-logging.basicConfig(
-    # filename='{SNAP_COMMON}/log/microstack_init.log'.format(**Env),
-    stream=sys.stdout,
-    level=logging.DEBUG
-)
-
-
-log = logging  # noqa

tools/init/init/shell.py

@@ -30,12 +30,28 @@ from typing import Dict, List
 import pymysql
 import wget
 
-from init.config import Env
+from init.config import Env, log
 
 
 _env = Env().get_env()
 
 
+def _popen(*args: List[str], env: Dict = _env):
+    """Run a shell command, piping STDOUT and STDERR to our logger.
+
+    :param args: strings to be composed into the bash call.
+    :param env: defaults to our Env singleton; can be overriden.
+
+    """
+    proc = subprocess.Popen(args, env=env, stdout=subprocess.PIPE,
+                            stderr=subprocess.STDOUT, bufsize=1,
+                            universal_newlines=True)
+    for line in iter(proc.stdout.readline, ''):
+        log.debug(line)
+    proc.wait()
+    return proc
+
+
 def check(*args: List[str], env: Dict = _env) -> int:
     """Execute a shell command, raising an error on failed excution.
 
@@ -43,7 +59,13 @@ def check(*args: List[str], env: Dict = _env) -> int:
     :param env: defaults to our Env singleton; can be overriden.
 
     """
-    return subprocess.check_call(args, env=env)
+    proc = _popen(*args, env=env)
+    if proc.returncode:
+        raise subprocess.CalledProcessError(
+            "Command '{}' returned non-zero exit status {}".format(
+                " ".join(args),
+                proc.returncode))
+    return proc.returncode
 
 
 def check_output(*args: List[str], env: Dict = _env) -> str:
@@ -67,7 +89,8 @@ def call(*args: List[str], env: Dict = _env) -> bool:
     :param args: strings to be composed into the bash call.
     :param env: defaults to our Env singleton; can be overriden.
     """
-    return not subprocess.call(args, env=env)
+    proc = _popen(*args, env=env)
+    return not proc.returncode
 
 
 def shell(cmd: str, env: Dict = _env) -> int:
@@ -82,8 +105,19 @@ def shell(cmd: str, env: Dict = _env) -> int:
     :param env: defaults to our Env singleton; can be overriden.
 
     """
-    return subprocess.check_call(cmd, shell=True, env=env,
+    proc = subprocess.Popen(cmd, env=env, stdout=subprocess.PIPE,
+                            stderr=subprocess.STDOUT, bufsize=1,
+                            universal_newlines=True, shell=True,
                             executable='/snap/core18/current/bin/bash')
+    for line in iter(proc.stdout.readline, ''):
+        log.debug(line)
+    proc.wait()
+    if proc.returncode:
+        raise subprocess.CalledProcessError(
+            "Command '{}' returned non-zero exit status {}".format(
+                cmd,
+                proc.returncode))
+    return proc.returncode
 
 
 def sql(cmd: str) -> None: