When backups to one of several repositories fails, keep backing up to the other repositories (#144).

NEWS

@@ -1,3 +1,17 @@
+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:
+   https://torsion.org/borgmatic/docs/how-to/add-preparation-and-cleanup-steps-to-backups/
+
+1.3.20
+ * #205: More robust sample systemd service: boot delay, network dependency, lowered CPU/IO
+   priority, etc.
+ * #221: Fix "borgmatic create --progress" output so that it updates on the console in real-time.
+
 1.3.19
  * #219: Fix visibility of "borgmatic prune --stats" output.
 

borgmatic/borg/create.py

@@ -4,7 +4,7 @@ import logging
 import os
 import tempfile
 
-from borgmatic.execute import execute_command
+from borgmatic.execute import execute_command, execute_command_without_capture
 
 logger = logging.getLogger(__name__)
 
@@ -163,6 +163,12 @@ def create_archive(
         + sources
     )
 
+    # The progress output isn't compatible with captured and logged output, as progress messes with
+    # the terminal directly.
+    if progress:
+        execute_command_without_capture(full_command)
+        return
+
     if json:
         output_log_level = None
     elif stats:

borgmatic/borg/extract.py

@@ -1,6 +1,6 @@
 import logging
 
-from borgmatic.execute import execute_command
+from borgmatic.execute import execute_command, execute_command_without_capture
 
 logger = logging.getLogger(__name__)
 
@@ -83,4 +83,10 @@ def extract_archive(
         + (tuple(restore_paths) if restore_paths else ())
     )
 
+    # The progress output isn't compatible with captured and logged output, as progress messes with
+    # the terminal directly.
+    if progress:
+        execute_command_without_capture(full_command)
+        return
+
     execute_command(full_command)

borgmatic/borg/init.py

@@ -1,7 +1,7 @@
 import logging
 import subprocess
 
-from borgmatic.execute import BORG_ERROR_EXIT_CODE, execute_command
+from borgmatic.execute import execute_command, execute_command_without_capture
 
 logger = logging.getLogger(__name__)
 
@@ -45,8 +45,4 @@ def initialize_repository(
     )
 
     # Don't use execute_command() here because it doesn't support interactive prompts.
-    try:
+    execute_command_without_capture(init_command)
-        subprocess.check_call(init_command)
-    except subprocess.CalledProcessError as error:
-        if error.returncode >= BORG_ERROR_EXIT_CODE:
-            raise

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,13 @@ def run_configuration(config_filename, config, arguments):  # pragma: no cover
     )
     global_arguments = arguments['global']
 
-    try:
+    local_path = location.get('local_path', 'borg')
-        local_path = location.get('local_path', 'borg')
+    remote_path = location.get('remote_path')
-        remote_path = location.get('remote_path')
+    borg_environment.initialize(storage)
-        borg_environment.initialize(storage)
+    encountered_error = False
 
-        if 'create' in arguments:
+    if 'create' in arguments:
+        try:
             hook.execute_hook(
                 hooks.get('before_backup'),
                 hooks.get('umask'),
@@ -55,20 +59,33 @@ def run_configuration(config_filename, config, arguments):  # pragma: no cover
                 'pre-backup',
                 global_arguments.dry_run,
             )
-
+        except (OSError, CalledProcessError) as error:
-        for repository_path in location['repositories']:
+            encountered_error = True
-            yield from run_actions(
+            yield from make_error_log_records(
-                arguments=arguments,
+                '{}: Error running pre-backup hook'.format(config_filename), error
-                location=location,
-                storage=storage,
-                retention=retention,
-                consistency=consistency,
-                local_path=local_path,
-                remote_path=remote_path,
-                repository_path=repository_path,
             )
 
-        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 = True
+                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 +93,25 @@ def run_configuration(config_filename, config, arguments):  # pragma: no cover
                 'post-backup',
                 global_arguments.dry_run,
             )
-    except (OSError, CalledProcessError):
+        except (OSError, CalledProcessError) as error:
-        hook.execute_hook(
+            encountered_error = True
-            hooks.get('on_error'),
+            yield from make_error_log_records(
-            hooks.get('umask'),
+                '{}: Error running post-backup hook'.format(config_filename), error
-            config_filename,
+            )
-            'on-error',
+
-            global_arguments.dry_run,
+    if encountered_error:
-        )
+        try:
-        raise
+            hook.execute_hook(
+                hooks.get('on_error'),
+                hooks.get('umask'),
+                config_filename,
+                'on-error',
+                global_arguments.dry_run,
+            )
+        except (OSError, CalledProcessError) as error:
+            yield from make_error_log_records(
+                '{}: Error running on-error hook'.format(config_filename), error
+            )
 
 
 def run_actions(
@@ -231,6 +258,38 @@ def load_configurations(config_filenames):
     return (configs, logs)
 
 
+def make_error_log_records(message, error=None):
+    '''
+    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:
+        yield logging.makeLogRecord(
+            dict(levelno=logging.CRITICAL, levelname='CRITICAL', msg=message)
+        )
+        yield logging.makeLogRecord(
+            dict(levelno=logging.CRITICAL, levelname='CRITICAL', msg=error.output)
+        )
+        yield logging.makeLogRecord(dict(levelno=logging.CRITICAL, levelname='CRITICAL', msg=error))
+    except (ValueError, OSError) as error:
+        yield logging.makeLogRecord(
+            dict(levelno=logging.CRITICAL, levelname='CRITICAL', msg=message)
+        )
+        yield logging.makeLogRecord(dict(levelno=logging.CRITICAL, levelname='CRITICAL', 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.
+        pass
+
+
 def collect_configuration_run_summary_logs(configs, arguments):
     '''
     Given a dict of configuration filename to corresponding parsed configuration, and parsed
@@ -253,16 +312,42 @@ def collect_configuration_run_summary_logs(configs, arguments):
         try:
             validate.guard_configuration_contains_repository(repository, configs)
         except ValueError as error:
-            yield logging.makeLogRecord(
+            yield from make_error_log_records(str(error))
-                dict(levelno=logging.CRITICAL, levelname='CRITICAL', msg=error)
+            return
-            )
+
+    if not configs:
+        yield from make_error_log_records(
+            '{}: No configuration files found'.format(' '.join(arguments['global'].config_paths))
+        )
+        return
+
+    if 'create' in arguments:
+        try:
+            for config_filename, config in configs.items():
+                hooks = config.get('hooks', {})
+                hook.execute_hook(
+                    hooks.get('before_everything'),
+                    hooks.get('umask'),
+                    config_filename,
+                    'pre-everything',
+                    arguments['global'].dry_run,
+                )
+        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:
+        results = list(run_configuration(config_filename, config, arguments))
-            json_results.extend(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,
@@ -270,45 +355,25 @@ def collect_configuration_run_summary_logs(configs, arguments):
                     msg='{}: Successfully ran configuration file'.format(config_filename),
                 )
             )
-        except CalledProcessError as error:
+            if results:
-            yield logging.makeLogRecord(
+                json_results.extend(results)
-                dict(
-                    levelno=logging.CRITICAL,
-                    levelname='CRITICAL',
-                    msg='{}: Error running configuration file'.format(config_filename),
-                )
-            )
-            yield logging.makeLogRecord(
-                dict(levelno=logging.CRITICAL, levelname='CRITICAL', msg=error.output)
-            )
-            yield logging.makeLogRecord(
-                dict(levelno=logging.CRITICAL, levelname='CRITICAL', msg=error)
-            )
-        except (ValueError, OSError) as error:
-            yield logging.makeLogRecord(
-                dict(
-                    levelno=logging.CRITICAL,
-                    levelname='CRITICAL',
-                    msg='{}: Error running configuration file'.format(config_filename),
-                )
-            )
-            yield logging.makeLogRecord(
-                dict(levelno=logging.CRITICAL, levelname='CRITICAL', msg=error)
-            )
 
     if json_results:
         sys.stdout.write(json.dumps(json_results))
 
-    if not configs:
+    if 'create' in arguments:
-        yield logging.makeLogRecord(
+        try:
-            dict(
+            for config_filename, config in configs.items():
-                levelno=logging.CRITICAL,
+                hooks = config.get('hooks', {})
-                levelname='CRITICAL',
+                hook.execute_hook(
-                msg='{}: No configuration files found'.format(
+                    hooks.get('after_everything'),
-                    ' '.join(arguments['global'].config_paths)
+                    hooks.get('umask'),
-                ),
+                    config_filename,
-            )
+                    'post-everything',
-        )
+                    arguments['global'].dry_run,
+                )
+        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/config/schema.yaml

@@ -337,31 +337,52 @@ map:
                 example: false
     hooks:
         desc: |
-            Shell commands or scripts to execute before and after a backup or if an error has occurred.
+            Shell commands or scripts to execute at various points during a borgmatic run.
-            IMPORTANT: All provided commands and scripts are executed with user permissions of borgmatic.
+            IMPORTANT: All provided commands and scripts are executed with user permissions of
-            Do not forget to set secure permissions on this file as well as on any script listed (chmod 0700) to
+            borgmatic. Do not forget to set secure permissions on this configuration file (chmod
-            prevent potential shell injection or privilege escalation.
+            0600) as well as on any script called from a hook (chmod 0700) to prevent potential
+            shell injection or privilege escalation.
         map:
             before_backup:
                 seq:
                     - type: str
-                desc: List of one or more shell commands or scripts to execute before creating a backup.
+                desc: |
+                    List of one or more shell commands or scripts to execute before creating a
+                    backup, run once per configuration file.
                 example:
-                    - echo "Starting a backup job."
+                    - echo "Starting a backup."
             after_backup:
                 seq:
                     - type: str
-                desc: List of one or more shell commands or scripts to execute after creating a backup.
+                desc: |
+                    List of one or more shell commands or scripts to execute after creating a
+                    backup, run once per configuration file.
                 example:
-                    - echo "Backup created."
+                    - echo "Created a backup."
             on_error:
                 seq:
                     - type: str
                 desc: |
                     List of one or more shell commands or scripts to execute when an exception occurs
-                    during a backup or when running a hook.
+                    during a backup or when running a before_backup or after_backup hook.
                 example:
-                    - echo "Error while creating a backup or running a hook."
+                    - echo "Error while creating a backup or running a backup hook."
+            before_everything:
+                seq:
+                    - type: str
+                desc: |
+                    List of one or more shell commands or scripts to execute before running all
+                    actions (if one of them is "create"), run once before all configuration files.
+                example:
+                    - echo "Starting actions."
+            after_everything:
+                seq:
+                    - type: str
+                desc: |
+                    List of one or more shell commands or scripts to execute after running all
+                    actions (if one of them is "create"), run once after all configuration files.
+                example:
+                    - echo "Completed actions."
             umask:
                 type: scalar
                 desc: Umask used when executing hooks. Defaults to the umask that borgmatic is run with.

borgmatic/execute.py

@@ -53,6 +53,8 @@ def execute_command(full_command, output_log_level=logging.INFO, shell=False):
     Execute the given command (a sequence of command/argument strings) and log its output at the
     given log level. If output log level is None, instead capture and return the output. If
     shell is True, execute the command within a shell.
+
+    Raise subprocesses.CalledProcessError if an error occurs while running the command.
     '''
     logger.debug(' '.join(full_command))
 
@@ -61,3 +63,18 @@ def execute_command(full_command, output_log_level=logging.INFO, shell=False):
         return output.decode() if output is not None else None
     else:
         execute_and_log_output(full_command, output_log_level, shell=shell)
+
+
+def execute_command_without_capture(full_command):
+    '''
+    Execute the given command (a sequence of command/argument strings), but don't capture or log its
+    output in any way. This is necessary for commands that monkey with the terminal (e.g. progress
+    display) or provide interactive prompts.
+    '''
+    logger.debug(' '.join(full_command))
+
+    try:
+        subprocess.check_call(full_command)
+    except subprocess.CalledProcessError as error:
+        if error.returncode >= BORG_ERROR_EXIT_CODE:
+            raise

borgmatic/hook.py

@@ -13,6 +13,7 @@ def execute_hook(commands, umask, config_filename, description, dry_run):
     if this is a dry run.
 
     Raise ValueError if the umask cannot be parsed.
+    Raise subprocesses.CalledProcessError if an error occurs in a hook.
     '''
     if not commands:
         logger.debug('{}: No commands to run for {} hook'.format(config_filename, description))

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

@@ -20,22 +20,47 @@ hooks:
         - rm /to/file.sql
 ```
 
-borgmatic hooks run once per configuration file. `before_backup` hooks run
+The `before_backup` and `after_backup` hooks each run once per configuration
-prior to backups of all repositories. `after_backup` hooks run afterwards, but
+file. `before_backup` hooks run prior to backups of all repositories in a
-not if an error occurs in a previous hook or in the backups themselves.
+configuration file, right before the `create` action. `after_backup` hooks run
+afterwards, but not if an error occurs in a previous hook or in the backups
+themselves.
 
+You can also use `before_everything` and `after_everything` hooks to perform
+global setup or cleanup:
+
+```yaml
+hooks:
+    before_everything:
+        - set-up-stuff-globally
+    after_everything:
+        - clean-up-stuff-globally
+```
+
+`before_everything` hooks collected from all borgmatic configuration files run
+once before all configuration files (prior to all actions), but only if there
+is a `create` action. An error encountered during a `before_everything` hook
+causes borgmatic to exit without creating backups.
+
+`after_everything` hooks run once after all configuration files and actions,
+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 another hook. Here's an example configuration:
+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 hook."
+        - 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.
+
 ## Hook output
 
 Any output produced by your hooks shows up both at the console and in syslog
@@ -48,7 +73,8 @@ your backups</a>.
 An important security note about hooks: borgmatic executes all hook commands
 with the user permissions of borgmatic itself. So to prevent potential shell
 injection or privilege escalation, do not forget to set secure permissions
-(`chmod 0700`) on borgmatic configuration files and scripts invoked by hooks.
+on borgmatic configuration files (`chmod 0600`) and scripts (`chmod 0700`)
+invoked by hooks.
 
 
 ## Related documentation

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

@@ -20,6 +20,16 @@ Or, for even more progress and debug spew:
 borgmatic --verbosity 2
 ```
 
+## Backup summary
+
+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:
+
+```bash
+borgmatic --stats
+```
+
 ## Existing backups
 
 Borgmatic provides convenient flags for Borg's

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

@@ -7,11 +7,11 @@ To get up and running, first [install
 Borg](https://borgbackup.readthedocs.io/en/stable/installation.html), at
 least version 1.1.
 
-Borgmatic consumes configurations in `/etc/borgmatic/` and `/etc/borgmatic.d/`
+By default, borgmatic looks for its configuration files in `/etc/borgmatic/`
-by default. Therefore, we show how to install borgmatic for the root user which
+and `/etc/borgmatic.d/`, where the root user typically has read access.
-will have access permissions for these locations by default.
 
-Run the following commands to download and install borgmatic:
+So, to download and install borgmatic as the root user, run the following
+commands:
 
 ```bash
 sudo pip3 install --user --upgrade borgmatic
@@ -39,6 +39,7 @@ borgmatic:
  * [OpenBSD](http://ports.su/sysutils/borgmatic)
  * [openSUSE](https://software.opensuse.org/package/borgmatic)
  * [stand-alone binary](https://github.com/cmarquardt/borgmatic-binary)
+ * [virtualenv](https://virtualenv.pypa.io/en/stable/)
 
 
 ## Hosting providers

sample/cron-alpine/borgmatic

@@ -1,3 +0,0 @@
-# You can drop this file into /etc/cron.d/ to run borgmatic nightly.
-
-0 3 * * * PATH=$PATH:/usr/bin /root/.local/bin/borgmatic

sample/cron/borgmatic

@@ -1,3 +1,3 @@
 # You can drop this file into /etc/cron.d/ to run borgmatic nightly.
 
-0 3 * * * root PATH=$PATH:/usr/local/bin /root/.local/bin/borgmatic
+0 3 * * * root PATH=$PATH:/usr/bin:/usr/local/bin /root/.local/bin/borgmatic --syslog-verbosity 1

sample/systemd/borgmatic.service

@@ -1,7 +1,22 @@
 [Unit]
 Description=borgmatic backup
+Wants=network-online.target
+After=network-online.target
+ConditionACPower=true
 
 [Service]
 Type=oneshot
-ExecStart=/root/.local/bin/borgmatic
+
+# Lower CPU and I/O priority.
+Nice=19
+CPUSchedulingPolicy=batch
+IOSchedulingClass=best-effort
+IOSchedulingPriority=7
+IOWeight=100
+
+Restart=no
 LogRateLimitIntervalSec=0
+
+# Delay start to prevent backups running during boot.
+ExecStartPre=sleep 1m
+ExecStart=systemd-inhibit --who="borgmatic" --why="Prevent interrupting scheduled backup" /root/.local/bin/borgmatic --syslog-verbosity 1

setup.py

@@ -1,6 +1,6 @@
 from setuptools import find_packages, setup
 
-VERSION = '1.3.19'
+VERSION = '1.3.22'
 
 
 setup(

tests/unit/borg/test_create.py

@@ -758,6 +758,29 @@ def test_create_archive_with_stats_calls_borg_with_stats_parameter():
     )
 
 
+def test_create_archive_with_progress_calls_borg_with_progress_parameter():
+    flexmock(module).should_receive('_expand_directories').and_return(('foo', 'bar'))
+    flexmock(module).should_receive('_expand_home_directories').and_return(())
+    flexmock(module).should_receive('_write_pattern_file').and_return(None)
+    flexmock(module).should_receive('_make_pattern_flags').and_return(())
+    flexmock(module).should_receive('_make_exclude_flags').and_return(())
+    flexmock(module).should_receive('execute_command_without_capture').with_args(
+        ('borg', 'create', '--progress') + ARCHIVE_WITH_PATHS
+    )
+
+    module.create_archive(
+        dry_run=False,
+        repository='repo',
+        location_config={
+            'source_directories': ['foo', 'bar'],
+            'repositories': ['repo'],
+            'exclude_patterns': None,
+        },
+        storage_config={},
+        progress=True,
+    )
+
+
 def test_create_archive_with_json_calls_borg_with_json_parameter():
     flexmock(module).should_receive('_expand_directories').and_return(('foo', 'bar'))
     flexmock(module).should_receive('_expand_home_directories').and_return(())

tests/unit/borg/test_extract.py

@@ -195,7 +195,9 @@ def test_extract_archive_calls_borg_with_dry_run_parameter():
 
 
 def test_extract_archive_calls_borg_with_progress_parameter():
-    insert_execute_command_mock(('borg', 'extract', '--progress', 'repo::archive'))
+    flexmock(module).should_receive('execute_command_without_capture').with_args(
+        ('borg', 'extract', '--progress', 'repo::archive')
+    ).once()
 
     module.extract_archive(
         dry_run=False,

tests/unit/borg/test_init.py

@@ -23,8 +23,8 @@ def insert_info_command_not_found_mock():
 
 
 def insert_init_command_mock(init_command, **kwargs):
-    flexmock(module.subprocess).should_receive('check_call').with_args(
+    flexmock(module).should_receive('execute_command_without_capture').with_args(
-        init_command, **kwargs
+        init_command
     ).once()
 
 
@@ -35,18 +35,9 @@ def test_initialize_repository_calls_borg_with_parameters():
     module.initialize_repository(repository='repo', encryption_mode='repokey')
 
 
-def test_initialize_repository_does_not_raise_for_borg_init_warning():
-    insert_info_command_not_found_mock()
-    flexmock(module.subprocess).should_receive('check_call').and_raise(
-        module.subprocess.CalledProcessError(1, 'borg init')
-    )
-
-    module.initialize_repository(repository='repo', encryption_mode='repokey')
-
-
 def test_initialize_repository_raises_for_borg_init_error():
     insert_info_command_not_found_mock()
-    flexmock(module.subprocess).should_receive('check_call').and_raise(
+    flexmock(module).should_receive('execute_command_without_capture').and_raise(
         module.subprocess.CalledProcessError(2, 'borg init')
     )
 
@@ -56,7 +47,7 @@ def test_initialize_repository_raises_for_borg_init_error():
 
 def test_initialize_repository_skips_initialization_when_repository_already_exists():
     insert_info_command_found_mock()
-    flexmock(module.subprocess).should_receive('check_call').never()
+    flexmock(module).should_receive('execute_command_without_capture').never()
 
     module.initialize_repository(repository='repo', encryption_mode='repokey')
 

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,10 +109,46 @@ def test_load_configurations_logs_critical_for_parse_error():
     configs, logs = tuple(module.load_configurations(('test.yaml',)))
 
     assert configs == {}
-    assert any(log for log in logs if log.levelno == 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(
+            '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():
+    logs = tuple(module.make_error_log_records('Error', ValueError()))
+
+    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('Error', OSError()))
+
+    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('Error', KeyError()))
+
+    assert logs == ()
 
 
 def test_collect_configuration_run_summary_logs_info_for_success():
+    flexmock(module.hook).should_receive('execute_hook').never()
     flexmock(module).should_receive('run_configuration').and_return([])
     arguments = {}
 
@@ -35,7 +156,18 @@ def test_collect_configuration_run_summary_logs_info_for_success():
         module.collect_configuration_run_summary_logs({'test.yaml': {}}, arguments=arguments)
     )
 
-    assert all(log for log in logs if log.levelno == module.logging.INFO)
+    assert {log.levelno for log in logs} == {logging.INFO}
+
+
+def test_collect_configuration_run_summary_executes_hooks_for_create():
+    flexmock(module).should_receive('run_configuration').and_return([])
+    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} == {logging.INFO}
 
 
 def test_collect_configuration_run_summary_logs_info_for_success_with_extract():
@@ -47,33 +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 all(log for log in logs if log.levelno == 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 any(log for log in logs if log.levelno == module.logging.CRITICAL)
+    assert logs == expected_logs
 
 
-def test_collect_configuration_run_summary_logs_critical_for_list_with_archive_and_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)
+
+    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 logs == expected_logs
+
+
+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 expected_logs[0] in logs
+
+
+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 any(log for log in logs if log.levelno == module.logging.CRITICAL)
+    assert logs == expected_logs
 
 
 def test_collect_configuration_run_summary_logs_info_for_success_with_list():
@@ -84,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 all(log for log in logs if log.levelno == 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)
+    flexmock(module).should_receive('run_configuration').and_return(
-    arguments = {}
+        [logging.makeLogRecord(dict(levelno=logging.CRITICAL, levelname='CRITICAL', msg='Error'))]
-
-    logs = tuple(
-        module.collect_configuration_run_summary_logs({'test.yaml': {}}, arguments=arguments)
-    )
-
-    assert any(log for log in logs if log.levelno == 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')
     )
     arguments = {}
 
@@ -110,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 any(log for log in logs if log.levelno == 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_collect_configuration_run_summary_logs_outputs_merged_json_results():
@@ -126,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 any(log for log in logs if log.levelno == module.logging.CRITICAL)

tests/unit/test_execute.py

@@ -1,5 +1,6 @@
 import logging
 
+import pytest
 from flexmock import flexmock
 
 from borgmatic import execute as module
@@ -49,3 +50,28 @@ def test_execute_command_captures_output_with_shell():
     output = module.execute_command(full_command, output_log_level=None, shell=True)
 
     assert output == expected_output
+
+
+def test_execute_command_without_capture_does_not_raise_on_success():
+    flexmock(module.subprocess).should_receive('check_call').and_raise(
+        module.subprocess.CalledProcessError(0, 'borg init')
+    )
+
+    module.execute_command_without_capture(('borg', 'init'))
+
+
+def test_execute_command_without_capture_does_not_raise_on_warning():
+    flexmock(module.subprocess).should_receive('check_call').and_raise(
+        module.subprocess.CalledProcessError(1, 'borg init')
+    )
+
+    module.execute_command_without_capture(('borg', 'init'))
+
+
+def test_execute_command_without_capture_raises_on_error():
+    flexmock(module.subprocess).should_receive('check_call').and_raise(
+        module.subprocess.CalledProcessError(2, 'borg init')
+    )
+
+    with pytest.raises(module.subprocess.CalledProcessError):
+        module.execute_command_without_capture(('borg', 'init'))