Fixed spurious, intermittent test failures related to command execution and logging.

borgmatic/execute.py

@@ -69,6 +69,7 @@ def log_outputs(processes, exclude_stdouts, output_log_level, borg_local_path):
     }
     output_buffers = list(process_for_output_buffer.keys())
     captured_outputs = collections.defaultdict(list)
+    still_running = True
 
     # Log output for each process until they all exit.
     while True:
@@ -108,6 +109,9 @@ def log_outputs(processes, exclude_stdouts, output_log_level, borg_local_path):
                     else:
                         logger.log(output_log_level, line)
 
+        if not still_running:
+            break
+
         still_running = False
 
         for process in processes:
@@ -137,9 +141,6 @@ def log_outputs(processes, exclude_stdouts, output_log_level, borg_local_path):
                     exit_code, command_for_process(process), '\n'.join(last_lines)
                 )
 
-        if not still_running:
-            break
-
     if captured_outputs:
         return {
             process: '\n'.join(output_lines) for process, output_lines in captured_outputs.items()

tests/integration/test_execute.py

@@ -278,7 +278,7 @@ def test_log_outputs_with_unfinished_process_re_polls():
     flexmock(module).should_receive('exit_code_indicates_error').and_return(False)
 
     process = subprocess.Popen(['true'], stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
-    flexmock(process).should_receive('poll').and_return(None).and_return(0).twice()
+    flexmock(process).should_receive('poll').and_return(None).and_return(0).times(3)
     flexmock(module).should_receive('output_buffer_for_process').and_return(process.stdout)
 
     module.log_outputs(