More detailed error alerting via runtime context available in "on_error" hook (#174).

NEWS

@@ -1,3 +1,10 @@
+1.3.23
+ * #174: More detailed error alerting via runtime context available in "on_error" hook.
+
+1.3.22
+ * #144: When backups to one of several repositories fails, keep backing up to the other
+   repositories and report errors afterwards.
+
 1.3.21
  * #192: User-defined hooks for global setup or cleanup that run before/after all actions. See the
    documentation for more information:

borgmatic/commands/borgmatic.py

@@ -28,13 +28,16 @@ logger = logging.getLogger(__name__)
 LEGACY_CONFIG_PATH = '/etc/borgmatic/config'
 
 
-def run_configuration(config_filename, config, arguments):  # pragma: no cover
+def run_configuration(config_filename, config, arguments):
     '''
     Given a config filename, the corresponding parsed config dict, and command-line arguments as a
     dict from subparser name to a namespace of parsed arguments, execute its defined pruning,
     backups, consistency checks, and/or other actions.
 
-    Yield JSON output strings from executing any actions that produce JSON.
+    Yield a combination of:
+
+      * JSON output strings from successfully executing any actions that produce JSON
+      * logging.LogRecord instances containing errors from any actions or backup hooks that fail
     '''
     (location, storage, retention, consistency, hooks) = (
         config.get(section_name, {})
@@ -42,12 +45,14 @@ def run_configuration(config_filename, config, arguments):  # pragma: no cover
     )
     global_arguments = arguments['global']
 
-    try:
-        local_path = location.get('local_path', 'borg')
-        remote_path = location.get('remote_path')
-        borg_environment.initialize(storage)
+    local_path = location.get('local_path', 'borg')
+    remote_path = location.get('remote_path')
+    borg_environment.initialize(storage)
+    encountered_error = None
+    error_repository = ''
 
-        if 'create' in arguments:
+    if 'create' in arguments:
+        try:
             hook.execute_hook(
                 hooks.get('before_backup'),
                 hooks.get('umask'),
@@ -55,20 +60,34 @@ def run_configuration(config_filename, config, arguments):  # pragma: no cover
                 'pre-backup',
                 global_arguments.dry_run,
             )
-
-        for repository_path in location['repositories']:
-            yield from run_actions(
-                arguments=arguments,
-                location=location,
-                storage=storage,
-                retention=retention,
-                consistency=consistency,
-                local_path=local_path,
-                remote_path=remote_path,
-                repository_path=repository_path,
+        except (OSError, CalledProcessError) as error:
+            encountered_error = error
+            yield from make_error_log_records(
+                '{}: Error running pre-backup hook'.format(config_filename), error
             )
 
-        if 'create' in arguments:
+    if not encountered_error:
+        for repository_path in location['repositories']:
+            try:
+                yield from run_actions(
+                    arguments=arguments,
+                    location=location,
+                    storage=storage,
+                    retention=retention,
+                    consistency=consistency,
+                    local_path=local_path,
+                    remote_path=remote_path,
+                    repository_path=repository_path,
+                )
+            except (OSError, CalledProcessError) as error:
+                encountered_error = error
+                error_repository = repository_path
+                yield from make_error_log_records(
+                    '{}: Error running actions for repository'.format(repository_path), error
+                )
+
+    if 'create' in arguments and not encountered_error:
+        try:
             hook.execute_hook(
                 hooks.get('after_backup'),
                 hooks.get('umask'),
@@ -76,15 +95,28 @@ def run_configuration(config_filename, config, arguments):  # pragma: no cover
                 'post-backup',
                 global_arguments.dry_run,
             )
-    except (OSError, CalledProcessError):
-        hook.execute_hook(
-            hooks.get('on_error'),
-            hooks.get('umask'),
-            config_filename,
-            'on-error',
-            global_arguments.dry_run,
-        )
-        raise
+        except (OSError, CalledProcessError) as error:
+            encountered_error = error
+            yield from make_error_log_records(
+                '{}: Error running post-backup hook'.format(config_filename), error
+            )
+
+    if encountered_error:
+        try:
+            hook.execute_hook(
+                hooks.get('on_error'),
+                hooks.get('umask'),
+                config_filename,
+                'on-error',
+                global_arguments.dry_run,
+                repository=error_repository,
+                error=encountered_error,
+                output=getattr(encountered_error, 'output', ''),
+            )
+        except (OSError, CalledProcessError) as error:
+            yield from make_error_log_records(
+                '{}: Error running on-error hook'.format(config_filename), error
+            )
 
 
 def run_actions(
@@ -231,11 +263,17 @@ def load_configurations(config_filenames):
     return (configs, logs)
 
 
-def make_error_log_records(error, message):
+def make_error_log_records(message, error=None):
     '''
-    Given an exception object and error message text, yield a series of logging.LogRecord instances
-    with error summary information.
+    Given error message text and an optional exception object, yield a series of logging.LogRecord
+    instances with error summary information.
     '''
+    if not error:
+        yield logging.makeLogRecord(
+            dict(levelno=logging.CRITICAL, levelname='CRITICAL', msg=message)
+        )
+        return
+
     try:
         raise error
     except CalledProcessError as error:
@@ -279,25 +317,17 @@ def collect_configuration_run_summary_logs(configs, arguments):
         try:
             validate.guard_configuration_contains_repository(repository, configs)
         except ValueError as error:
-            yield logging.makeLogRecord(
-                dict(levelno=logging.CRITICAL, levelname='CRITICAL', msg=error)
-            )
+            yield from make_error_log_records(str(error))
             return
 
     if not configs:
-        yield logging.makeLogRecord(
-            dict(
-                levelno=logging.CRITICAL,
-                levelname='CRITICAL',
-                msg='{}: No configuration files found'.format(
-                    ' '.join(arguments['global'].config_paths)
-                ),
-            )
+        yield from make_error_log_records(
+            '{}: No configuration files found'.format(' '.join(arguments['global'].config_paths))
         )
         return
 
-    try:
-        if 'create' in arguments:
+    if 'create' in arguments:
+        try:
             for config_filename, config in configs.items():
                 hooks = config.get('hooks', {})
                 hook.execute_hook(
@@ -307,15 +337,22 @@ def collect_configuration_run_summary_logs(configs, arguments):
                     'pre-everything',
                     arguments['global'].dry_run,
                 )
-    except (CalledProcessError, ValueError, OSError) as error:
-        yield from make_error_log_records(error, 'Error running pre-everything hook')
-        return
+        except (CalledProcessError, ValueError, OSError) as error:
+            yield from make_error_log_records('Error running pre-everything hook', error)
+            return
 
     # Execute the actions corresponding to each configuration file.
     json_results = []
     for config_filename, config in configs.items():
-        try:
-            json_results.extend(list(run_configuration(config_filename, config, arguments)))
+        results = list(run_configuration(config_filename, config, arguments))
+        error_logs = tuple(result for result in results if isinstance(result, logging.LogRecord))
+
+        if error_logs:
+            yield from make_error_log_records(
+                '{}: Error running configuration file'.format(config_filename)
+            )
+            yield from error_logs
+        else:
             yield logging.makeLogRecord(
                 dict(
                     levelno=logging.INFO,
@@ -323,16 +360,14 @@ def collect_configuration_run_summary_logs(configs, arguments):
                     msg='{}: Successfully ran configuration file'.format(config_filename),
                 )
             )
-        except (CalledProcessError, ValueError, OSError) as error:
-            yield from make_error_log_records(
-                error, '{}: Error running configuration file'.format(config_filename)
-            )
+            if results:
+                json_results.extend(results)
 
     if json_results:
         sys.stdout.write(json.dumps(json_results))
 
-    try:
-        if 'create' in arguments:
+    if 'create' in arguments:
+        try:
             for config_filename, config in configs.items():
                 hooks = config.get('hooks', {})
                 hook.execute_hook(
@@ -342,8 +377,8 @@ def collect_configuration_run_summary_logs(configs, arguments):
                     'post-everything',
                     arguments['global'].dry_run,
                 )
-    except (CalledProcessError, ValueError, OSError) as error:
-        yield from make_error_log_records(error, 'Error running post-everything hook')
+        except (CalledProcessError, ValueError, OSError) as error:
+            yield from make_error_log_records('Error running post-everything hook', error)
 
 
 def exit_with_help_link():  # pragma: no cover

borgmatic/hook.py

@@ -6,12 +6,26 @@ from borgmatic import execute
 logger = logging.getLogger(__name__)
 
 
-def execute_hook(commands, umask, config_filename, description, dry_run):
+def interpolate_context(command, context):
+    '''
+    Given a single hook command and a dict of context names/values, interpolate the values by
+    "{name}" into the command and return the result.
+    '''
+    for name, value in context.items():
+        command = command.replace('{%s}' % name, str(value))
+
+    return command
+
+
+def execute_hook(commands, umask, config_filename, description, dry_run, **context):
     '''
     Given a list of hook commands to execute, a umask to execute with (or None), a config filename,
     a hook description, and whether this is a dry run, run the given commands. Or, don't run them
     if this is a dry run.
 
+    The context contains optional values interpolated by name into the hook commands. Currently,
+    this only applies to the on_error hook.
+
     Raise ValueError if the umask cannot be parsed.
     Raise subprocesses.CalledProcessError if an error occurs in a hook.
     '''
@@ -21,6 +35,9 @@ def execute_hook(commands, umask, config_filename, description, dry_run):
 
     dry_run_label = ' (dry run; not actually running hooks)' if dry_run else ''
 
+    context['configuration_filename'] = config_filename
+    commands = [interpolate_context(command, context) for command in commands]
+
     if len(commands) == 1:
         logger.info(
             '{}: Running command for {} hook{}'.format(config_filename, description, dry_run_label)

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

@@ -47,19 +47,10 @@ but only if there is a `create` action. It runs even if an error occurs during
 a backup or a backup hook, but not if an error occurs during a
 `before_everything` hook.
 
-## Error hooks
-
 borgmatic also runs `on_error` hooks if an error occurs, either when creating
-a backup or running a backup hook. Here's an example configuration:
-
-```yaml
-hooks:
-    on_error:
-        - echo "Error while creating a backup or running a backup hook."
-```
-
-Note however that borgmatic does not run `on_error` hooks if an error occurs
-within a `before_everything` or `after_everything` hook.
+a backup or running a backup hook. See the [error alerting
+documentation](https://torsion.org/borgmatic/docs/how-to/inspect-your-backups.md)
+for more information.
 
 ## Hook output
 

docs/how-to/inspect-your-backups.md

@@ -24,7 +24,7 @@ borgmatic --verbosity 2
 
 If you're less concerned with progress during a backup, and you just want to
 see the summary of archive statistics at the end, you can use the stats
-option:
+option when performing a backup:
 
 ```bash
 borgmatic --stats
@@ -82,6 +82,49 @@ Note that the [sample borgmatic systemd service
 file](https://torsion.org/borgmatic/docs/how-to/set-up-backups/#systemd)
 already has this rate limit disabled.
 
+## Error alerting
+
+When an error occurs during a backup, borgmatic can run configurable shell
+commands to fire off custom error notifications or take other actions, so you
+can get alerted as soon as something goes wrong. Here's a not-so-useful
+example:
+
+```yaml
+hooks:
+    on_error:
+        - echo "Error while creating a backup or running a backup hook."
+```
+
+The `on_error` hook supports interpolating particular runtime variables into
+the hook command. Here's an example that assumes you provide a separate shell
+script to handle the alerting:
+
+```yaml
+hooks:
+    on_error:
+        - send-text-message.sh "{configuration_filename}" "{repository}"
+```
+
+In this example, when the error occurs, borgmatic interpolates a few runtime
+values into the hook command: the borgmatic configuration filename, and the
+path of the repository. Here's the full set of supported variables you can use
+here:
+
+ * `configuration_filename`: borgmatic configuration filename in which the
+   error occurred
+ * `repository`: path of the repository in which the error occurred (may be
+   blank if the error occurs in a hook)
+ * `error`: the error message itself
+ * `output`: output of the command that failed (may be blank if an error
+   occurred without running a command)
+
+Note that borgmatic does not run `on_error` hooks if an error occurs within a
+`before_everything` or `after_everything` hook. For more about hooks, see the
+[borgmatic hooks
+documentation](https://torsion.org/borgmatic/docs/how-to/add-preparation-and-cleanup-steps-to-backups.md),
+especially the security information.
+
+
 ## Scripting borgmatic
 
 To consume the output of borgmatic in other software, you can include an
@@ -96,4 +139,5 @@ output only shows up at the console, and not in syslog.
 ## Related documentation
 
  * [Set up backups with borgmatic](https://torsion.org/borgmatic/docs/how-to/set-up-backups.md)
+ * [Add preparation and cleanup steps to backups](https://torsion.org/borgmatic/docs/how-to/add-preparation-and-cleanup-steps-to-backups.md)
  * [Develop on borgmatic](https://torsion.org/borgmatic/docs/how-to/develop-on-borgmatic.md)

setup.py

@@ -1,6 +1,6 @@
 from setuptools import find_packages, setup
 
-VERSION = '1.3.21'
+VERSION = '1.3.23'
 
 
 setup(

tests/unit/commands/test_borgmatic.py

@@ -1,3 +1,4 @@
+import logging
 import subprocess
 
 from flexmock import flexmock
@@ -5,6 +6,90 @@ from flexmock import flexmock
 from borgmatic.commands import borgmatic as module
 
 
+def test_run_configuration_runs_actions_for_each_repository():
+    flexmock(module.borg_environment).should_receive('initialize')
+    expected_results = [flexmock(), flexmock()]
+    flexmock(module).should_receive('run_actions').and_return(expected_results[:1]).and_return(
+        expected_results[1:]
+    )
+    config = {'location': {'repositories': ['foo', 'bar']}}
+    arguments = {'global': flexmock()}
+
+    results = list(module.run_configuration('test.yaml', config, arguments))
+
+    assert results == expected_results
+
+
+def test_run_configuration_executes_hooks_for_create_action():
+    flexmock(module.borg_environment).should_receive('initialize')
+    flexmock(module.hook).should_receive('execute_hook').twice()
+    flexmock(module).should_receive('run_actions').and_return([])
+    config = {'location': {'repositories': ['foo']}}
+    arguments = {'global': flexmock(dry_run=False), 'create': flexmock()}
+
+    list(module.run_configuration('test.yaml', config, arguments))
+
+
+def test_run_configuration_logs_actions_error():
+    flexmock(module.borg_environment).should_receive('initialize')
+    flexmock(module.hook).should_receive('execute_hook')
+    expected_results = [flexmock()]
+    flexmock(module).should_receive('make_error_log_records').and_return(expected_results)
+    flexmock(module).should_receive('run_actions').and_raise(OSError)
+    config = {'location': {'repositories': ['foo']}}
+    arguments = {'global': flexmock(dry_run=False)}
+
+    results = list(module.run_configuration('test.yaml', config, arguments))
+
+    assert results == expected_results
+
+
+def test_run_configuration_logs_pre_hook_error():
+    flexmock(module.borg_environment).should_receive('initialize')
+    flexmock(module.hook).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('run_actions').never()
+    config = {'location': {'repositories': ['foo']}}
+    arguments = {'global': flexmock(dry_run=False), 'create': flexmock()}
+
+    results = list(module.run_configuration('test.yaml', config, arguments))
+
+    assert results == expected_results
+
+
+def test_run_configuration_logs_post_hook_error():
+    flexmock(module.borg_environment).should_receive('initialize')
+    flexmock(module.hook).should_receive('execute_hook').and_return(None).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('run_actions').and_return([])
+    config = {'location': {'repositories': ['foo']}}
+    arguments = {'global': flexmock(dry_run=False), 'create': flexmock()}
+
+    results = list(module.run_configuration('test.yaml', config, arguments))
+
+    assert results == expected_results
+
+
+def test_run_configuration_logs_on_error_hook_error():
+    flexmock(module.borg_environment).should_receive('initialize')
+    flexmock(module.hook).should_receive('execute_hook').and_raise(OSError)
+    expected_results = [flexmock(), flexmock()]
+    flexmock(module).should_receive('make_error_log_records').and_return(
+        expected_results[:1]
+    ).and_return(expected_results[1:])
+    flexmock(module).should_receive('run_actions').and_raise(OSError)
+    config = {'location': {'repositories': ['foo']}}
+    arguments = {'global': flexmock(dry_run=False)}
+
+    results = list(module.run_configuration('test.yaml', config, arguments))
+
+    assert results == expected_results
+
+
 def test_load_configurations_collects_parsed_configurations():
     configuration = flexmock()
     other_configuration = flexmock()
@@ -24,34 +109,40 @@ def test_load_configurations_logs_critical_for_parse_error():
     configs, logs = tuple(module.load_configurations(('test.yaml',)))
 
     assert configs == {}
-    assert {log.levelno for log in logs} == {module.logging.CRITICAL}
+    assert {log.levelno for log in logs} == {logging.CRITICAL}
+
+
+def test_make_error_log_records_generates_output_logs_for_message_only():
+    logs = tuple(module.make_error_log_records('Error'))
+
+    assert {log.levelno for log in logs} == {logging.CRITICAL}
 
 
 def test_make_error_log_records_generates_output_logs_for_called_process_error():
     logs = tuple(
         module.make_error_log_records(
-            subprocess.CalledProcessError(1, 'ls', 'error output'), 'Error'
+            'Error', subprocess.CalledProcessError(1, 'ls', 'error output')
         )
     )
 
-    assert {log.levelno for log in logs} == {module.logging.CRITICAL}
+    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():
-    logs = tuple(module.make_error_log_records(ValueError(), 'Error'))
+    logs = tuple(module.make_error_log_records('Error', ValueError()))
 
-    assert {log.levelno for log in logs} == {module.logging.CRITICAL}
+    assert {log.levelno for log in logs} == {logging.CRITICAL}
 
 
 def test_make_error_log_records_generates_logs_for_os_error():
-    logs = tuple(module.make_error_log_records(OSError(), 'Error'))
+    logs = tuple(module.make_error_log_records('Error', OSError()))
 
-    assert {log.levelno for log in logs} == {module.logging.CRITICAL}
+    assert {log.levelno for log in logs} == {logging.CRITICAL}
 
 
 def test_make_error_log_records_generates_nothing_for_other_error():
-    logs = tuple(module.make_error_log_records(KeyError(), 'Error'))
+    logs = tuple(module.make_error_log_records('Error', KeyError()))
 
     assert logs == ()
 
@@ -65,7 +156,7 @@ def test_collect_configuration_run_summary_logs_info_for_success():
         module.collect_configuration_run_summary_logs({'test.yaml': {}}, arguments=arguments)
     )
 
-    assert {log.levelno for log in logs} == {module.logging.INFO}
+    assert {log.levelno for log in logs} == {logging.INFO}
 
 
 def test_collect_configuration_run_summary_executes_hooks_for_create():
@@ -76,7 +167,7 @@ def test_collect_configuration_run_summary_executes_hooks_for_create():
         module.collect_configuration_run_summary_logs({'test.yaml': {}}, arguments=arguments)
     )
 
-    assert {log.levelno for log in logs} == {module.logging.INFO}
+    assert {log.levelno for log in logs} == {logging.INFO}
 
 
 def test_collect_configuration_run_summary_logs_info_for_success_with_extract():
@@ -88,56 +179,74 @@ def test_collect_configuration_run_summary_logs_info_for_success_with_extract():
         module.collect_configuration_run_summary_logs({'test.yaml': {}}, arguments=arguments)
     )
 
-    assert {log.levelno for log in logs} == {module.logging.INFO}
+    assert {log.levelno for log in logs} == {logging.INFO}
 
 
-def test_collect_configuration_run_summary_logs_critical_for_extract_with_repository_error():
+def test_collect_configuration_run_summary_logs_extract_with_repository_error():
     flexmock(module.validate).should_receive('guard_configuration_contains_repository').and_raise(
         ValueError
     )
+    expected_logs = (flexmock(),)
+    flexmock(module).should_receive('make_error_log_records').and_return(expected_logs)
     arguments = {'extract': flexmock(repository='repo')}
 
     logs = tuple(
         module.collect_configuration_run_summary_logs({'test.yaml': {}}, arguments=arguments)
     )
 
-    assert {log.levelno for log in logs} == {module.logging.CRITICAL}
+    assert logs == expected_logs
 
 
-def test_collect_configuration_run_summary_logs_critical_for_pre_hook_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)
+
+    logs = tuple(module.collect_configuration_run_summary_logs({}, arguments=arguments))
+
+    assert logs == expected_logs
+
+
+def test_collect_configuration_run_summary_logs_pre_hook_error():
     flexmock(module.hook).should_receive('execute_hook').and_raise(ValueError)
+    expected_logs = (flexmock(),)
+    flexmock(module).should_receive('make_error_log_records').and_return(expected_logs)
     arguments = {'create': flexmock(), 'global': flexmock(dry_run=False)}
 
     logs = tuple(
         module.collect_configuration_run_summary_logs({'test.yaml': {}}, arguments=arguments)
     )
 
-    assert {log.levelno for log in logs} == {module.logging.CRITICAL}
+    assert logs == expected_logs
 
 
-def test_collect_configuration_run_summary_logs_critical_for_post_hook_error():
+def test_collect_configuration_run_summary_logs_post_hook_error():
     flexmock(module.hook).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)
     arguments = {'create': flexmock(), 'global': flexmock(dry_run=False)}
 
     logs = tuple(
         module.collect_configuration_run_summary_logs({'test.yaml': {}}, arguments=arguments)
     )
 
-    assert {log.levelno for log in logs} == {module.logging.INFO, module.logging.CRITICAL}
+    assert expected_logs[0] in logs
 
 
-def test_collect_configuration_run_summary_logs_critical_for_list_with_archive_and_repository_error():
+def test_collect_configuration_run_summary_logs_for_list_with_archive_and_repository_error():
     flexmock(module.validate).should_receive('guard_configuration_contains_repository').and_raise(
         ValueError
     )
+    expected_logs = (flexmock(),)
+    flexmock(module).should_receive('make_error_log_records').and_return(expected_logs)
     arguments = {'list': flexmock(repository='repo', archive='test')}
 
     logs = tuple(
         module.collect_configuration_run_summary_logs({'test.yaml': {}}, arguments=arguments)
     )
 
-    assert {log.levelno for log in logs} == {module.logging.CRITICAL}
+    assert logs == expected_logs
 
 
 def test_collect_configuration_run_summary_logs_info_for_success_with_list():
@@ -148,25 +257,13 @@ def test_collect_configuration_run_summary_logs_info_for_success_with_list():
         module.collect_configuration_run_summary_logs({'test.yaml': {}}, arguments=arguments)
     )
 
-    assert {log.levelno for log in logs} == {module.logging.INFO}
+    assert {log.levelno for log in logs} == {logging.INFO}
 
 
-def test_collect_configuration_run_summary_logs_critical_for_run_value_error():
+def test_collect_configuration_run_summary_logs_run_configuration_error():
     flexmock(module.validate).should_receive('guard_configuration_contains_repository')
-    flexmock(module).should_receive('run_configuration').and_raise(ValueError)
-    arguments = {}
-
-    logs = tuple(
-        module.collect_configuration_run_summary_logs({'test.yaml': {}}, arguments=arguments)
-    )
-
-    assert {log.levelno for log in logs} == {module.logging.CRITICAL}
-
-
-def test_collect_configuration_run_summary_logs_critical_including_output_for_run_process_error():
-    flexmock(module.validate).should_receive('guard_configuration_contains_repository')
-    flexmock(module).should_receive('run_configuration').and_raise(
-        subprocess.CalledProcessError(1, 'command', 'error output')
+    flexmock(module).should_receive('run_configuration').and_return(
+        [logging.makeLogRecord(dict(levelno=logging.CRITICAL, levelname='CRITICAL', msg='Error'))]
     )
     arguments = {}
 
@@ -174,8 +271,7 @@ def test_collect_configuration_run_summary_logs_critical_including_output_for_ru
         module.collect_configuration_run_summary_logs({'test.yaml': {}}, arguments=arguments)
     )
 
-    assert {log.levelno for log in logs} == {module.logging.CRITICAL}
-    assert any(log for log in logs if 'error output' in str(log))
+    assert {log.levelno for log in logs} == {logging.CRITICAL}
 
 
 def test_collect_configuration_run_summary_logs_outputs_merged_json_results():
@@ -190,12 +286,3 @@ def test_collect_configuration_run_summary_logs_outputs_merged_json_results():
             {'test.yaml': {}, 'test2.yaml': {}}, arguments=arguments
         )
     )
-
-
-def test_collect_configuration_run_summary_logs_critical_for_missing_configs():
-    flexmock(module).should_receive('run_configuration').and_return([])
-    arguments = {'global': flexmock(config_paths=[])}
-
-    logs = tuple(module.collect_configuration_run_summary_logs({}, arguments=arguments))
-
-    assert {log.levelno for log in logs} == {module.logging.CRITICAL}

tests/unit/test_hook.py

@@ -5,7 +5,24 @@ from flexmock import flexmock
 from borgmatic import hook as module
 
 
+def test_interpolate_context_passes_through_command_without_variable():
+    assert module.interpolate_context('ls', {'foo': 'bar'}) == 'ls'
+
+
+def test_interpolate_context_passes_through_command_with_unknown_variable():
+    assert module.interpolate_context('ls {baz}', {'foo': 'bar'}) == 'ls {baz}'
+
+
+def test_interpolate_context_interpolates_variables():
+    context = {'foo': 'bar', 'baz': 'quux'}
+
+    assert module.interpolate_context('ls {foo}{baz} {baz}', context) == 'ls barquux quux'
+
+
 def test_execute_hook_invokes_each_command():
+    flexmock(module).should_receive('interpolate_context').replace_with(
+        lambda command, context: command
+    )
     flexmock(module.execute).should_receive('execute_command').with_args(
         [':'], output_log_level=logging.WARNING, shell=True
     ).once()
@@ -14,6 +31,9 @@ def test_execute_hook_invokes_each_command():
 
 
 def test_execute_hook_with_multiple_commands_invokes_each_command():
+    flexmock(module).should_receive('interpolate_context').replace_with(
+        lambda command, context: command
+    )
     flexmock(module.execute).should_receive('execute_command').with_args(
         [':'], output_log_level=logging.WARNING, shell=True
     ).once()
@@ -25,6 +45,9 @@ def test_execute_hook_with_multiple_commands_invokes_each_command():
 
 
 def test_execute_hook_with_umask_sets_that_umask():
+    flexmock(module).should_receive('interpolate_context').replace_with(
+        lambda command, context: command
+    )
     flexmock(module.os).should_receive('umask').with_args(0o77).and_return(0o22).once()
     flexmock(module.os).should_receive('umask').with_args(0o22).once()
     flexmock(module.execute).should_receive('execute_command').with_args(
@@ -35,6 +58,9 @@ def test_execute_hook_with_umask_sets_that_umask():
 
 
 def test_execute_hook_with_dry_run_skips_commands():
+    flexmock(module).should_receive('interpolate_context').replace_with(
+        lambda command, context: command
+    )
     flexmock(module.execute).should_receive('execute_command').never()
 
     module.execute_hook([':', 'true'], None, 'config.yaml', 'pre-backup', dry_run=True)
@@ -45,6 +71,9 @@ def test_execute_hook_with_empty_commands_does_not_raise():
 
 
 def test_execute_hook_on_error_logs_as_error():
+    flexmock(module).should_receive('interpolate_context').replace_with(
+        lambda command, context: command
+    )
     flexmock(module.execute).should_receive('execute_command').with_args(
         [':'], output_log_level=logging.ERROR, shell=True
     ).once()