Container build times and quiet header/body output on PASS (#3649)

toolset/benchmark/benchmarker.py

@@ -76,7 +76,7 @@ class Benchmarker:
 
     def stop(self, signal=None, frame=None):
         log("Shutting down (may take a moment)")
-        self.docker_helper.stop(kill=True)
+        self.docker_helper.stop()
         sys.exit(0)
 
     ##########################################################################################

toolset/benchmark/framework_test.py

@@ -163,8 +163,10 @@ class FrameworkTest:
                 [output_result(r1, r2, url) for (r1, r2, url) in results]
 
                 if test.failed:
+                    test.output_headers_and_body()
                     self.benchmarker.results.report_verify_results(self, test_type, 'fail')
                 elif test.warned:
+                    test.output_headers_and_body()
                     self.benchmarker.results.report_verify_results(self, test_type, 'warn')
                 elif test.passed:
                     self.benchmarker.results.report_verify_results(self, test_type, 'pass')

toolset/benchmark/test_types/framework_test_type.py

@@ -32,6 +32,8 @@ class FrameworkTestType:
         self.name = name
         self.requires_db = requires_db
         self.args = args
+        self.headers = ""
+        self.body = ""
 
         if accept_header is None:
             self.accept_header = self.accept('json')
@@ -77,11 +79,13 @@ class FrameworkTestType:
         headers = {'Accept': self.accept_header}
         r = requests.get(url, timeout=15, headers=headers)
 
-        headers = r.headers
-        body = r.content
-        log(str(headers))
-        log(body)
-        return headers, body
+        self.headers = r.headers
+        self.body = r.content
+        return self.headers, self.body
+
+    def output_headers_and_body(self):
+        log(str(self.headers))
+        log(self.body)
 
     def verify(self, base_url):
         '''

toolset/utils/docker_helper.py

@@ -208,25 +208,22 @@ class DockerHelper:
         return container
 
     @staticmethod
-    def __stop_container(container, kill):
+    def __stop_container(container):
         try:
-            if kill:
-                container.kill()
-            else:
-                container.stop()
+            container.kill()
         except:
-            # container has already been stopped/killed
+            # container has already been killed
             pass
 
     @staticmethod
-    def __stop_all(docker_client, kill):
+    def __stop_all(docker_client):
         for container in docker_client.containers.list():
             if len(container.image.tags) > 0 \
                     and 'techempower' in container.image.tags[0] \
                     and 'tfb:latest' not in container.image.tags[0]:
-                DockerHelper.__stop_container(container, kill)
+                DockerHelper.__stop_container(container)
 
-    def stop(self, containers=None, kill=False):
+    def stop(self, containers=None):
         '''
         Attempts to stop a container or list of containers.
         If no containers are passed, stops all running containers.
@@ -238,11 +235,11 @@ class DockerHelper:
             if not isinstance(containers, list):
                 containers = [containers]
             for container in containers:
-                DockerHelper.__stop_container(container, kill)
+                DockerHelper.__stop_container(container)
         else:
-            self.__stop_all(self.server, kill)
+            self.__stop_all(self.server)
             if is_multi_setup:
-                self.__stop_all(self.database, kill)
+                self.__stop_all(self.database)
 
         self.database.containers.prune()
         if is_multi_setup:

toolset/utils/time_logger.py

@@ -20,6 +20,7 @@ class TimeLogger:
         self.test_total = 0
         self.verify_start = 0
         self.verify_total = 0
+        self.build_logs = []
 
     @staticmethod
     def output(sec):
@@ -51,11 +52,21 @@ class TimeLogger:
     def log_build_end(self, log_prefix, file):
         total = int(time.time() - self.build_start)
         self.build_total = self.build_total + total
-        log("Total build time: %s" % TimeLogger.output(total),
+        log_str = "Total build time: %s" % TimeLogger.output(total)
+        self.build_logs.append({'log_prefix': log_prefix, 'str': log_str})
+        log(log_str,
             prefix=log_prefix,
             file=file,
             color=Fore.YELLOW)
 
+    def log_build_flush(self, file):
+        for b_log in self.build_logs:
+            log(b_log['str'],
+                prefix=b_log['log_prefix'],
+                file=file,
+                color=Fore.YELLOW)
+        self.build_logs = []
+
     def log_test_start(self):
         self.test_start = time.time()
 
@@ -92,6 +103,7 @@ class TimeLogger:
         self.verify_start = time.time()
 
     def log_verify_end(self, log_prefix, file):
+        self.log_build_flush(file)
         total = int(time.time() - self.verify_start)
         self.verify_total = self.verify_total + total
         log("Total verify time: %s" % TimeLogger.output(total),