runcmd.py: show live subprocess output when verbose

When executed with `--verbose`, send stdout and stderr data from
subprocesses to `sys.stdout` and `sys.stderr` as it is generated to
provide better feedback for long-running processes like ansible which
produce a lot of output

1 files changed, 42 insertions, 7 deletions

diff --git a/vmdb/runcmd.py b/vmdb/runcmd.py
index 116c6cb..d3161a7 100644
--- a/vmdb/runcmd.py
+++ b/vmdb/runcmd.py
@@ -15,13 +15,13 @@
 #
 # =*= License: GPL-3+ =*=
 
-
+import io
 import logging
 import os
+import selectors
 import subprocess
 import sys
 
-
 _verbose = False
 
 
@@ -43,8 +43,18 @@ def progress(msg):
         sys.stdout.flush()
 
 
+def _log_line(line, stream_out, stream_label):
+    if line:
+        line = line.decode("UTF8")
+        if _verbose:
+            stream_out.write(line)
+            stream_out.flush()
+        logging.debug("%s: %s", stream_label, line)
+    return bool(line)
+
+
 def runcmd(argv, **kwargs):
-    progress("Exec: %r" % (argv,))
+    progress("Exec: %r" % (argv, ))
     env = kwargs.get("env", os.environ.copy())
     env["LC_ALL"] = "C.UTF8"
     kwargs["env"] = env
@@ -52,13 +62,38 @@ def runcmd(argv, **kwargs):
     kwargs["stderr"] = kwargs.get("stderr", subprocess.PIPE)
     for name in env:
         logging.debug(f"ENV: {name}={env[name]}")
+
+    stdout_buffer = io.BytesIO()
+
+    def _log_stdout(stream_in):
+        line = stream_in.readline()
+        stdout_buffer.write(line)
+        return _log_line(line, sys.stdout, "STDOUT")
+
+    def _log_stderr(stream_in):
+        line = stream_in.readline()
+        return _log_line(line, sys.stderr, "STDERR")
+
+    selector = selectors.DefaultSelector()
     p = subprocess.Popen(argv, **kwargs)
-    out, err = p.communicate()
-    logging.debug("STDOUT: %s", out.decode("UTF8"))
-    logging.debug("STDERR: %s", err.decode("UTF8"))
+    selector.register(p.stdout, selectors.EVENT_READ, _log_stdout)
+    selector.register(p.stderr, selectors.EVENT_READ, _log_stderr)
+
+    while p.poll() is None:
+        events = selector.select()
+        for key, _ in events:
+            callback = key.data
+            callback(key.fileobj)
+    p.wait()
+    selector.close()
+
+    # drain stdout and stderr
+    while _log_stdout(p.stdout) or _log_stderr(p.stderr):
+        pass
+
     if p.returncode != 0:
         raise RuncmdError("Program failed: {}".format(p.returncode))
-    return out
+    return stdout_buffer.getvalue()
 
 
 def runcmd_chroot(chroot, argv, *argvs, **kwargs):