Log the outputs of run_scancode as progress indication #300 (#305)

* Log the outputs of `run_scancode` as progress indication #300

Signed-off-by: Thomas Druez <tdruez@nexb.com>

* Add changelog entry #300

Signed-off-by: Thomas Druez <tdruez@nexb.com>

CHANGELOG.rst

@@ -1,6 +1,11 @@
 // Release notes
 // -------------
 
+### Unreleased
+
+- Log the outputs of run_scancode as progress indication.
+  https://github.com/nexB/scancode.io/issues/300
+
 ### v21.8.2
 
 - Upgrade ScanCode-toolkit to version 21.7.30

scanpipe/pipes/__init__.py

@@ -20,10 +20,12 @@
 # ScanCode.io is a free software code scanning tool from nexB Inc. and others.
 # Visit https://github.com/nexB/scancode.io for support and download.
 
+import logging
 import subprocess
 import sys
 from datetime import datetime
 from pathlib import Path
+from time import sleep
 
 from django.db.models import Count
 
@@ -33,6 +35,8 @@
 from scanpipe.models import DiscoveredPackage
 from scanpipe.pipes import scancode
 
+logger = logging.getLogger("scanpipe.pipes")
+
 
 def make_codebase_resource(project, location, rootfs_path=None):
     """
@@ -189,16 +193,44 @@ def get_bin_executable(filename):
     return str(Path(sys.executable).parent / filename)
 
 
-def run_command(cmd):
+def _stream_process(process, stream_to=logger.info):
+    exitcode = process.poll()
+
+    for line in process.stdout:
+        stream_to(line.rstrip("\n"))
+
+    has_terminated = exitcode is not None
+    return has_terminated
+
+
+def run_command(cmd, log_output=False):
     """
     Returns (exitcode, output) of executing the provided `cmd` in a shell.
     `cmd` can be provided as a string or as a list of arguments.
+
+    If `log_output` is True, the stdout and stderr of the process will be captured
+    and streamed to the `logger`.
     """
     if isinstance(cmd, list):
         cmd = " ".join(cmd)
 
-    exitcode, output = subprocess.getstatusoutput(cmd)
-    return exitcode, output
+    if not log_output:
+        exitcode, output = subprocess.getstatusoutput(cmd)
+        return exitcode, output
+
+    process = subprocess.Popen(
+        cmd,
+        shell=True,
+        stdout=subprocess.PIPE,
+        stderr=subprocess.STDOUT,
+        universal_newlines=True,
+    )
+
+    while _stream_process(process):
+        sleep(1)
+
+    exitcode = process.poll()
+    return exitcode, ""
 
 
 def remove_prefix(text, prefix):

scanpipe/pipes/scancode.py

@@ -314,10 +314,11 @@ def run_scancode(location, output_file, options, raise_on_error=False):
         shlex.quote(location),
         *default_options,
         *options,
+        "--verbose",
         f"--json-pp {shlex.quote(output_file)}",
     ]
 
-    exitcode, output = pipes.run_command(scancode_args)
+    exitcode, output = pipes.run_command(scancode_args, log_output=True)
     if exitcode > 0 and raise_on_error:
         raise ScancodeError(output)
 

scanpipe/tests/test_pipelines.py

@@ -202,6 +202,7 @@ class ScanPackagePipelineTest(TestCase):
         "tool_version",
         "--json-pp",
         "--processes",
+        "--verbose",
     ]
 
     def _without_keys(self, data, exclude_keys):

scanpipe/tests/test_pipes.py

@@ -506,7 +506,7 @@ def test_scanpipe_pipes_scancode_run_scancode(self):
             options=["--info"],
         )
         self.assertEqual(0, exitcode)
-        self.assertIn("Scanning done.", output)
+        self.assertEqual("", output)
 
     def test_scanpipe_pipes_scancode_make_results_summary(self):
         project = Project.objects.create(name="Analysis")