fix error logging and except ordering

Author: messa

blockcopy.py

@@ -134,10 +134,10 @@ def main():
 
         logger.debug('Done')
     except CollectedExceptions as exc:
-        logger.error('Failed: %r', args.command, exc)
+        logger.error('Failed: %r', exc)
         sys.exit(f'ERROR ({args.command}): {exc}')
     except Exception as exc:
-        logger.exception('Failed: %r', args.command, exc)
+        logger.exception('Failed: %r', exc)
         sys.exit(f'ERROR ({args.command}): {exc}')
 
 
@@ -250,14 +250,14 @@ def read_worker():
                         # Probably `[Errno 29] Illegal seek` when reading from pipe e.g. from pv command
                         source_end_offset = None
 
+            except Exception as exc:
+                logger.exception('do_checksum read_worker failed: %r', exc)
+                exception_collector.collect_exception(exc)
             except BaseException as exc:
                 # not sure what the exception could be, but let's log it and re-raise it
                 logger.exception('do_checksum read_worker failed (BaseException): %r', exc)
                 exception_collector.collect_exception(exc)
                 raise exc
-            except Exception as exc:
-                logger.exception('do_checksum read_worker failed: %r', exc)
-                exception_collector.collect_exception(exc)
             finally:
                 for _ in range(worker_count):
                     block_queue.put(None)
@@ -320,14 +320,14 @@ def send_worker():
                                 hash_output_stream.write(block_hash)
                     finally:
                         send_queue.task_done()
+            except Exception as exc:
+                logger.exception('do_checksum send_worker failed: %r', exc)
+                exception_collector.collect_exception(exc)
             except BaseException as exc:
                 # not sure what the exception could be, but let's log it and re-raise it
                 logger.exception('do_checksum send_worker failed (BaseException): %r', exc)
                 exception_collector.collect_exception(exc)
                 raise exc
-            except Exception as exc:
-                logger.exception('do_checksum send_worker failed: %r', exc)
-                exception_collector.collect_exception(exc)
 
         futures = [
             executor.submit(read_worker),
@@ -513,14 +513,14 @@ def flush_hash_batch():
                 # Do not trigger the exception collector - it would make other threads terminate.
                 # But do set some flag that the whole workflow is not running successfully.
                 encountered_incomplete_read = exc
+            except Exception as exc:
+                logger.exception('do_retrieve read_worker failed: %r', exc)
+                exception_collector.collect_exception(exc)
             except BaseException as exc:
                 # not sure what the exception could be, but let's log it and re-raise it
                 logger.exception('do_retrieve read_worker failed (BaseException): %r', exc)
                 exception_collector.collect_exception(exc)
                 raise exc
-            except Exception as exc:
-                logger.exception('do_retrieve read_worker failed: %r', exc)
-                exception_collector.collect_exception(exc)
             finally:
                 for _ in range(worker_count):
                     hash_queue.put(None)
@@ -592,14 +592,14 @@ def send_worker():
                             block_output_stream.flush()
                     finally:
                         send_queue.task_done()
+            except Exception as exc:
+                logger.exception('do_retrieve send_worker failed: %r', exc)
+                exception_collector.collect_exception(exc)
             except BaseException as exc:
                 # not sure what the exception could be, but let's log it and re-raise it
                 logger.exception('do_retrieve send_worker failed (BaseException): %r', exc)
                 exception_collector.collect_exception(exc)
                 raise exc
-            except Exception as exc:
-                logger.exception('do_retrieve send_worker failed: %r', exc)
-                exception_collector.collect_exception(exc)
 
         futures = [
             executor.submit(read_worker),

tests/test_copy.py

@@ -55,14 +55,13 @@ def test_copy_tiny_incomplete_hash_stream(tmp_path, script_path):
     dst_path = tmp_path / 'dst_file'
     dst_path.write_bytes(b'-' * len(test_content))
 
-    cmd1 = [executable, script_path, '-v', 'checksum', str(dst_path)]
-    cmd2 = [executable, script_path, '-v', 'retrieve', str(src_path)]
-    cmd3 = [executable, script_path, '-v', 'save', str(dst_path)]
+    cmd1 = [executable, script_path, 'checksum', str(dst_path)]
+    cmd2 = [executable, script_path, 'retrieve', str(src_path)]
+    cmd3 = [executable, script_path, 'save', str(dst_path)]
 
     with ExitStack() as stack:
-        print('Running: ', cmd1)
-        p1 = stack.enter_context(Popen(cmd1, stdin=DEVNULL, stdout=PIPE))
-        p1_output = p1.stdout.read()
+        p1 = stack.enter_context(Popen(cmd1, stdin=DEVNULL, stdout=PIPE, stderr=PIPE))
+        p1_output, _ = p1.communicate(timeout=5)
         assert p1.wait() == 0
         assert p1_output == (
             b'Hash'
@@ -77,14 +76,12 @@ def test_copy_tiny_incomplete_hash_stream(tmp_path, script_path):
         # remove the `done` command
         p1_output = p1_output[:-4]
 
-        print('Running: ', cmd2)
-        p2 = stack.enter_context(Popen(cmd2, stdin=PIPE, stdout=PIPE))
+        p2 = stack.enter_context(Popen(cmd2, stdin=PIPE, stdout=PIPE, stderr=PIPE))
         p2_output, _ = p2.communicate(input=p1_output, timeout=5)
         assert p2.wait() == 1
         assert p2_output == b'data\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x0cHello World!'
 
-        print('Running: ', cmd3)
-        p3 = stack.enter_context(Popen(cmd3, stdin=PIPE, stdout=PIPE))
+        p3 = stack.enter_context(Popen(cmd3, stdin=PIPE, stdout=PIPE, stderr=PIPE))
         p3_output, _ = p3.communicate(input=p2_output, timeout=5)
         assert p3.wait() == 1
         assert p3_output == b''