From 2d8ebc68390dd69f89de8570bb65f91926b4cf2d Mon Sep 17 00:00:00 2001
From: Julian Oes <julian@oes.ch>
Date: Wed, 22 Dec 2021 14:40:24 +0100
Subject: [PATCH] mavsdk_tests: add timestamp to log output

The timestamp is added when the output is queued up, rather than later
when the queue is emptied and some time might have passed.
---
 test/mavsdk_tests/mavsdk_test_runner.py | 7 -------
 test/mavsdk_tests/process_helper.py     | 8 ++++++++
 2 files changed, 8 insertions(+), 7 deletions(-)

diff --git a/test/mavsdk_tests/mavsdk_test_runner.py b/test/mavsdk_tests/mavsdk_test_runner.py
index 09655dcd8d..0054bd702c 100755
--- a/test/mavsdk_tests/mavsdk_test_runner.py
+++ b/test/mavsdk_tests/mavsdk_test_runner.py
@@ -486,15 +486,12 @@ class Tester:
             runner.stop()
 
     def collect_runner_output(self) -> None:
-        max_name = max(len(runner.name) for runner in self.active_runners)
-
         for runner in self.active_runners:
             while True:
                 line = runner.get_output_line()
                 if not line:
                     break
 
-                line = self.add_name_prefix(max_name, runner.name, line)
                 self.add_to_combined_log(line)
                 if self.verbose:
                     print(line, end="")
@@ -572,10 +569,6 @@ class Tester:
         with open(filename, 'r') as f:
             return f.read()
 
-    @staticmethod
-    def add_name_prefix(width: int, name: str, text: str) -> str:
-        return colorize("[" + name.ljust(width) + "] " + text, color.RESET)
-
     @staticmethod
     def determine_logfile_path(log_dir: str, desc: str) -> str:
         return os.path.join(log_dir, "log-{}.log".format(desc))
diff --git a/test/mavsdk_tests/process_helper.py b/test/mavsdk_tests/process_helper.py
index 097f20c9fc..37dfaffcee 100644
--- a/test/mavsdk_tests/process_helper.py
+++ b/test/mavsdk_tests/process_helper.py
@@ -74,10 +74,18 @@ class Runner:
                 break
             if not line or line == "\n":
                 continue
+            line = self.add_prefix(10, self.name, line)
             self.output_queue.put(line)
             self.log_fd.write(line)
             self.log_fd.flush()
 
+    def add_prefix(self, width: int, name: str, text: str) -> str:
+        return "[" + self.seconds() + "|" + name.ljust(width) + "] " + text
+
+    def seconds(self) -> str:
+        dt = time.time() - self.start_time
+        return "{: 8.03f}".format(dt)
+
     def poll(self) -> Optional[int]:
         return self.process.poll()