reduce redundant output when capturing late logs

it's unclear if late logs ever captures logs not already echoed,
but this at least eliminates the redundant output

Author: minrk

repo2docker/app.py

@@ -16,10 +16,10 @@
 import shutil
 import tempfile
 import time
-
-from .engine import BuildError, ContainerEngineException, ImageLoadError
 from urllib.parse import urlparse
+
 import escapism
+from iso8601 import parse_date
 from pythonjsonlogger import jsonlogger
 
 from traitlets import Any, Dict, Int, List, Unicode, Bool, default
@@ -38,6 +38,7 @@
     RBuildPack,
 )
 from . import contentproviders
+from .engine import BuildError, ContainerEngineException, ImageLoadError
 from .utils import ByteSpecification, chdir
 
 
@@ -629,9 +630,12 @@ def wait_for_container(self, container):
         Displaying logs while it's running
         """
 
+        last_timestamp = None
         try:
-            for line in container.logs(stream=True):
-                self.log.info(line.decode("utf-8"), extra=dict(phase="running"))
+            for line in container.logs(stream=True, timestamps=True):
+                line = line.decode("utf-8")
+                last_timestamp, line = line.split(" ", maxsplit=1)
+                self.log.info(line, extra=dict(phase="running"))
 
         finally:
             container.reload()
@@ -646,9 +650,16 @@ def wait_for_container(self, container):
                 "Container finished running.\n".upper(), extra=dict(phase="running")
             )
             # are there more logs? Let's send them back too
-            late_logs = container.logs().decode("utf-8")
+            if last_timestamp:
+                # docker only accepts integer timestamps
+                # this means we will usually replay logs from the last second
+                # of the container
+                # we should check if this ever returns anything new,
+                # since we know it ~always returns something redundant
+                last_timestamp = int(parse_date(last_timestamp).timestamp())
+            late_logs = container.logs(since=last_timestamp).decode("utf-8")
             for line in late_logs.split("\n"):
-                self.log.info(line + "\n", extra=dict(phase="running"))
+                self.log.debug(line + "\n", extra=dict(phase="running"))
 
             container.remove()
             if exit_code:

setup.py

@@ -50,6 +50,7 @@ def get_identifier(json):
         "docker",
         "entrypoints",
         "escapism",
+        "iso8601",
         "jinja2",
         "python-json-logger",
         "requests",