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

@@ -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))

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()