Clarify one_file_system behavior in schema comment (#520).

NEWS

@@ -1,3 +1,10 @@
+1.5.25.dev0
+ * #516: Fix handling of TERM signal to exit borgmatic, not just forward the signal to Borg.
+ * #517: Fix borgmatic exit code (so it's zero) when initial Borg calls fail but later retries
+   succeed.
+ * Change Healthchecks logs truncation size from 10k bytes to 100k bytes, corresponding to that
+   same change on Healthchecks.io.
+
 1.5.24
  * #431: Add "working_directory" option to support source directories with relative paths.
  * #444: When loading a configuration file that is unreadable due to file permissions, warn instead

borgmatic/commands/borgmatic.py

@@ -72,7 +72,7 @@ def run_configuration(config_filename, config, arguments):
     try:
         local_borg_version = borg_version.local_borg_version(local_path)
     except (OSError, CalledProcessError, ValueError) as error:
-        yield from make_error_log_records(
+        yield from log_error_records(
             '{}: Error getting local Borg version'.format(config_filename), error
         )
         return
@@ -146,9 +146,7 @@ def run_configuration(config_filename, config, arguments):
             return
 
         encountered_error = error
-        yield from make_error_log_records(
+        yield from log_error_records('{}: Error running pre hook'.format(config_filename), error)
-            '{}: Error running pre hook'.format(config_filename), error
-        )
 
     if not encountered_error:
         repo_queue = Queue()
@@ -175,15 +173,24 @@ def run_configuration(config_filename, config, arguments):
                     repository_path=repository_path,
                 )
             except (OSError, CalledProcessError, ValueError) as error:
-                yield from make_error_log_records(
-                    '{}: Error running actions for repository'.format(repository_path), error
-                )
                 if retry_num < retries:
                     repo_queue.put((repository_path, retry_num + 1),)
+                    tuple(  # Consume the generator so as to trigger logging.
+                        log_error_records(
+                            '{}: Error running actions for repository'.format(repository_path),
+                            error,
+                            levelno=logging.WARNING,
+                            log_command_error_output=True,
+                        )
+                    )
                     logger.warning(
                         f'{config_filename}: Retrying... attempt {retry_num + 1}/{retries}'
                     )
                     continue
+
+                yield from log_error_records(
+                    '{}: Error running actions for repository'.format(repository_path), error
+                )
                 encountered_error = error
                 error_repository = repository_path
 
@@ -264,7 +271,7 @@ def run_configuration(config_filename, config, arguments):
                 return
 
             encountered_error = error
-            yield from make_error_log_records(
+            yield from log_error_records(
                 '{}: Error running post hook'.format(config_filename), error
             )
 
@@ -301,7 +308,7 @@ def run_configuration(config_filename, config, arguments):
             if command.considered_soft_failure(config_filename, error):
                 return
 
-            yield from make_error_log_records(
+            yield from log_error_records(
                 '{}: Error running on-error hook'.format(config_filename), error
             )
 
@@ -704,28 +711,39 @@ def log_record(suppress_log=False, **kwargs):
     return record
 
 
-def make_error_log_records(message, error=None):
+def log_error_records(
+    message, error=None, levelno=logging.CRITICAL, log_command_error_output=False
+):
     '''
-    Given error message text and an optional exception object, yield a series of logging.LogRecord
+    Given error message text, an optional exception object, an optional log level, and whether to
-    instances with error summary information. As a side effect, log each record.
+    log the error output of a CalledProcessError (if any), log error summary information and also
+    yield it as a series of logging.LogRecord instances.
+
+    Note that because the logs are yielded as a generator, logs won't get logged unless you consume
+    the generator output.
     '''
+    level_name = logging._levelToName[levelno]
+
     if not error:
-        yield log_record(levelno=logging.CRITICAL, levelname='CRITICAL', msg=message)
+        yield log_record(levelno=levelno, levelname=level_name, msg=message)
         return
 
     try:
         raise error
     except CalledProcessError as error:
-        yield log_record(levelno=logging.CRITICAL, levelname='CRITICAL', msg=message)
+        yield log_record(levelno=levelno, levelname=level_name, msg=message)
         if error.output:
             # Suppress these logs for now and save full error output for the log summary at the end.
             yield log_record(
-                levelno=logging.CRITICAL, levelname='CRITICAL', msg=error.output, suppress_log=True
+                levelno=levelno,
+                levelname=level_name,
+                msg=error.output,
+                suppress_log=not log_command_error_output,
             )
-        yield log_record(levelno=logging.CRITICAL, levelname='CRITICAL', msg=error)
+        yield log_record(levelno=levelno, levelname=level_name, msg=error)
     except (ValueError, OSError) as error:
-        yield log_record(levelno=logging.CRITICAL, levelname='CRITICAL', msg=message)
+        yield log_record(levelno=levelno, levelname=level_name, msg=message)
-        yield log_record(levelno=logging.CRITICAL, levelname='CRITICAL', msg=error)
+        yield log_record(levelno=levelno, levelname=level_name, msg=error)
     except:  # noqa: E722
         # Raising above only as a means of determining the error type. Swallow the exception here
         # because we don't want the exception to propagate out of this function.
@@ -764,11 +782,11 @@ def collect_configuration_run_summary_logs(configs, arguments):
         try:
             validate.guard_configuration_contains_repository(repository, configs)
         except ValueError as error:
-            yield from make_error_log_records(str(error))
+            yield from log_error_records(str(error))
             return
 
     if not configs:
-        yield from make_error_log_records(
+        yield from log_error_records(
             '{}: No valid configuration files found'.format(
                 ' '.join(arguments['global'].config_paths)
             )
@@ -787,7 +805,7 @@ def collect_configuration_run_summary_logs(configs, arguments):
                     arguments['global'].dry_run,
                 )
         except (CalledProcessError, ValueError, OSError) as error:
-            yield from make_error_log_records('Error running pre-everything hook', error)
+            yield from log_error_records('Error running pre-everything hook', error)
             return
 
     # Execute the actions corresponding to each configuration file.
@@ -797,7 +815,7 @@ def collect_configuration_run_summary_logs(configs, arguments):
         error_logs = tuple(result for result in results if isinstance(result, logging.LogRecord))
 
         if error_logs:
-            yield from make_error_log_records(
+            yield from log_error_records(
                 '{}: Error running configuration file'.format(config_filename)
             )
             yield from error_logs
@@ -819,7 +837,7 @@ def collect_configuration_run_summary_logs(configs, arguments):
                 mount_point=arguments['umount'].mount_point, local_path=get_local_path(configs)
             )
         except (CalledProcessError, OSError) as error:
-            yield from make_error_log_records('Error unmounting mount point', error)
+            yield from log_error_records('Error unmounting mount point', error)
 
     if json_results:
         sys.stdout.write(json.dumps(json_results))
@@ -836,7 +854,7 @@ def collect_configuration_run_summary_logs(configs, arguments):
                     arguments['global'].dry_run,
                 )
         except (CalledProcessError, ValueError, OSError) as error:
-            yield from make_error_log_records('Error running post-everything hook', error)
+            yield from log_error_records('Error running post-everything hook', error)
 
 
 def exit_with_help_link():  # pragma: no cover

borgmatic/config/schema.yaml

@@ -53,10 +53,10 @@ properties:
             one_file_system:
                 type: boolean
                 description: |
-                    Stay in same file system (do not cross mount points).
+                    Stay in same file system: do not cross mount points beyond
-                    Defaults to false. But when a database hook is used, the
+                    the given source directories. Defaults to false. But when a
-                    setting here is ignored and one_file_system is considered
+                    database hook is used, the setting here is ignored and
-                    true.
+                    one_file_system is considered true.
                 example: true
             numeric_owner:
                 type: boolean

borgmatic/hooks/healthchecks.py

@@ -13,7 +13,7 @@ MONITOR_STATE_TO_HEALTHCHECKS = {
 }
 
 PAYLOAD_TRUNCATION_INDICATOR = '...\n'
-PAYLOAD_LIMIT_BYTES = 10 * 1024 - len(PAYLOAD_TRUNCATION_INDICATOR)
+PAYLOAD_LIMIT_BYTES = 100 * 1024 - len(PAYLOAD_TRUNCATION_INDICATOR)
 
 
 class Forgetful_buffering_handler(logging.Handler):

borgmatic/signals.py

@@ -1,23 +1,34 @@
+import logging
 import os
 import signal
+import sys
+
+logger = logging.getLogger(__name__)
 
 
-def _handle_signal(signal_number, frame):  # pragma: no cover
+EXIT_CODE_FROM_SIGNAL = 128
+
+
+def handle_signal(signal_number, frame):
     '''
     Send the signal to all processes in borgmatic's process group, which includes child processes.
     '''
     # Prevent infinite signal handler recursion. If the parent frame is this very same handler
     # function, we know we're recursing.
-    if frame.f_back.f_code.co_name == _handle_signal.__name__:
+    if frame.f_back.f_code.co_name == handle_signal.__name__:
         return
 
     os.killpg(os.getpgrp(), signal_number)
 
+    if signal_number == signal.SIGTERM:
+        logger.critical('Exiting due to TERM signal')
+        sys.exit(EXIT_CODE_FROM_SIGNAL + signal.SIGTERM)
 
-def configure_signals():  # pragma: no cover
+
+def configure_signals():
     '''
     Configure borgmatic's signal handlers to pass relevant signals through to any child processes
     like Borg. Note that SIGINT gets passed through even without these changes.
     '''
     for signal_number in (signal.SIGHUP, signal.SIGTERM, signal.SIGUSR1, signal.SIGUSR2):
-        signal.signal(signal_number, _handle_signal)
+        signal.signal(signal_number, handle_signal)

docs/how-to/add-preparation-and-cleanup-steps-to-backups.md

@@ -59,11 +59,11 @@ variables you can use here:
  * `repositories`: comma-separated paths of all repositories configured in the
    current borgmatic configuration file
 
+## Global hooks
+
 You can also use `before_everything` and `after_everything` hooks to perform
 global setup or cleanup:
 
-## Global hooks
-
 ```yaml
 hooks:
     before_everything:

docs/how-to/set-up-backups.md

@@ -28,7 +28,7 @@ sudo pip3 install --user --upgrade borgmatic
 This installs borgmatic and its commands at the `/root/.local/bin` path.
 
 Your pip binary may have a different name than "pip3". Make sure you're using
-Python 3.6+, as borgmatic does not support Python 2.
+Python 3.7+, as borgmatic does not support older versions of Python.
 
 The next step is to ensure that borgmatic's commands available are on your
 system `PATH`, so that you can run borgmatic:

scripts/release

@@ -31,8 +31,8 @@ python3 setup.py bdist_wheel
 python3 setup.py sdist
 gpg --detach-sign --armor dist/borgmatic-*.tar.gz
 gpg --detach-sign --armor dist/borgmatic-*-py3-none-any.whl
-twine upload -r pypi dist/borgmatic-*.tar.gz dist/borgmatic-*.tar.gz.asc
+twine upload -r pypi --username __token__ dist/borgmatic-*.tar.gz dist/borgmatic-*.tar.gz.asc
-twine upload -r pypi dist/borgmatic-*-py3-none-any.whl dist/borgmatic-*-py3-none-any.whl.asc
+twine upload -r pypi --username __token__ dist/borgmatic-*-py3-none-any.whl dist/borgmatic-*-py3-none-any.whl.asc
 
 # Set release changelogs on projects.torsion.org and GitHub.
 release_changelog="$(cat NEWS | sed '/^$/q' | grep -v '^\S')"

setup.py

@@ -1,6 +1,6 @@
 from setuptools import find_packages, setup
 
-VERSION = '1.5.24'
+VERSION = '1.5.25.dev0'
 
 
 setup(

tests/unit/commands/test_borgmatic.py

@@ -112,7 +112,7 @@ def test_run_configuration_logs_actions_error():
     flexmock(module.command).should_receive('execute_hook')
     flexmock(module.dispatch).should_receive('call_hooks')
     expected_results = [flexmock()]
-    flexmock(module).should_receive('make_error_log_records').and_return(expected_results)
+    flexmock(module).should_receive('log_error_records').and_return(expected_results)
     flexmock(module).should_receive('run_actions').and_raise(OSError)
     config = {'location': {'repositories': ['foo']}}
     arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False)}
@@ -127,7 +127,7 @@ def test_run_configuration_logs_pre_hook_error():
     flexmock(module.borg_version).should_receive('local_borg_version').and_return(flexmock())
     flexmock(module.command).should_receive('execute_hook').and_raise(OSError).and_return(None)
     expected_results = [flexmock()]
-    flexmock(module).should_receive('make_error_log_records').and_return(expected_results)
+    flexmock(module).should_receive('log_error_records').and_return(expected_results)
     flexmock(module).should_receive('run_actions').never()
     config = {'location': {'repositories': ['foo']}}
     arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()}
@@ -142,7 +142,7 @@ def test_run_configuration_bails_for_pre_hook_soft_failure():
     flexmock(module.borg_version).should_receive('local_borg_version').and_return(flexmock())
     error = subprocess.CalledProcessError(borgmatic.hooks.command.SOFT_FAIL_EXIT_CODE, 'try again')
     flexmock(module.command).should_receive('execute_hook').and_raise(error).and_return(None)
-    flexmock(module).should_receive('make_error_log_records').never()
+    flexmock(module).should_receive('log_error_records').never()
     flexmock(module).should_receive('run_actions').never()
     config = {'location': {'repositories': ['foo']}}
     arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()}
@@ -160,7 +160,7 @@ def test_run_configuration_logs_post_hook_error():
     ).and_return(None)
     flexmock(module.dispatch).should_receive('call_hooks')
     expected_results = [flexmock()]
-    flexmock(module).should_receive('make_error_log_records').and_return(expected_results)
+    flexmock(module).should_receive('log_error_records').and_return(expected_results)
     flexmock(module).should_receive('run_actions').and_return([])
     config = {'location': {'repositories': ['foo']}}
     arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()}
@@ -178,7 +178,7 @@ def test_run_configuration_bails_for_post_hook_soft_failure():
         error
     ).and_return(None)
     flexmock(module.dispatch).should_receive('call_hooks')
-    flexmock(module).should_receive('make_error_log_records').never()
+    flexmock(module).should_receive('log_error_records').never()
     flexmock(module).should_receive('run_actions').and_return([])
     config = {'location': {'repositories': ['foo']}}
     arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()}
@@ -193,7 +193,7 @@ def test_run_configuration_logs_on_error_hook_error():
     flexmock(module.borg_version).should_receive('local_borg_version').and_return(flexmock())
     flexmock(module.command).should_receive('execute_hook').and_raise(OSError)
     expected_results = [flexmock(), flexmock()]
-    flexmock(module).should_receive('make_error_log_records').and_return(
+    flexmock(module).should_receive('log_error_records').and_return(
         expected_results[:1]
     ).and_return(expected_results[1:])
     flexmock(module).should_receive('run_actions').and_raise(OSError)
@@ -211,7 +211,7 @@ def test_run_configuration_bails_for_on_error_hook_soft_failure():
     error = subprocess.CalledProcessError(borgmatic.hooks.command.SOFT_FAIL_EXIT_CODE, 'try again')
     flexmock(module.command).should_receive('execute_hook').and_return(None).and_raise(error)
     expected_results = [flexmock()]
-    flexmock(module).should_receive('make_error_log_records').and_return(expected_results)
+    flexmock(module).should_receive('log_error_records').and_return(expected_results)
     flexmock(module).should_receive('run_actions').and_raise(OSError)
     config = {'location': {'repositories': ['foo']}}
     arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()}
@@ -227,12 +227,11 @@ def test_run_configuration_retries_soft_error():
     flexmock(module.borg_version).should_receive('local_borg_version').and_return(flexmock())
     flexmock(module.command).should_receive('execute_hook')
     flexmock(module).should_receive('run_actions').and_raise(OSError).and_return([])
-    expected_results = [flexmock()]
+    flexmock(module).should_receive('log_error_records').and_return([flexmock()]).once()
-    flexmock(module).should_receive('make_error_log_records').and_return(expected_results).once()
     config = {'location': {'repositories': ['foo']}, 'storage': {'retries': 1}}
     arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()}
     results = list(module.run_configuration('test.yaml', config, arguments))
-    assert results == expected_results
+    assert results == []
 
 
 def test_run_configuration_retries_hard_error():
@@ -241,18 +240,20 @@ def test_run_configuration_retries_hard_error():
     flexmock(module.borg_version).should_receive('local_borg_version').and_return(flexmock())
     flexmock(module.command).should_receive('execute_hook')
     flexmock(module).should_receive('run_actions').and_raise(OSError).times(2)
-    expected_results = [flexmock(), flexmock()]
+    flexmock(module).should_receive('log_error_records').with_args(
-    flexmock(module).should_receive('make_error_log_records').with_args(
+        'foo: Error running actions for repository',
-        'foo: Error running actions for repository', OSError
+        OSError,
-    ).and_return(expected_results[:1]).with_args(
+        levelno=logging.WARNING,
-        'foo: Error running actions for repository', OSError
+        log_command_error_output=True,
-    ).and_return(
+    ).and_return([flexmock()])
-        expected_results[1:]
+    error_logs = [flexmock()]
-    ).twice()
+    flexmock(module).should_receive('log_error_records').with_args(
+        'foo: Error running actions for repository', OSError,
+    ).and_return(error_logs)
     config = {'location': {'repositories': ['foo']}, 'storage': {'retries': 1}}
     arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()}
     results = list(module.run_configuration('test.yaml', config, arguments))
-    assert results == expected_results
+    assert results == error_logs
 
 
 def test_run_repos_ordered():
@@ -261,10 +262,10 @@ def test_run_repos_ordered():
     flexmock(module.command).should_receive('execute_hook')
     flexmock(module).should_receive('run_actions').and_raise(OSError).times(2)
     expected_results = [flexmock(), flexmock()]
-    flexmock(module).should_receive('make_error_log_records').with_args(
+    flexmock(module).should_receive('log_error_records').with_args(
         'foo: Error running actions for repository', OSError
     ).and_return(expected_results[:1]).ordered()
-    flexmock(module).should_receive('make_error_log_records').with_args(
+    flexmock(module).should_receive('log_error_records').with_args(
         'bar: Error running actions for repository', OSError
     ).and_return(expected_results[1:]).ordered()
     config = {'location': {'repositories': ['foo', 'bar']}}
@@ -278,23 +279,30 @@ def test_run_configuration_retries_round_robbin():
     flexmock(module.borg_version).should_receive('local_borg_version').and_return(flexmock())
     flexmock(module.command).should_receive('execute_hook')
     flexmock(module).should_receive('run_actions').and_raise(OSError).times(4)
-    expected_results = [flexmock(), flexmock(), flexmock(), flexmock()]
+    flexmock(module).should_receive('log_error_records').with_args(
-    flexmock(module).should_receive('make_error_log_records').with_args(
+        'foo: Error running actions for repository',
+        OSError,
+        levelno=logging.WARNING,
+        log_command_error_output=True,
+    ).and_return([flexmock()]).ordered()
+    flexmock(module).should_receive('log_error_records').with_args(
+        'bar: Error running actions for repository',
+        OSError,
+        levelno=logging.WARNING,
+        log_command_error_output=True,
+    ).and_return([flexmock()]).ordered()
+    foo_error_logs = [flexmock()]
+    flexmock(module).should_receive('log_error_records').with_args(
         'foo: Error running actions for repository', OSError
-    ).and_return(expected_results[0:1]).ordered()
+    ).and_return(foo_error_logs).ordered()
-    flexmock(module).should_receive('make_error_log_records').with_args(
+    bar_error_logs = [flexmock()]
+    flexmock(module).should_receive('log_error_records').with_args(
         'bar: Error running actions for repository', OSError
-    ).and_return(expected_results[1:2]).ordered()
+    ).and_return(bar_error_logs).ordered()
-    flexmock(module).should_receive('make_error_log_records').with_args(
-        'foo: Error running actions for repository', OSError
-    ).and_return(expected_results[2:3]).ordered()
-    flexmock(module).should_receive('make_error_log_records').with_args(
-        'bar: Error running actions for repository', OSError
-    ).and_return(expected_results[3:4]).ordered()
     config = {'location': {'repositories': ['foo', 'bar']}, 'storage': {'retries': 1}}
     arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()}
     results = list(module.run_configuration('test.yaml', config, arguments))
-    assert results == expected_results
+    assert results == foo_error_logs + bar_error_logs
 
 
 def test_run_configuration_retries_one_passes():
@@ -304,20 +312,26 @@ def test_run_configuration_retries_one_passes():
     flexmock(module).should_receive('run_actions').and_raise(OSError).and_raise(OSError).and_return(
         []
     ).and_raise(OSError).times(4)
-    expected_results = [flexmock(), flexmock(), flexmock()]
+    flexmock(module).should_receive('log_error_records').with_args(
-    flexmock(module).should_receive('make_error_log_records').with_args(
+        'foo: Error running actions for repository',
-        'foo: Error running actions for repository', OSError
+        OSError,
-    ).and_return(expected_results[0:1]).ordered()
+        levelno=logging.WARNING,
-    flexmock(module).should_receive('make_error_log_records').with_args(
+        log_command_error_output=True,
+    ).and_return([flexmock()]).ordered()
+    flexmock(module).should_receive('log_error_records').with_args(
+        'bar: Error running actions for repository',
+        OSError,
+        levelno=logging.WARNING,
+        log_command_error_output=True,
+    ).and_return(flexmock()).ordered()
+    error_logs = [flexmock()]
+    flexmock(module).should_receive('log_error_records').with_args(
         'bar: Error running actions for repository', OSError
-    ).and_return(expected_results[1:2]).ordered()
+    ).and_return(error_logs).ordered()
-    flexmock(module).should_receive('make_error_log_records').with_args(
-        'bar: Error running actions for repository', OSError
-    ).and_return(expected_results[2:3]).ordered()
     config = {'location': {'repositories': ['foo', 'bar']}, 'storage': {'retries': 1}}
     arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()}
     results = list(module.run_configuration('test.yaml', config, arguments))
-    assert results == expected_results
+    assert results == error_logs
 
 
 def test_run_configuration_retry_wait():
@@ -325,29 +339,38 @@ def test_run_configuration_retry_wait():
     flexmock(module.borg_version).should_receive('local_borg_version').and_return(flexmock())
     flexmock(module.command).should_receive('execute_hook')
     flexmock(module).should_receive('run_actions').and_raise(OSError).times(4)
-    expected_results = [flexmock(), flexmock(), flexmock(), flexmock()]
+    flexmock(module).should_receive('log_error_records').with_args(
-    flexmock(module).should_receive('make_error_log_records').with_args(
+        'foo: Error running actions for repository',
-        'foo: Error running actions for repository', OSError
+        OSError,
-    ).and_return(expected_results[0:1]).ordered()
+        levelno=logging.WARNING,
+        log_command_error_output=True,
+    ).and_return([flexmock()]).ordered()
 
     flexmock(time).should_receive('sleep').with_args(10).and_return().ordered()
-    flexmock(module).should_receive('make_error_log_records').with_args(
+    flexmock(module).should_receive('log_error_records').with_args(
-        'foo: Error running actions for repository', OSError
+        'foo: Error running actions for repository',
-    ).and_return(expected_results[1:2]).ordered()
+        OSError,
+        levelno=logging.WARNING,
+        log_command_error_output=True,
+    ).and_return([flexmock()]).ordered()
 
     flexmock(time).should_receive('sleep').with_args(20).and_return().ordered()
-    flexmock(module).should_receive('make_error_log_records').with_args(
+    flexmock(module).should_receive('log_error_records').with_args(
-        'foo: Error running actions for repository', OSError
+        'foo: Error running actions for repository',
-    ).and_return(expected_results[2:3]).ordered()
+        OSError,
+        levelno=logging.WARNING,
+        log_command_error_output=True,
+    ).and_return([flexmock()]).ordered()
 
     flexmock(time).should_receive('sleep').with_args(30).and_return().ordered()
-    flexmock(module).should_receive('make_error_log_records').with_args(
+    error_logs = [flexmock()]
+    flexmock(module).should_receive('log_error_records').with_args(
         'foo: Error running actions for repository', OSError
-    ).and_return(expected_results[3:4]).ordered()
+    ).and_return(error_logs).ordered()
     config = {'location': {'repositories': ['foo']}, 'storage': {'retries': 3, 'retry_wait': 10}}
     arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()}
     results = list(module.run_configuration('test.yaml', config, arguments))
-    assert results == expected_results
+    assert results == error_logs
 
 
 def test_run_configuration_retries_timeout_multiple_repos():
@@ -357,29 +380,35 @@ def test_run_configuration_retries_timeout_multiple_repos():
     flexmock(module).should_receive('run_actions').and_raise(OSError).and_raise(OSError).and_return(
         []
     ).and_raise(OSError).times(4)
-    expected_results = [flexmock(), flexmock(), flexmock()]
+    flexmock(module).should_receive('log_error_records').with_args(
-    flexmock(module).should_receive('make_error_log_records').with_args(
+        'foo: Error running actions for repository',
-        'foo: Error running actions for repository', OSError
+        OSError,
-    ).and_return(expected_results[0:1]).ordered()
+        levelno=logging.WARNING,
-    flexmock(module).should_receive('make_error_log_records').with_args(
+        log_command_error_output=True,
-        'bar: Error running actions for repository', OSError
+    ).and_return([flexmock()]).ordered()
-    ).and_return(expected_results[1:2]).ordered()
+    flexmock(module).should_receive('log_error_records').with_args(
+        'bar: Error running actions for repository',
+        OSError,
+        levelno=logging.WARNING,
+        log_command_error_output=True,
+    ).and_return([flexmock()]).ordered()
 
     # Sleep before retrying foo (and passing)
     flexmock(time).should_receive('sleep').with_args(10).and_return().ordered()
 
     # Sleep before retrying bar (and failing)
     flexmock(time).should_receive('sleep').with_args(10).and_return().ordered()
-    flexmock(module).should_receive('make_error_log_records').with_args(
+    error_logs = [flexmock()]
+    flexmock(module).should_receive('log_error_records').with_args(
         'bar: Error running actions for repository', OSError
-    ).and_return(expected_results[2:3]).ordered()
+    ).and_return(error_logs).ordered()
     config = {
         'location': {'repositories': ['foo', 'bar']},
         'storage': {'retries': 1, 'retry_wait': 10},
     }
     arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()}
     results = list(module.run_configuration('test.yaml', config, arguments))
-    assert results == expected_results
+    assert results == error_logs
 
 
 def test_load_configurations_collects_parsed_configurations():
@@ -421,48 +450,46 @@ def test_log_record_with_suppress_does_not_raise():
     module.log_record(levelno=1, foo='bar', baz='quux', suppress_log=True)
 
 
-def test_make_error_log_records_generates_output_logs_for_message_only():
+def test_log_error_records_generates_output_logs_for_message_only():
     flexmock(module).should_receive('log_record').replace_with(dict)
 
-    logs = tuple(module.make_error_log_records('Error'))
+    logs = tuple(module.log_error_records('Error'))
 
     assert {log['levelno'] for log in logs} == {logging.CRITICAL}
 
 
-def test_make_error_log_records_generates_output_logs_for_called_process_error():
+def test_log_error_records_generates_output_logs_for_called_process_error():
     flexmock(module).should_receive('log_record').replace_with(dict)
     flexmock(module.logger).should_receive('getEffectiveLevel').and_return(logging.WARNING)
 
     logs = tuple(
-        module.make_error_log_records(
+        module.log_error_records('Error', subprocess.CalledProcessError(1, 'ls', 'error output'))
-            'Error', subprocess.CalledProcessError(1, 'ls', 'error output')
-        )
     )
 
     assert {log['levelno'] for log in logs} == {logging.CRITICAL}
     assert any(log for log in logs if 'error output' in str(log))
 
 
-def test_make_error_log_records_generates_logs_for_value_error():
+def test_log_error_records_generates_logs_for_value_error():
     flexmock(module).should_receive('log_record').replace_with(dict)
 
-    logs = tuple(module.make_error_log_records('Error', ValueError()))
+    logs = tuple(module.log_error_records('Error', ValueError()))
 
     assert {log['levelno'] for log in logs} == {logging.CRITICAL}
 
 
-def test_make_error_log_records_generates_logs_for_os_error():
+def test_log_error_records_generates_logs_for_os_error():
     flexmock(module).should_receive('log_record').replace_with(dict)
 
-    logs = tuple(module.make_error_log_records('Error', OSError()))
+    logs = tuple(module.log_error_records('Error', OSError()))
 
     assert {log['levelno'] for log in logs} == {logging.CRITICAL}
 
 
-def test_make_error_log_records_generates_nothing_for_other_error():
+def test_log_error_records_generates_nothing_for_other_error():
     flexmock(module).should_receive('log_record').replace_with(dict)
 
-    logs = tuple(module.make_error_log_records('Error', KeyError()))
+    logs = tuple(module.log_error_records('Error', KeyError()))
 
     assert logs == ()
 
@@ -519,7 +546,7 @@ def test_collect_configuration_run_summary_logs_extract_with_repository_error():
         ValueError
     )
     expected_logs = (flexmock(),)
-    flexmock(module).should_receive('make_error_log_records').and_return(expected_logs)
+    flexmock(module).should_receive('log_error_records').and_return(expected_logs)
     arguments = {'extract': flexmock(repository='repo')}
 
     logs = tuple(
@@ -546,7 +573,7 @@ def test_collect_configuration_run_summary_logs_mount_with_repository_error():
         ValueError
     )
     expected_logs = (flexmock(),)
-    flexmock(module).should_receive('make_error_log_records').and_return(expected_logs)
+    flexmock(module).should_receive('log_error_records').and_return(expected_logs)
     arguments = {'mount': flexmock(repository='repo')}
 
     logs = tuple(
@@ -559,7 +586,7 @@ def test_collect_configuration_run_summary_logs_mount_with_repository_error():
 def test_collect_configuration_run_summary_logs_missing_configs_error():
     arguments = {'global': flexmock(config_paths=[])}
     expected_logs = (flexmock(),)
-    flexmock(module).should_receive('make_error_log_records').and_return(expected_logs)
+    flexmock(module).should_receive('log_error_records').and_return(expected_logs)
 
     logs = tuple(module.collect_configuration_run_summary_logs({}, arguments=arguments))
 
@@ -569,7 +596,7 @@ def test_collect_configuration_run_summary_logs_missing_configs_error():
 def test_collect_configuration_run_summary_logs_pre_hook_error():
     flexmock(module.command).should_receive('execute_hook').and_raise(ValueError)
     expected_logs = (flexmock(),)
-    flexmock(module).should_receive('make_error_log_records').and_return(expected_logs)
+    flexmock(module).should_receive('log_error_records').and_return(expected_logs)
     arguments = {'create': flexmock(), 'global': flexmock(monitoring_verbosity=1, dry_run=False)}
 
     logs = tuple(
@@ -583,7 +610,7 @@ def test_collect_configuration_run_summary_logs_post_hook_error():
     flexmock(module.command).should_receive('execute_hook').and_return(None).and_raise(ValueError)
     flexmock(module).should_receive('run_configuration').and_return([])
     expected_logs = (flexmock(),)
-    flexmock(module).should_receive('make_error_log_records').and_return(expected_logs)
+    flexmock(module).should_receive('log_error_records').and_return(expected_logs)
     arguments = {'create': flexmock(), 'global': flexmock(monitoring_verbosity=1, dry_run=False)}
 
     logs = tuple(
@@ -598,7 +625,7 @@ def test_collect_configuration_run_summary_logs_for_list_with_archive_and_reposi
         ValueError
     )
     expected_logs = (flexmock(),)
-    flexmock(module).should_receive('make_error_log_records').and_return(expected_logs)
+    flexmock(module).should_receive('log_error_records').and_return(expected_logs)
     arguments = {'list': flexmock(repository='repo', archive='test')}
 
     logs = tuple(
@@ -624,7 +651,7 @@ def test_collect_configuration_run_summary_logs_run_configuration_error():
     flexmock(module).should_receive('run_configuration').and_return(
         [logging.makeLogRecord(dict(levelno=logging.CRITICAL, levelname='CRITICAL', msg='Error'))]
     )
-    flexmock(module).should_receive('make_error_log_records').and_return([])
+    flexmock(module).should_receive('log_error_records').and_return([])
     arguments = {}
 
     logs = tuple(
@@ -638,7 +665,7 @@ def test_collect_configuration_run_summary_logs_run_umount_error():
     flexmock(module.validate).should_receive('guard_configuration_contains_repository')
     flexmock(module).should_receive('run_configuration').and_return([])
     flexmock(module.borg_umount).should_receive('unmount_archive').and_raise(OSError)
-    flexmock(module).should_receive('make_error_log_records').and_return(
+    flexmock(module).should_receive('log_error_records').and_return(
         [logging.makeLogRecord(dict(levelno=logging.CRITICAL, levelname='CRITICAL', msg='Error'))]
     )
     arguments = {'umount': flexmock(mount_point='/mnt')}

tests/unit/test_signals.py

@@ -0,0 +1,40 @@
+from flexmock import flexmock
+
+from borgmatic import signals as module
+
+
+def test_handle_signal_forwards_to_subprocesses():
+    signal_number = 100
+    frame = flexmock(f_back=flexmock(f_code=flexmock(co_name='something')))
+    process_group = flexmock()
+    flexmock(module.os).should_receive('getpgrp').and_return(process_group)
+    flexmock(module.os).should_receive('killpg').with_args(process_group, signal_number).once()
+
+    module.handle_signal(signal_number, frame)
+
+
+def test_handle_signal_bails_on_recursion():
+    signal_number = 100
+    frame = flexmock(f_back=flexmock(f_code=flexmock(co_name='handle_signal')))
+    flexmock(module.os).should_receive('getpgrp').never()
+    flexmock(module.os).should_receive('killpg').never()
+
+    module.handle_signal(signal_number, frame)
+
+
+def test_handle_signal_exits_on_sigterm():
+    signal_number = module.signal.SIGTERM
+    frame = flexmock(f_back=flexmock(f_code=flexmock(co_name='something')))
+    flexmock(module.os).should_receive('getpgrp').and_return(flexmock)
+    flexmock(module.os).should_receive('killpg')
+    flexmock(module.sys).should_receive('exit').with_args(
+        module.EXIT_CODE_FROM_SIGNAL + signal_number
+    ).once()
+
+    module.handle_signal(signal_number, frame)
+
+
+def test_configure_signals_installs_signal_handlers():
+    flexmock(module.signal).should_receive('signal').at_least().once()
+
+    module.configure_signals()