Run all Borg commands such that they log to syslog as well as console.

borgmatic/borg/check.py

@@ -1,8 +1,7 @@
 import logging
-import os
-import subprocess
 
 from borgmatic.borg import extract
+from borgmatic.execute import execute_command
 from borgmatic.logger import get_logger
 
 DEFAULT_CHECKS = ('repository', 'archives')
@@ -114,11 +113,7 @@ def check_archives(
             + verbosity_flags
         )
 
-        # The check command spews to stdout/stderr even without the verbose flag. Suppress it.
+        execute_command(full_command)
-        stdout = None if verbosity_flags else open(os.devnull, 'w')
-
-        logger.debug(' '.join(full_command))
-        subprocess.check_call(full_command, stdout=stdout, stderr=subprocess.STDOUT)
 
     if 'extract' in checks:
         extract.extract_last_archive_dry_run(repository, lock_wait, local_path, remote_path)

borgmatic/borg/extract.py

@@ -1,7 +1,6 @@
 import logging
-import subprocess
-import sys
 
+from borgmatic.execute import execute_command
 from borgmatic.logger import get_logger
 
 logger = get_logger(__name__)
@@ -27,10 +26,11 @@ def extract_last_archive_dry_run(repository, lock_wait=None, local_path='borg',
         + verbosity_flags
     )
 
-    list_output = subprocess.check_output(full_list_command).decode(sys.stdout.encoding)
+    list_output = execute_command(full_list_command, output_log_level=None)
 
-    last_archive_name = list_output.strip().split('\n')[-1]
+    try:
-    if not last_archive_name:
+        last_archive_name = list_output.strip().splitlines()[-1]
+    except IndexError:
         return
 
     list_flag = ('--list',) if logger.isEnabledFor(logging.DEBUG) else ()
@@ -49,8 +49,7 @@ def extract_last_archive_dry_run(repository, lock_wait=None, local_path='borg',
         + list_flag
     )
 
-    logger.debug(' '.join(full_extract_command))
+    execute_command(full_extract_command)
-    subprocess.check_call(full_extract_command)
 
 
 def extract_archive(
@@ -85,5 +84,4 @@ def extract_archive(
         + (('--progress',) if progress else ())
     )
 
-    logger.debug(' '.join(full_command))
+    execute_command(full_command)
-    subprocess.check_call(full_command)

borgmatic/borg/info.py

@@ -24,4 +24,4 @@ def display_archives_info(
         + (('--json',) if json else ())
     )
 
-    return execute_command(full_command, output_log_level=None if json else logging.INFO)
+    return execute_command(full_command, output_log_level=None if json else logging.WARNING)

borgmatic/borg/init.py

@@ -1,6 +1,7 @@
 import logging
 import subprocess
 
+from borgmatic.execute import execute_command
 from borgmatic.logger import get_logger
 
 logger = get_logger(__name__)
@@ -22,9 +23,13 @@ def initialize_repository(
     info_command = (local_path, 'info', repository)
     logger.debug(' '.join(info_command))
 
-    if subprocess.call(info_command, stdout=subprocess.DEVNULL, stderr=subprocess.DEVNULL) == 0:
+    try:
+        execute_command(info_command, output_log_level=None)
         logger.info('Repository already exists. Skipping initialization.')
         return
+    except subprocess.CalledProcessError as error:
+        if error.returncode != 2:
+            raise
 
     init_command = (
         (local_path, 'init', repository)
@@ -36,5 +41,5 @@ def initialize_repository(
         + (('--remote-path', remote_path) if remote_path else ())
     )
 
-    logger.debug(' '.join(init_command))
+    # Don't use execute_command() here because it doesn't support interactive prompts.
     subprocess.check_call(init_command)

borgmatic/borg/list.py

@@ -25,4 +25,4 @@ def list_archives(
         + (('--json',) if json else ())
     )
 
-    return execute_command(full_command, output_log_level=None if json else logging.INFO)
+    return execute_command(full_command, output_log_level=None if json else logging.WARNING)

borgmatic/borg/prune.py

@@ -1,6 +1,6 @@
 import logging
-import subprocess
 
+from borgmatic.execute import execute_command
 from borgmatic.logger import get_logger
 
 logger = get_logger(__name__)
@@ -61,5 +61,4 @@ def prune_archives(
         + (('--stats',) if stats else ())
     )
 
-    logger.debug(' '.join(full_command))
+    execute_command(full_command)
-    subprocess.check_call(full_command)

borgmatic/commands/hook.py

@@ -30,4 +30,8 @@ def execute_hook(commands, config_filename, description, dry_run):
 
     for command in commands:
         if not dry_run:
-            execute.execute_command([command], output_log_level=logging.WARNING, shell=True)
+            execute.execute_command(
+                [command],
+                output_log_level=logging.ERROR if description == 'on-error' else logging.WARNING,
+                shell=True,
+            )

borgmatic/execute.py

@@ -13,6 +13,9 @@ def execute_and_log_output(full_command, output_log_level, shell):
 
     while process.poll() is None:
         line = process.stdout.readline().rstrip().decode()
+        if not line:
+            continue
+
         if line.startswith('borg: error:'):
             logger.error(line)
         else:

test_requirements.txt

@@ -7,7 +7,7 @@ colorama==0.4.1
 coverage==4.5.1
 docopt==0.6.2
 flake8==3.5.0
-flexmock==0.10.2
+flexmock==0.10.4
 isort==4.3.19
 mccabe==0.6.1
 more-itertools==4.3.0

tests/unit/borg/test_check.py

@@ -1,6 +1,4 @@
 import logging
-import sys
-from subprocess import STDOUT
 
 import pytest
 from flexmock import flexmock
@@ -10,14 +8,12 @@ from borgmatic.borg import check as module
 from ..test_verbosity import insert_logging_mock
 
 
-def insert_subprocess_mock(check_call_command, **kwargs):
+def insert_execute_command_mock(command):
-    subprocess = flexmock(module.subprocess)
+    flexmock(module).should_receive('execute_command').with_args(command).once()
-    subprocess.should_receive('check_call').with_args(check_call_command, **kwargs).once()
 
 
-def insert_subprocess_never():
+def insert_execute_command_never():
-    subprocess = flexmock(module.subprocess)
+    flexmock(module).should_receive('execute_command').never()
-    subprocess.should_receive('check_call').never()
 
 
 def test_parse_checks_returns_them_as_tuple():
@@ -120,10 +116,7 @@ def test_check_archives_calls_borg_with_parameters(checks):
     flexmock(module).should_receive('_make_check_flags').with_args(
         checks, check_last, None
     ).and_return(())
-    stdout = flexmock()
+    insert_execute_command_mock(('borg', 'check', 'repo'))
-    insert_subprocess_mock(('borg', 'check', 'repo'), stdout=stdout, stderr=STDOUT)
-    flexmock(sys.modules['builtins']).should_receive('open').and_return(stdout)
-    flexmock(module.os).should_receive('devnull')
 
     module.check_archives(
         repository='repo', storage_config={}, consistency_config=consistency_config
@@ -137,7 +130,7 @@ def test_check_archives_with_extract_check_calls_extract_only():
     flexmock(module).should_receive('_parse_checks').and_return(checks)
     flexmock(module).should_receive('_make_check_flags').never()
     flexmock(module.extract).should_receive('extract_last_archive_dry_run').once()
-    insert_subprocess_never()
+    insert_execute_command_never()
 
     module.check_archives(
         repository='repo', storage_config={}, consistency_config=consistency_config
@@ -150,7 +143,7 @@ def test_check_archives_with_log_info_calls_borg_with_info_parameter():
     flexmock(module).should_receive('_parse_checks').and_return(checks)
     flexmock(module).should_receive('_make_check_flags').and_return(())
     insert_logging_mock(logging.INFO)
-    insert_subprocess_mock(('borg', 'check', 'repo', '--info'), stdout=None, stderr=STDOUT)
+    insert_execute_command_mock(('borg', 'check', 'repo', '--info'))
 
     module.check_archives(
         repository='repo', storage_config={}, consistency_config=consistency_config
@@ -163,9 +156,7 @@ def test_check_archives_with_log_debug_calls_borg_with_debug_parameter():
     flexmock(module).should_receive('_parse_checks').and_return(checks)
     flexmock(module).should_receive('_make_check_flags').and_return(())
     insert_logging_mock(logging.DEBUG)
-    insert_subprocess_mock(
+    insert_execute_command_mock(('borg', 'check', 'repo', '--debug', '--show-rc'))
-        ('borg', 'check', 'repo', '--debug', '--show-rc'), stdout=None, stderr=STDOUT
-    )
 
     module.check_archives(
         repository='repo', storage_config={}, consistency_config=consistency_config
@@ -175,7 +166,7 @@ def test_check_archives_with_log_debug_calls_borg_with_debug_parameter():
 def test_check_archives_without_any_checks_bails():
     consistency_config = {'check_last': None}
     flexmock(module).should_receive('_parse_checks').and_return(())
-    insert_subprocess_never()
+    insert_execute_command_never()
 
     module.check_archives(
         repository='repo', storage_config={}, consistency_config=consistency_config
@@ -190,10 +181,7 @@ def test_check_archives_with_local_path_calls_borg_via_local_path():
     flexmock(module).should_receive('_make_check_flags').with_args(
         checks, check_last, None
     ).and_return(())
-    stdout = flexmock()
+    insert_execute_command_mock(('borg1', 'check', 'repo'))
-    insert_subprocess_mock(('borg1', 'check', 'repo'), stdout=stdout, stderr=STDOUT)
-    flexmock(sys.modules['builtins']).should_receive('open').and_return(stdout)
-    flexmock(module.os).should_receive('devnull')
 
     module.check_archives(
         repository='repo',
@@ -211,12 +199,7 @@ def test_check_archives_with_remote_path_calls_borg_with_remote_path_parameters(
     flexmock(module).should_receive('_make_check_flags').with_args(
         checks, check_last, None
     ).and_return(())
-    stdout = flexmock()
+    insert_execute_command_mock(('borg', 'check', 'repo', '--remote-path', 'borg1'))
-    insert_subprocess_mock(
-        ('borg', 'check', 'repo', '--remote-path', 'borg1'), stdout=stdout, stderr=STDOUT
-    )
-    flexmock(sys.modules['builtins']).should_receive('open').and_return(stdout)
-    flexmock(module.os).should_receive('devnull')
 
     module.check_archives(
         repository='repo',
@@ -234,12 +217,7 @@ def test_check_archives_with_lock_wait_calls_borg_with_lock_wait_parameters():
     flexmock(module).should_receive('_make_check_flags').with_args(
         checks, check_last, None
     ).and_return(())
-    stdout = flexmock()
+    insert_execute_command_mock(('borg', 'check', 'repo', '--lock-wait', '5'))
-    insert_subprocess_mock(
-        ('borg', 'check', 'repo', '--lock-wait', '5'), stdout=stdout, stderr=STDOUT
-    )
-    flexmock(sys.modules['builtins']).should_receive('open').and_return(stdout)
-    flexmock(module.os).should_receive('devnull')
 
     module.check_archives(
         repository='repo', storage_config={'lock_wait': 5}, consistency_config=consistency_config
@@ -255,11 +233,7 @@ def test_check_archives_with_retention_prefix():
     flexmock(module).should_receive('_make_check_flags').with_args(
         checks, check_last, prefix
     ).and_return(())
-    stdout = flexmock()
+    insert_execute_command_mock(('borg', 'check', 'repo'))
-    insert_subprocess_mock(('borg', 'check', 'repo'), stdout=stdout, stderr=STDOUT)
-
-    flexmock(sys.modules['builtins']).should_receive('open').and_return(stdout)
-    flexmock(module.os).should_receive('devnull')
 
     module.check_archives(
         repository='repo', storage_config={}, consistency_config=consistency_config

tests/unit/borg/test_extract.py

@@ -1,5 +1,4 @@
 import logging
-import sys
 
 from flexmock import flexmock
 
@@ -8,61 +7,46 @@ from borgmatic.borg import extract as module
 from ..test_verbosity import insert_logging_mock
 
 
-def insert_subprocess_mock(check_call_command, **kwargs):
+def insert_execute_command_mock(command):
-    subprocess = flexmock(module.subprocess)
+    flexmock(module).should_receive('execute_command').with_args(command).once()
-    subprocess.should_receive('check_call').with_args(check_call_command, **kwargs).once()
 
 
-def insert_subprocess_never():
+def insert_execute_command_output_mock(command, result):
-    subprocess = flexmock(module.subprocess)
+    flexmock(module).should_receive('execute_command').with_args(
-    subprocess.should_receive('check_call').never()
+        command, output_log_level=None
-
+    ).and_return(result).once()
-
-def insert_subprocess_check_output_mock(check_output_command, result, **kwargs):
-    subprocess = flexmock(module.subprocess)
-    subprocess.should_receive('check_output').with_args(check_output_command, **kwargs).and_return(
-        result
-    ).once()
 
 
 def test_extract_last_archive_dry_run_calls_borg_with_last_archive():
-    flexmock(sys.stdout).encoding = 'utf-8'
+    insert_execute_command_output_mock(
-    insert_subprocess_check_output_mock(
+        ('borg', 'list', '--short', 'repo'), result='archive1\narchive2\n'
-        ('borg', 'list', '--short', 'repo'), result='archive1\narchive2\n'.encode('utf-8')
     )
-    insert_subprocess_mock(('borg', 'extract', '--dry-run', 'repo::archive2'))
+    insert_execute_command_mock(('borg', 'extract', '--dry-run', 'repo::archive2'))
 
     module.extract_last_archive_dry_run(repository='repo', lock_wait=None)
 
 
-def test_extract_last_archive_dry_run_without_any_archives_should_bail():
+def test_extract_last_archive_dry_run_without_any_archives_should_not_raise():
-    flexmock(sys.stdout).encoding = 'utf-8'
+    insert_execute_command_output_mock(('borg', 'list', '--short', 'repo'), result='\n')
-    insert_subprocess_check_output_mock(
-        ('borg', 'list', '--short', 'repo'), result='\n'.encode('utf-8')
-    )
-    insert_subprocess_never()
 
     module.extract_last_archive_dry_run(repository='repo', lock_wait=None)
 
 
 def test_extract_last_archive_dry_run_with_log_info_calls_borg_with_info_parameter():
-    flexmock(sys.stdout).encoding = 'utf-8'
+    insert_execute_command_output_mock(
-    insert_subprocess_check_output_mock(
+        ('borg', 'list', '--short', 'repo', '--info'), result='archive1\narchive2\n'
-        ('borg', 'list', '--short', 'repo', '--info'), result='archive1\narchive2\n'.encode('utf-8')
     )
-    insert_subprocess_mock(('borg', 'extract', '--dry-run', 'repo::archive2', '--info'))
+    insert_execute_command_mock(('borg', 'extract', '--dry-run', 'repo::archive2', '--info'))
     insert_logging_mock(logging.INFO)
 
     module.extract_last_archive_dry_run(repository='repo', lock_wait=None)
 
 
 def test_extract_last_archive_dry_run_with_log_debug_calls_borg_with_debug_parameter():
-    flexmock(sys.stdout).encoding = 'utf-8'
+    insert_execute_command_output_mock(
-    insert_subprocess_check_output_mock(
+        ('borg', 'list', '--short', 'repo', '--debug', '--show-rc'), result='archive1\narchive2\n'
-        ('borg', 'list', '--short', 'repo', '--debug', '--show-rc'),
-        result='archive1\narchive2\n'.encode('utf-8'),
     )
-    insert_subprocess_mock(
+    insert_execute_command_mock(
         ('borg', 'extract', '--dry-run', 'repo::archive2', '--debug', '--show-rc', '--list')
     )
     insert_logging_mock(logging.DEBUG)
@@ -71,22 +55,19 @@ def test_extract_last_archive_dry_run_with_log_debug_calls_borg_with_debug_param
 
 
 def test_extract_last_archive_dry_run_calls_borg_via_local_path():
-    flexmock(sys.stdout).encoding = 'utf-8'
+    insert_execute_command_output_mock(
-    insert_subprocess_check_output_mock(
+        ('borg1', 'list', '--short', 'repo'), result='archive1\narchive2\n'
-        ('borg1', 'list', '--short', 'repo'), result='archive1\narchive2\n'.encode('utf-8')
     )
-    insert_subprocess_mock(('borg1', 'extract', '--dry-run', 'repo::archive2'))
+    insert_execute_command_mock(('borg1', 'extract', '--dry-run', 'repo::archive2'))
 
     module.extract_last_archive_dry_run(repository='repo', lock_wait=None, local_path='borg1')
 
 
 def test_extract_last_archive_dry_run_calls_borg_with_remote_path_parameters():
-    flexmock(sys.stdout).encoding = 'utf-8'
+    insert_execute_command_output_mock(
-    insert_subprocess_check_output_mock(
+        ('borg', 'list', '--short', 'repo', '--remote-path', 'borg1'), result='archive1\narchive2\n'
-        ('borg', 'list', '--short', 'repo', '--remote-path', 'borg1'),
-        result='archive1\narchive2\n'.encode('utf-8'),
     )
-    insert_subprocess_mock(
+    insert_execute_command_mock(
         ('borg', 'extract', '--dry-run', 'repo::archive2', '--remote-path', 'borg1')
     )
 
@@ -94,18 +75,18 @@ def test_extract_last_archive_dry_run_calls_borg_with_remote_path_parameters():
 
 
 def test_extract_last_archive_dry_run_calls_borg_with_lock_wait_parameters():
-    flexmock(sys.stdout).encoding = 'utf-8'
+    insert_execute_command_output_mock(
-    insert_subprocess_check_output_mock(
+        ('borg', 'list', '--short', 'repo', '--lock-wait', '5'), result='archive1\narchive2\n'
-        ('borg', 'list', '--short', 'repo', '--lock-wait', '5'),
+    )
-        result='archive1\narchive2\n'.encode('utf-8'),
+    insert_execute_command_mock(
+        ('borg', 'extract', '--dry-run', 'repo::archive2', '--lock-wait', '5')
     )
-    insert_subprocess_mock(('borg', 'extract', '--dry-run', 'repo::archive2', '--lock-wait', '5'))
 
     module.extract_last_archive_dry_run(repository='repo', lock_wait=5)
 
 
 def test_extract_archive_calls_borg_with_restore_path_parameters():
-    insert_subprocess_mock(('borg', 'extract', 'repo::archive', 'path1', 'path2'))
+    insert_execute_command_mock(('borg', 'extract', 'repo::archive', 'path1', 'path2'))
 
     module.extract_archive(
         dry_run=False,
@@ -118,7 +99,7 @@ def test_extract_archive_calls_borg_with_restore_path_parameters():
 
 
 def test_extract_archive_calls_borg_with_remote_path_parameters():
-    insert_subprocess_mock(('borg', 'extract', 'repo::archive', '--remote-path', 'borg1'))
+    insert_execute_command_mock(('borg', 'extract', 'repo::archive', '--remote-path', 'borg1'))
 
     module.extract_archive(
         dry_run=False,
@@ -132,7 +113,7 @@ def test_extract_archive_calls_borg_with_remote_path_parameters():
 
 
 def test_extract_archive_calls_borg_with_numeric_owner_parameter():
-    insert_subprocess_mock(('borg', 'extract', 'repo::archive', '--numeric-owner'))
+    insert_execute_command_mock(('borg', 'extract', 'repo::archive', '--numeric-owner'))
 
     module.extract_archive(
         dry_run=False,
@@ -145,7 +126,7 @@ def test_extract_archive_calls_borg_with_numeric_owner_parameter():
 
 
 def test_extract_archive_calls_borg_with_umask_parameters():
-    insert_subprocess_mock(('borg', 'extract', 'repo::archive', '--umask', '0770'))
+    insert_execute_command_mock(('borg', 'extract', 'repo::archive', '--umask', '0770'))
 
     module.extract_archive(
         dry_run=False,
@@ -158,7 +139,7 @@ def test_extract_archive_calls_borg_with_umask_parameters():
 
 
 def test_extract_archive_calls_borg_with_lock_wait_parameters():
-    insert_subprocess_mock(('borg', 'extract', 'repo::archive', '--lock-wait', '5'))
+    insert_execute_command_mock(('borg', 'extract', 'repo::archive', '--lock-wait', '5'))
 
     module.extract_archive(
         dry_run=False,
@@ -171,7 +152,7 @@ def test_extract_archive_calls_borg_with_lock_wait_parameters():
 
 
 def test_extract_archive_with_log_info_calls_borg_with_info_parameter():
-    insert_subprocess_mock(('borg', 'extract', 'repo::archive', '--info'))
+    insert_execute_command_mock(('borg', 'extract', 'repo::archive', '--info'))
     insert_logging_mock(logging.INFO)
 
     module.extract_archive(
@@ -185,7 +166,9 @@ def test_extract_archive_with_log_info_calls_borg_with_info_parameter():
 
 
 def test_extract_archive_with_log_debug_calls_borg_with_debug_parameters():
-    insert_subprocess_mock(('borg', 'extract', 'repo::archive', '--debug', '--list', '--show-rc'))
+    insert_execute_command_mock(
+        ('borg', 'extract', 'repo::archive', '--debug', '--list', '--show-rc')
+    )
     insert_logging_mock(logging.DEBUG)
 
     module.extract_archive(
@@ -199,7 +182,7 @@ def test_extract_archive_with_log_debug_calls_borg_with_debug_parameters():
 
 
 def test_extract_archive_calls_borg_with_dry_run_parameter():
-    insert_subprocess_mock(('borg', 'extract', 'repo::archive', '--dry-run'))
+    insert_execute_command_mock(('borg', 'extract', 'repo::archive', '--dry-run'))
 
     module.extract_archive(
         dry_run=True,
@@ -212,7 +195,7 @@ def test_extract_archive_calls_borg_with_dry_run_parameter():
 
 
 def test_extract_archive_calls_borg_with_progress_parameter():
-    insert_subprocess_mock(('borg', 'extract', 'repo::archive', '--progress'))
+    insert_execute_command_mock(('borg', 'extract', 'repo::archive', '--progress'))
 
     module.extract_archive(
         dry_run=False,

tests/unit/borg/test_info.py

@@ -11,7 +11,7 @@ INFO_COMMAND = ('borg', 'info', 'repo')
 
 def test_display_archives_info_calls_borg_with_parameters():
     flexmock(module).should_receive('execute_command').with_args(
-        INFO_COMMAND, output_log_level=logging.INFO
+        INFO_COMMAND, output_log_level=logging.WARNING
     )
 
     module.display_archives_info(repository='repo', storage_config={})
@@ -19,7 +19,7 @@ def test_display_archives_info_calls_borg_with_parameters():
 
 def test_display_archives_info_with_log_info_calls_borg_with_info_parameter():
     flexmock(module).should_receive('execute_command').with_args(
-        INFO_COMMAND + ('--info',), output_log_level=logging.INFO
+        INFO_COMMAND + ('--info',), output_log_level=logging.WARNING
     )
     insert_logging_mock(logging.INFO)
     module.display_archives_info(repository='repo', storage_config={})
@@ -27,7 +27,7 @@ def test_display_archives_info_with_log_info_calls_borg_with_info_parameter():
 
 def test_display_archives_info_with_log_debug_calls_borg_with_debug_parameter():
     flexmock(module).should_receive('execute_command').with_args(
-        INFO_COMMAND + ('--debug', '--show-rc'), output_log_level=logging.INFO
+        INFO_COMMAND + ('--debug', '--show-rc'), output_log_level=logging.WARNING
     )
     insert_logging_mock(logging.DEBUG)
 
@@ -46,7 +46,7 @@ def test_display_archives_info_with_json_calls_borg_with_json_parameter():
 
 def test_display_archives_info_with_local_path_calls_borg_via_local_path():
     flexmock(module).should_receive('execute_command').with_args(
-        ('borg1',) + INFO_COMMAND[1:], output_log_level=logging.INFO
+        ('borg1',) + INFO_COMMAND[1:], output_log_level=logging.WARNING
     )
 
     module.display_archives_info(repository='repo', storage_config={}, local_path='borg1')
@@ -54,7 +54,7 @@ def test_display_archives_info_with_local_path_calls_borg_via_local_path():
 
 def test_display_archives_info_with_remote_path_calls_borg_with_remote_path_parameters():
     flexmock(module).should_receive('execute_command').with_args(
-        INFO_COMMAND + ('--remote-path', 'borg1'), output_log_level=logging.INFO
+        INFO_COMMAND + ('--remote-path', 'borg1'), output_log_level=logging.WARNING
     )
 
     module.display_archives_info(repository='repo', storage_config={}, remote_path='borg1')
@@ -63,7 +63,7 @@ def test_display_archives_info_with_remote_path_calls_borg_with_remote_path_para
 def test_display_archives_info_with_lock_wait_calls_borg_with_lock_wait_parameters():
     storage_config = {'lock_wait': 5}
     flexmock(module).should_receive('execute_command').with_args(
-        INFO_COMMAND + ('--lock-wait', '5'), output_log_level=logging.INFO
+        INFO_COMMAND + ('--lock-wait', '5'), output_log_level=logging.WARNING
     )
 
     module.display_archives_info(repository='repo', storage_config=storage_config)

tests/unit/borg/test_init.py

@@ -1,4 +1,5 @@
 import logging
+import subprocess
 
 from flexmock import flexmock
 
@@ -6,51 +7,56 @@ from borgmatic.borg import init as module
 
 from ..test_verbosity import insert_logging_mock
 
-INFO_REPOSITORY_EXISTS_RESPONSE_CODE = 0
 INFO_REPOSITORY_NOT_FOUND_RESPONSE_CODE = 2
 INIT_COMMAND = ('borg', 'init', 'repo', '--encryption', 'repokey')
 
 
-def insert_info_command_mock(info_response):
+def insert_info_command_found_mock():
-    subprocess = flexmock(module.subprocess)
+    flexmock(module).should_receive('execute_command')
-    subprocess.should_receive('call').and_return(info_response)
+
+
+def insert_info_command_not_found_mock():
+    flexmock(module).should_receive('execute_command').and_raise(
+        subprocess.CalledProcessError(INFO_REPOSITORY_NOT_FOUND_RESPONSE_CODE, [])
+    )
 
 
 def insert_init_command_mock(init_command, **kwargs):
-    subprocess = flexmock(module.subprocess)
+    flexmock(module.subprocess).should_receive('check_call').with_args(
-    subprocess.should_receive('check_call').with_args(init_command, **kwargs).once()
+        init_command, **kwargs
+    ).once()
 
 
 def test_initialize_repository_calls_borg_with_parameters():
-    insert_info_command_mock(INFO_REPOSITORY_NOT_FOUND_RESPONSE_CODE)
+    insert_info_command_not_found_mock()
     insert_init_command_mock(INIT_COMMAND)
 
     module.initialize_repository(repository='repo', encryption_mode='repokey')
 
 
 def test_initialize_repository_skips_initialization_when_repository_already_exists():
-    insert_info_command_mock(INFO_REPOSITORY_EXISTS_RESPONSE_CODE)
+    insert_info_command_found_mock()
     flexmock(module.subprocess).should_receive('check_call').never()
 
     module.initialize_repository(repository='repo', encryption_mode='repokey')
 
 
 def test_initialize_repository_with_append_only_calls_borg_with_append_only_parameter():
-    insert_info_command_mock(INFO_REPOSITORY_NOT_FOUND_RESPONSE_CODE)
+    insert_info_command_not_found_mock()
     insert_init_command_mock(INIT_COMMAND + ('--append-only',))
 
     module.initialize_repository(repository='repo', encryption_mode='repokey', append_only=True)
 
 
 def test_initialize_repository_with_storage_quota_calls_borg_with_storage_quota_parameter():
-    insert_info_command_mock(INFO_REPOSITORY_NOT_FOUND_RESPONSE_CODE)
+    insert_info_command_not_found_mock()
     insert_init_command_mock(INIT_COMMAND + ('--storage-quota', '5G'))
 
     module.initialize_repository(repository='repo', encryption_mode='repokey', storage_quota='5G')
 
 
 def test_initialize_repository_with_log_info_calls_borg_with_info_parameter():
-    insert_info_command_mock(INFO_REPOSITORY_NOT_FOUND_RESPONSE_CODE)
+    insert_info_command_not_found_mock()
     insert_init_command_mock(INIT_COMMAND + ('--info',))
     insert_logging_mock(logging.INFO)
 
@@ -58,7 +64,7 @@ def test_initialize_repository_with_log_info_calls_borg_with_info_parameter():
 
 
 def test_initialize_repository_with_log_debug_calls_borg_with_debug_parameter():
-    insert_info_command_mock(INFO_REPOSITORY_NOT_FOUND_RESPONSE_CODE)
+    insert_info_command_not_found_mock()
     insert_init_command_mock(INIT_COMMAND + ('--debug',))
     insert_logging_mock(logging.DEBUG)
 
@@ -66,14 +72,14 @@ def test_initialize_repository_with_log_debug_calls_borg_with_debug_parameter():
 
 
 def test_initialize_repository_with_local_path_calls_borg_via_local_path():
-    insert_info_command_mock(INFO_REPOSITORY_NOT_FOUND_RESPONSE_CODE)
+    insert_info_command_not_found_mock()
     insert_init_command_mock(('borg1',) + INIT_COMMAND[1:])
 
     module.initialize_repository(repository='repo', encryption_mode='repokey', local_path='borg1')
 
 
 def test_initialize_repository_with_remote_path_calls_borg_with_remote_path_parameter():
-    insert_info_command_mock(INFO_REPOSITORY_NOT_FOUND_RESPONSE_CODE)
+    insert_info_command_not_found_mock()
     insert_init_command_mock(INIT_COMMAND + ('--remote-path', 'borg1'))
 
     module.initialize_repository(repository='repo', encryption_mode='repokey', remote_path='borg1')

tests/unit/borg/test_list.py

@@ -11,7 +11,7 @@ LIST_COMMAND = ('borg', 'list', 'repo')
 
 def test_list_archives_calls_borg_with_parameters():
     flexmock(module).should_receive('execute_command').with_args(
-        LIST_COMMAND, output_log_level=logging.INFO
+        LIST_COMMAND, output_log_level=logging.WARNING
     )
 
     module.list_archives(repository='repo', storage_config={})
@@ -19,7 +19,7 @@ def test_list_archives_calls_borg_with_parameters():
 
 def test_list_archives_with_log_info_calls_borg_with_info_parameter():
     flexmock(module).should_receive('execute_command').with_args(
-        LIST_COMMAND + ('--info',), output_log_level=logging.INFO
+        LIST_COMMAND + ('--info',), output_log_level=logging.WARNING
     )
     insert_logging_mock(logging.INFO)
 
@@ -28,7 +28,7 @@ def test_list_archives_with_log_info_calls_borg_with_info_parameter():
 
 def test_list_archives_with_log_debug_calls_borg_with_debug_parameter():
     flexmock(module).should_receive('execute_command').with_args(
-        LIST_COMMAND + ('--debug', '--show-rc'), output_log_level=logging.INFO
+        LIST_COMMAND + ('--debug', '--show-rc'), output_log_level=logging.WARNING
     )
     insert_logging_mock(logging.DEBUG)
 
@@ -38,7 +38,7 @@ def test_list_archives_with_log_debug_calls_borg_with_debug_parameter():
 def test_list_archives_with_lock_wait_calls_borg_with_lock_wait_parameters():
     storage_config = {'lock_wait': 5}
     flexmock(module).should_receive('execute_command').with_args(
-        LIST_COMMAND + ('--lock-wait', '5'), output_log_level=logging.INFO
+        LIST_COMMAND + ('--lock-wait', '5'), output_log_level=logging.WARNING
     )
 
     module.list_archives(repository='repo', storage_config=storage_config)
@@ -47,7 +47,7 @@ def test_list_archives_with_lock_wait_calls_borg_with_lock_wait_parameters():
 def test_list_archives_with_archive_calls_borg_with_archive_parameter():
     storage_config = {}
     flexmock(module).should_receive('execute_command').with_args(
-        ('borg', 'list', 'repo::archive'), output_log_level=logging.INFO
+        ('borg', 'list', 'repo::archive'), output_log_level=logging.WARNING
     )
 
     module.list_archives(repository='repo', storage_config=storage_config, archive='archive')
@@ -55,7 +55,7 @@ def test_list_archives_with_archive_calls_borg_with_archive_parameter():
 
 def test_list_archives_with_local_path_calls_borg_via_local_path():
     flexmock(module).should_receive('execute_command').with_args(
-        ('borg1',) + LIST_COMMAND[1:], output_log_level=logging.INFO
+        ('borg1',) + LIST_COMMAND[1:], output_log_level=logging.WARNING
     )
 
     module.list_archives(repository='repo', storage_config={}, local_path='borg1')
@@ -63,7 +63,7 @@ def test_list_archives_with_local_path_calls_borg_via_local_path():
 
 def test_list_archives_with_remote_path_calls_borg_with_remote_path_parameters():
     flexmock(module).should_receive('execute_command').with_args(
-        LIST_COMMAND + ('--remote-path', 'borg1'), output_log_level=logging.INFO
+        LIST_COMMAND + ('--remote-path', 'borg1'), output_log_level=logging.WARNING
     )
 
     module.list_archives(repository='repo', storage_config={}, remote_path='borg1')

tests/unit/borg/test_prune.py

@@ -8,9 +8,8 @@ from borgmatic.borg import prune as module
 from ..test_verbosity import insert_logging_mock
 
 
-def insert_subprocess_mock(check_call_command, **kwargs):
+def insert_execute_command_mock(prune_command, **kwargs):
-    subprocess = flexmock(module.subprocess)
+    flexmock(module).should_receive('execute_command').with_args(prune_command).once()
-    subprocess.should_receive('check_call').with_args(check_call_command, **kwargs).once()
 
 
 BASE_PRUNE_FLAGS = (('--keep-daily', '1'), ('--keep-weekly', '2'), ('--keep-monthly', '3'))
@@ -52,7 +51,7 @@ def test_prune_archives_calls_borg_with_parameters():
     flexmock(module).should_receive('_make_prune_flags').with_args(retention_config).and_return(
         BASE_PRUNE_FLAGS
     )
-    insert_subprocess_mock(PRUNE_COMMAND)
+    insert_execute_command_mock(PRUNE_COMMAND)
 
     module.prune_archives(
         dry_run=False, repository='repo', storage_config={}, retention_config=retention_config
@@ -64,7 +63,7 @@ def test_prune_archives_with_log_info_calls_borg_with_info_parameter():
     flexmock(module).should_receive('_make_prune_flags').with_args(retention_config).and_return(
         BASE_PRUNE_FLAGS
     )
-    insert_subprocess_mock(PRUNE_COMMAND + ('--stats', '--info'))
+    insert_execute_command_mock(PRUNE_COMMAND + ('--stats', '--info'))
     insert_logging_mock(logging.INFO)
 
     module.prune_archives(
@@ -77,7 +76,7 @@ def test_prune_archives_with_log_debug_calls_borg_with_debug_parameter():
     flexmock(module).should_receive('_make_prune_flags').with_args(retention_config).and_return(
         BASE_PRUNE_FLAGS
     )
-    insert_subprocess_mock(PRUNE_COMMAND + ('--stats', '--debug', '--list', '--show-rc'))
+    insert_execute_command_mock(PRUNE_COMMAND + ('--stats', '--debug', '--list', '--show-rc'))
     insert_logging_mock(logging.DEBUG)
 
     module.prune_archives(
@@ -90,7 +89,7 @@ def test_prune_archives_with_dry_run_calls_borg_with_dry_run_parameter():
     flexmock(module).should_receive('_make_prune_flags').with_args(retention_config).and_return(
         BASE_PRUNE_FLAGS
     )
-    insert_subprocess_mock(PRUNE_COMMAND + ('--dry-run',))
+    insert_execute_command_mock(PRUNE_COMMAND + ('--dry-run',))
 
     module.prune_archives(
         repository='repo', storage_config={}, dry_run=True, retention_config=retention_config
@@ -102,7 +101,7 @@ def test_prune_archives_with_local_path_calls_borg_via_local_path():
     flexmock(module).should_receive('_make_prune_flags').with_args(retention_config).and_return(
         BASE_PRUNE_FLAGS
     )
-    insert_subprocess_mock(('borg1',) + PRUNE_COMMAND[1:])
+    insert_execute_command_mock(('borg1',) + PRUNE_COMMAND[1:])
 
     module.prune_archives(
         dry_run=False,
@@ -118,7 +117,7 @@ def test_prune_archives_with_remote_path_calls_borg_with_remote_path_parameters(
     flexmock(module).should_receive('_make_prune_flags').with_args(retention_config).and_return(
         BASE_PRUNE_FLAGS
     )
-    insert_subprocess_mock(PRUNE_COMMAND + ('--remote-path', 'borg1'))
+    insert_execute_command_mock(PRUNE_COMMAND + ('--remote-path', 'borg1'))
 
     module.prune_archives(
         dry_run=False,
@@ -135,7 +134,7 @@ def test_prune_archives_with_umask_calls_borg_with_umask_parameters():
     flexmock(module).should_receive('_make_prune_flags').with_args(retention_config).and_return(
         BASE_PRUNE_FLAGS
     )
-    insert_subprocess_mock(PRUNE_COMMAND + ('--umask', '077'))
+    insert_execute_command_mock(PRUNE_COMMAND + ('--umask', '077'))
 
     module.prune_archives(
         dry_run=False,
@@ -151,7 +150,7 @@ def test_prune_archives_with_lock_wait_calls_borg_with_lock_wait_parameters():
     flexmock(module).should_receive('_make_prune_flags').with_args(retention_config).and_return(
         BASE_PRUNE_FLAGS
     )
-    insert_subprocess_mock(PRUNE_COMMAND + ('--lock-wait', '5'))
+    insert_execute_command_mock(PRUNE_COMMAND + ('--lock-wait', '5'))
 
     module.prune_archives(
         dry_run=False,