better logging

pelican_deploy/deploy.py

@@ -1,6 +1,7 @@
 from pathlib import Path
 from collections import namedtuple
-from pelican_deploy.gittool import Repo
+from pelican_deploy.gittool import Repo, log_git_result
+from functools import partial
 from subprocess import Popen, PIPE
 from concurrent.futures import ThreadPoolExecutor
 from threading import RLock
@@ -12,6 +13,9 @@ import atexit
 
 log = logging.getLogger(__name__)
 
+log_git = partial(log_git_result, out_logger=log.debug,
+                  err_logger=log.debug, status_logger=log.debug)
+
 BUILD_REPO_DIR = "{name}_build_repo"
 OUTPUT_DIR = "{name}_output"
 
@@ -60,6 +64,8 @@ class DeploymentRunner:
                 log.info("Build repository %s not there, cloneing", e)
                 result = repo.clone("--branch", "self.git_branch",
                                     "--depth", "1", self.clone_url, ".")
+                log_git(result)
+
 
         origin_url = repo.config_get("remote.origin.url")
         if origin_url != self.clone_url:
@@ -69,23 +75,29 @@ class DeploymentRunner:
 
         # deinit submodules to avoid removed ones dangling around later
         # they should stay around in .git, so reinit should be fast
-        repo.submodule("deinit", ".")
+        result = repo.submodule("deinit", ".")
+        log_git(result)
 
         log.info("%s build_repo: reset it hard!", self.name)
-        repo.reset("--hard")
+        result = repo.reset("--hard")
+        log_git(result)
 
         log.info("%s build_repo: pulling changes from origin", self.name)
         refspec = "+{b}:{b}".format(b=self.git_branch)
-        repo.pull("--force", "--no-edit", "--recurse-submodules", "--depth",
-                  "1", "origin", refspec)
+        result = repo.pull("--force", "--no-edit", "--recurse-submodules",
+                           "--depth", "1", "origin", refspec)
+        log_git(result)
+
         try:
-            repo.clean("--force", "-d", "-x")
+            result = repo.clean("--force", "-d", "-x")
+            log_git(result)
         except:
             log.warning("git clean failed!", exc_info=True)
 
         # update the submodules
         log.info("%s build_repo: update submodules", self.name)
-        repo.submodule("update", "--init", "--force", "--recursive")
+        result = repo.submodule("update", "--init", "--force", "--recursive")
+        log_git(result)
 
     def build(self, abort_running=False):
         with self._build_lock:

pelican_deploy/gittool.py

@@ -3,7 +3,7 @@ import shlex
 from collections import namedtuple
 from subprocess import Popen, PIPE
 
-CmdResult = namedtuple("CmdResult", "status stdout stderr")
+CmdResult = namedtuple("CmdResult", "cmd status stdout stderr")
 
 class GitCommandError(Exception):
     def __init__(self, message, result, *args, **kwargs):
@@ -30,10 +30,10 @@ class Repo:
         proc = self.popen_cmd(*args, env=env)
         outs, errs = proc.communicate(timeout=timeout)
         status = proc.wait()
-        res = CmdResult(status, outs, errs)
+        res = CmdResult(args,status, outs, errs)
         if status != 0 and errors_raise:
             raise GitCommandError("git failed: {}".format(args), res)
-        return CmdResult(status, outs, errs)
+        return res
 
     def popen_cmd(self, *args, env=None, universal_newlines=True):
         return Popen(args, stdout=PIPE, stderr=PIPE, cwd=self.repo_dir, env=env,
@@ -50,3 +50,13 @@ class Repo:
         res = self.config("--get", key)
         return res.stdout.rstrip("\r\n")
 
+def log_git_result(result, out_logger=None, err_logger=None, status_logger=None):
+    if status_logger:
+        err_logger('%s exit status: %s', result.cmd, result.status)
+    if out_logger:
+        out_logger('git stdout:\n%s', result.stdout)
+    if err_logger:
+        err_logger('git stderr:\n%s', result.stderr)
+
+
+