Bump version for release.

.gitea/workflows/build.yaml

@@ -17,6 +17,7 @@ jobs:
   docs:
     needs: [test]
     runs-on: host
+    if: gitea.event_name == 'push'
     env:
       IMAGE_NAME: projects.torsion.org/borgmatic-collective/borgmatic:docs
 

NEWS

@@ -1,3 +1,12 @@
+2.0.4
+ * #1072: Fix path rewriting for non-root patterns in the ZFS, Btrfs, and LVM hooks.
+ * #1073: Clarify the documentation about when an "after: error" command hook runs and how it
+   differs from other hooks:
+   https://torsion.org/borgmatic/docs/how-to/add-preparation-and-cleanup-steps-to-backups/
+ * #1075: Fix an incorrect warning about Borg placeholders being unsupported in a command hook.
+ * #1080: If the exact same "everything" command hook is present in multiple configuration files,
+   only run it once.
+
 2.0.3
  * #1065: Fix a regression in monitoring hooks in which an error pinged the finish state instead of
    the fail state.

borgmatic/actions/pattern.py

@@ -165,6 +165,29 @@ def expand_patterns(patterns, working_directory=None, skip_paths=None):
     )
 
 
+def get_existent_path_or_parent(path):
+    '''
+    Given a path, return it if it exists. Otherwise, return the longest parent directory of the path
+    that exists. Return None if none of these paths exist.
+
+    This is used below for finding an existent path prefix of pattern's path, which is necessary if
+    the path contain globs or other special characters that we don't want to try to interpret
+    (because we want to leave that responsibility to Borg).
+    '''
+    if path.startswith('/e2e/'):
+        return None
+
+    try:
+        return next(
+            candidate_path
+            for candidate_path in (path,)
+            + tuple(str(parent) for parent in pathlib.PurePath(path).parents)
+            if os.path.exists(candidate_path)
+        )
+    except StopIteration:
+        return None
+
+
 def device_map_patterns(patterns, working_directory=None):
     '''
     Given a sequence of borgmatic.borg.pattern.Pattern instances and an optional working directory,
@@ -174,23 +197,31 @@ def device_map_patterns(patterns, working_directory=None):
 
     This is handy for determining whether two different pattern paths are on the same filesystem
     (have the same device identifier).
+
+    This function only considers the start of a pattern's path—from the start of the path up until
+    there's a path component with a glob or other non-literal character. If there are no such
+    characters, the whole path is considered. The rationale is that it's not feasible for borgmatic
+    to interpret Borg's patterns to see which actual files (and therefore devices) they map to. So
+    for instance, a pattern with a path of "/var/log/*/data" would end up with its device set to the
+    device of "/var/log"—ignoring the "/*/data" part due to that glob.
+
+    The one exception is that if a regular expression pattern path starts with "^", that will get
+    stripped off for purposes of determining its device.
     '''
     return tuple(
         borgmatic.borg.pattern.Pattern(
             pattern.path,
             pattern.type,
             pattern.style,
-            device=pattern.device
-            or (
-                os.stat(full_path).st_dev
-                if pattern.type == borgmatic.borg.pattern.Pattern_type.ROOT
-                and os.path.exists(full_path)
-                else None
-            ),
+            device=pattern.device or (os.stat(existent_path).st_dev if existent_path else None),
             source=pattern.source,
         )
         for pattern in patterns
-        for full_path in (os.path.join(working_directory or '', pattern.path),)
+        for existent_path in (
+            get_existent_path_or_parent(
+                os.path.join(working_directory or '', pattern.path.lstrip('^'))
+            ),
+        )
     )
 
 

borgmatic/borg/create.py

@@ -69,7 +69,7 @@ def collect_special_file_paths(
     '''
     # Omit "--exclude-nodump" from the Borg dry run command, because that flag causes Borg to open
     # files including any named pipe we've created. And omit "--filter" because that can break the
-    # paths output parsing below such that path lines no longer start with th expected "- ".
+    # paths output parsing below such that path lines no longer start with the expected "- ".
     paths_output = execute_command_and_capture_output(
         flags.omit_flag_and_value(flags.omit_flag(create_command, '--exclude-nodump'), '--filter')
         + ('--dry-run', '--list'),

borgmatic/commands/borgmatic.py

@@ -893,17 +893,29 @@ def collect_configuration_run_summary_logs(configs, config_paths, arguments, log
         return
 
     try:
+        seen_command_hooks = []
+
         for config_filename, config in configs.items():
-            command.execute_hooks(
-                command.filter_hooks(
-                    config.get('commands'), before='everything', action_names=arguments.keys()
+            command_hooks = command.filter_hooks(
+                tuple(
+                    command_hook
+                    for command_hook in config.get('commands', ())
+                    if command_hook not in seen_command_hooks
                 ),
-                config.get('umask'),
-                borgmatic.config.paths.get_working_directory(config),
-                arguments['global'].dry_run,
-                configuration_filename=config_filename,
-                log_file=log_file_path or '',
+                before='everything',
+                action_names=arguments.keys(),
             )
+
+            if command_hooks:
+                command.execute_hooks(
+                    command_hooks,
+                    config.get('umask'),
+                    borgmatic.config.paths.get_working_directory(config),
+                    arguments['global'].dry_run,
+                    configuration_filename=config_filename,
+                    log_file=log_file_path or '',
+                )
+                seen_command_hooks += list(command_hooks)
     except (CalledProcessError, ValueError, OSError) as error:
         yield from log_error_records('Error running before everything hook', error)
         return
@@ -951,20 +963,30 @@ def collect_configuration_run_summary_logs(configs, config_paths, arguments, log
         sys.stdout.write(json.dumps(json_results))
 
     try:
+        seen_command_hooks = []
+
         for config_filename, config in configs.items():
-            command.execute_hooks(
-                command.filter_hooks(
-                    config.get('commands'),
-                    after='everything',
-                    action_names=arguments.keys(),
-                    state_names=['fail' if encountered_error else 'finish'],
+            command_hooks = command.filter_hooks(
+                tuple(
+                    command_hook
+                    for command_hook in config.get('commands', ())
+                    if command_hook not in seen_command_hooks
                 ),
-                config.get('umask'),
-                borgmatic.config.paths.get_working_directory(config),
-                arguments['global'].dry_run,
-                configuration_filename=config_filename,
-                log_file=log_file_path or '',
+                after='everything',
+                action_names=arguments.keys(),
+                state_names=['fail' if encountered_error else 'finish'],
             )
+
+            if command_hooks:
+                command.execute_hooks(
+                    command_hooks,
+                    config.get('umask'),
+                    borgmatic.config.paths.get_working_directory(config),
+                    arguments['global'].dry_run,
+                    configuration_filename=config_filename,
+                    log_file=log_file_path or '',
+                )
+                seen_command_hooks += list(command_hooks)
     except (CalledProcessError, ValueError, OSError) as error:
         yield from log_error_records('Error running after everything hook', error)
 

borgmatic/hooks/command.py

@@ -13,6 +13,19 @@ logger = logging.getLogger(__name__)
 
 
 SOFT_FAIL_EXIT_CODE = 75
+BORG_PLACEHOLDERS = {
+    '{hostname}',
+    '{fqdn}',
+    '{reverse-fqdn}',
+    '{now}',
+    '{utcnow}',
+    '{user}',
+    '{pid}',
+    '{borgversion}',
+    '{borgmajor}',
+    '{borgminor}',
+    '{borgpatch}',
+}
 
 
 def interpolate_context(hook_description, command, context):
@@ -23,10 +36,13 @@ def interpolate_context(hook_description, command, context):
     for name, value in context.items():
         command = command.replace(f'{{{name}}}', shlex.quote(str(value)))
 
-    for unsupported_variable in re.findall(r'{\w+}', command):
-        logger.warning(
-            f"Variable '{unsupported_variable}' is not supported in {hook_description} hook"
-        )
+    for unsupported_variable in re.findall(r'\{\w+\}', command):
+        # Warn about variables unknown to borgmatic, but don't warn if the variable name happens to
+        # be a Borg placeholder, as Borg should hopefully consume it.
+        if unsupported_variable not in BORG_PLACEHOLDERS:
+            logger.warning(
+                f'Variable "{unsupported_variable}" is not supported in the {hook_description} hook'
+            )
 
     return command
 

borgmatic/hooks/data_source/snapshot.py

@@ -8,9 +8,9 @@ def get_contained_patterns(parent_directory, candidate_patterns):
     '''
     Given a parent directory and a set of candidate patterns potentially inside it, get the subset
     of contained patterns for which the parent directory is actually the parent, a grandparent, the
-    very same directory, etc. The idea is if, say, /var/log and /var/lib are candidate pattern
-    paths, but there's a parent directory (logical volume, dataset, subvolume, etc.) at /var, then
-    /var is what we want to snapshot.
+    very same directory, etc. The idea is if, say, "/var/log" and "/var/lib" are candidate pattern
+    paths, but there's a parent directory (logical volume, dataset, subvolume, etc.) at "/var", then
+    "/var" is what we want to snapshot.
 
     If a parent directory and a candidate pattern are on different devices, skip the pattern. That's
     because any snapshot of a parent directory won't actually include "contained" directories if
@@ -18,8 +18,8 @@ def get_contained_patterns(parent_directory, candidate_patterns):
 
     For this function to work, a candidate pattern path can't have any globs or other non-literal
     characters in the initial portion of the path that matches the parent directory. For instance, a
-    parent directory of /var would match a candidate pattern path of /var/log/*/data, but not a
-    pattern path like /v*/log/*/data.
+    parent directory of "/var" would match a candidate pattern path of "/var/log/*/data", but not a
+    pattern path like "/v*/log/*/data".
 
     The one exception is that if a regular expression pattern path starts with "^", that will get
     stripped off for purposes of matching against a parent directory.

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

@@ -74,10 +74,6 @@ commands:
           - echo "After successful create!"
 ```
 
-Additionally, when command hooks run, they respect the `working_directory`
-option if it is configured, meaning that the hook commands are run in that
-directory.
-
 Each command in the `commands:` list has the following options:
 
  * `before` or `after`: Name for the point in borgmatic's execution that the commands should be run before or after, one of:
@@ -92,6 +88,13 @@ Each command in the `commands:` list has the following options:
     * `fail`: An error occurred.
  * `run`: List of one or more shell commands or scripts to run when this command hook is triggered.
 
+When command hooks run, they respect the `working_directory` option if it is
+configured, meaning that the hook commands are run in that directory.
+
+<span class="minilink minilink-addedin">New in version 2.0.4</span>If the exact
+same `everything` command hook is present in multiple configuration files,
+borgmatic only runs it once.
+
 
 ### Order of execution
 
@@ -113,11 +116,20 @@ borgmatic for the `create` and `prune` actions. Here's the order of execution:
             * Run `after: action` hooks for `prune`.
         * Run `after: repository` hooks (for the first repository).
     * Run `after: configuration` hooks (from the first configuration file).
+    * Run `after: error` hooks (if an error occurs).
  * Run `after: everything` hooks (from all configuration files).
 
 This same order of execution extends to multiple repositories and/or
 configuration files.
 
+Based on the above, you can see the difference between, say, an `after: action`
+hook with `states: [fail]` and an `after: error` hook. The `after: action hook`
+runs immediately after the create action fails for a particular repository—so
+before any subsequent actions for that repository or other repositories even
+have a chance to run. Whereas the `after: error` hook doesn't run until all
+actions for—and repositories in—a configuration file have had a chance to
+execute.
+
 
 ### Deprecated command hooks
 

pyproject.toml

@@ -1,6 +1,6 @@
 [project]
 name = "borgmatic"
-version = "2.0.3"
+version = "2.0.4"
 authors = [
   { name="Dan Helfman", email="witten@torsion.org" },
 ]

tests/end-to-end/commands/fake_btrfs.py

@@ -53,7 +53,7 @@ def save_snapshots(snapshot_paths):
 
 
 def print_subvolume_list(arguments, snapshot_paths):
-    assert arguments.subvolume_path == '/mnt/subvolume'
+    assert arguments.subvolume_path == '/e2e/mnt/subvolume'
 
     if not arguments.snapshots_only:
         for line in BUILTIN_SUBVOLUME_LIST_LINES:

tests/end-to-end/commands/fake_findmnt.py

@@ -14,7 +14,7 @@ def parse_arguments(*unparsed_arguments):
 BUILTIN_FILESYSTEM_MOUNT_OUTPUT = '''{
        "filesystems": [
           {
-             "target": "/mnt/subvolume",
+             "target": "/e2e/mnt/subvolume",
              "source": "/dev/loop0",
              "fstype": "btrfs",
              "options": "rw,relatime,ssd,space_cache=v2,subvolid=5,subvol=/"

tests/end-to-end/commands/fake_lsblk.py

@@ -20,7 +20,7 @@ BUILTIN_BLOCK_DEVICES = {
         {
             'name': 'vgroup-lvolume',
             'path': '/dev/mapper/vgroup-lvolume',
-            'mountpoint': '/mnt/lvolume',
+            'mountpoint': '/e2e/mnt/lvolume',
             'type': 'lvm',
         },
         {

tests/end-to-end/commands/fake_zfs.py

@@ -23,20 +23,20 @@ def parse_arguments(*unparsed_arguments):
 
 BUILTIN_DATASETS = (
     {
-        'name': 'pool',
+        'name': 'e2e/pool',
         'used': '256K',
         'avail': '23.7M',
         'refer': '25K',
         'canmount': 'on',
-        'mountpoint': '/pool',
+        'mountpoint': '/e2e/pool',
     },
     {
-        'name': 'pool/dataset',
+        'name': 'e2e/pool/dataset',
         'used': '256K',
         'avail': '23.7M',
         'refer': '25K',
         'canmount': 'on',
-        'mountpoint': '/pool/dataset',
+        'mountpoint': '/e2e/pool/dataset',
     },
 )
 

tests/end-to-end/hooks/data_source/test_btrfs.py

@@ -16,10 +16,10 @@ def generate_configuration(config_path, repository_path):
         open(config_path)
         .read()
         .replace('ssh://user@backupserver/./sourcehostname.borg', repository_path)
-        .replace('- path: /mnt/backup', '')
+        .replace('- path: /e2e/mnt/backup', '')
         .replace('label: local', '')
         .replace('- /home', f'- {config_path}')
-        .replace('- /etc', '- /mnt/subvolume/subdir')
+        .replace('- /etc', '- /e2e/mnt/subvolume/subdir')
         .replace('- /var/log/syslog*', '')
         + 'encryption_passphrase: "test"\n'
         + 'btrfs:\n'
@@ -51,11 +51,11 @@ def test_btrfs_create_and_list():
             f'borgmatic --config {config_path} list --archive latest'.split(' ')
         ).decode(sys.stdout.encoding)
 
-        assert 'mnt/subvolume/subdir/file.txt' in output
+        assert 'e2e/mnt/subvolume/subdir/file.txt' in output
 
         # Assert that the snapshot has been deleted.
         assert not subprocess.check_output(
-            'python3 /app/tests/end-to-end/commands/fake_btrfs.py subvolume list -s /mnt/subvolume'.split(
+            'python3 /app/tests/end-to-end/commands/fake_btrfs.py subvolume list -s /e2e/mnt/subvolume'.split(
                 ' '
             )
         )

tests/end-to-end/hooks/data_source/test_lvm.py

@@ -17,10 +17,10 @@ def generate_configuration(config_path, repository_path):
         open(config_path)
         .read()
         .replace('ssh://user@backupserver/./sourcehostname.borg', repository_path)
-        .replace('- path: /mnt/backup', '')
+        .replace('- path: /e2e/mnt/backup', '')
         .replace('label: local', '')
         .replace('- /home', f'- {config_path}')
-        .replace('- /etc', '- /mnt/lvolume/subdir')
+        .replace('- /etc', '- /e2e/mnt/lvolume/subdir')
         .replace('- /var/log/syslog*', '')
         + 'encryption_passphrase: "test"\n'
         + 'lvm:\n'
@@ -56,7 +56,7 @@ def test_lvm_create_and_list():
             f'borgmatic --config {config_path} list --archive latest'.split(' ')
         ).decode(sys.stdout.encoding)
 
-        assert 'mnt/lvolume/subdir/file.txt' in output
+        assert 'e2e/mnt/lvolume/subdir/file.txt' in output
 
         # Assert that the snapshot has been deleted.
         assert not json.loads(

tests/end-to-end/hooks/data_source/test_zfs.py

@@ -19,7 +19,7 @@ def generate_configuration(config_path, repository_path):
         .replace('- path: /mnt/backup', '')
         .replace('label: local', '')
         .replace('- /home', f'- {config_path}')
-        .replace('- /etc', '- /pool/dataset/subdir')
+        .replace('- /etc', '- /e2e/pool/dataset/subdir')
         .replace('- /var/log/syslog*', '')
         + 'encryption_passphrase: "test"\n'
         + 'zfs:\n'
@@ -45,14 +45,14 @@ def test_zfs_create_and_list():
         )
 
         # Run a create action to exercise ZFS snapshotting and backup.
-        subprocess.check_call(f'borgmatic --config {config_path} create'.split(' '))
+        subprocess.check_call(f'borgmatic -v 2 --config {config_path} create'.split(' '))
 
         # List the resulting archive and assert that the snapshotted files are there.
         output = subprocess.check_output(
             f'borgmatic --config {config_path} list --archive latest'.split(' ')
         ).decode(sys.stdout.encoding)
 
-        assert 'pool/dataset/subdir/file.txt' in output
+        assert 'e2e/pool/dataset/subdir/file.txt' in output
 
         # Assert that the snapshot has been deleted.
         assert not subprocess.check_output(

tests/unit/actions/test_pattern.py

@@ -245,36 +245,69 @@ def test_expand_patterns_expands_only_tildes_in_non_root_patterns():
     assert paths == (Pattern('/root/bar/*', Pattern_type.INCLUDE),)
 
 
-def test_device_map_patterns_gives_device_id_per_path():
+def test_get_existent_path_or_parent_passes_through_existent_path():
     flexmock(module.os.path).should_receive('exists').and_return(True)
+
+    assert module.get_existent_path_or_parent('/foo/bar/baz') == '/foo/bar/baz'
+
+
+def test_get_existent_path_or_parent_with_non_existent_path_returns_none():
+    flexmock(module.os.path).should_receive('exists').and_return(False)
+
+    assert module.get_existent_path_or_parent('/foo/bar/baz') is None
+
+
+def test_get_existent_path_or_parent_with_non_existent_path_returns_existent_parent():
+    flexmock(module.os.path).should_receive('exists').with_args('/foo/bar/baz*').and_return(False)
+    flexmock(module.os.path).should_receive('exists').with_args('/foo/bar').and_return(True)
+    flexmock(module.os.path).should_receive('exists').with_args('/foo').never()
+    flexmock(module.os.path).should_receive('exists').with_args('/').never()
+
+    assert module.get_existent_path_or_parent('/foo/bar/baz*') == '/foo/bar'
+
+
+def test_get_existent_path_or_parent_with_non_existent_path_returns_existent_grandparent():
+    flexmock(module.os.path).should_receive('exists').with_args('/foo/bar/baz*').and_return(False)
+    flexmock(module.os.path).should_receive('exists').with_args('/foo/bar').and_return(False)
+    flexmock(module.os.path).should_receive('exists').with_args('/foo').and_return(True)
+    flexmock(module.os.path).should_receive('exists').with_args('/').never()
+
+    assert module.get_existent_path_or_parent('/foo/bar/baz*') == '/foo'
+
+
+def test_get_existent_path_or_parent_with_end_to_end_test_prefix_returns_none():
+    flexmock(module.os.path).should_receive('exists').never()
+
+    assert module.get_existent_path_or_parent('/e2e/foo/bar/baz') is None
+
+
+def test_device_map_patterns_gives_device_id_per_path():
+    flexmock(module).should_receive('get_existent_path_or_parent').replace_with(lambda path: path)
     flexmock(module.os).should_receive('stat').with_args('/foo').and_return(flexmock(st_dev=55))
     flexmock(module.os).should_receive('stat').with_args('/bar').and_return(flexmock(st_dev=66))
 
-    device_map = module.device_map_patterns((Pattern('/foo'), Pattern('/bar')))
-
-    assert device_map == (
-        Pattern('/foo', device=55),
-        Pattern('/bar', device=66),
-    )
-
-
-def test_device_map_patterns_only_considers_root_patterns():
-    flexmock(module.os.path).should_receive('exists').and_return(True)
-    flexmock(module.os).should_receive('stat').with_args('/foo').and_return(flexmock(st_dev=55))
-    flexmock(module.os).should_receive('stat').with_args('/bar*').never()
-
     device_map = module.device_map_patterns(
-        (Pattern('/foo'), Pattern('/bar*', Pattern_type.INCLUDE))
+        (
+            Pattern('/foo'),
+            Pattern('^/bar', type=Pattern_type.INCLUDE, style=Pattern_style.REGULAR_EXPRESSION),
+        )
     )
 
     assert device_map == (
         Pattern('/foo', device=55),
-        Pattern('/bar*', Pattern_type.INCLUDE),
+        Pattern(
+            '^/bar', type=Pattern_type.INCLUDE, style=Pattern_style.REGULAR_EXPRESSION, device=66
+        ),
     )
 
 
 def test_device_map_patterns_with_missing_path_does_not_error():
-    flexmock(module.os.path).should_receive('exists').and_return(True).and_return(False)
+    flexmock(module).should_receive('get_existent_path_or_parent').with_args('/foo').and_return(
+        '/foo'
+    )
+    flexmock(module).should_receive('get_existent_path_or_parent').with_args('/bar').and_return(
+        None
+    )
     flexmock(module.os).should_receive('stat').with_args('/foo').and_return(flexmock(st_dev=55))
     flexmock(module.os).should_receive('stat').with_args('/bar').never()
 
@@ -287,7 +320,7 @@ def test_device_map_patterns_with_missing_path_does_not_error():
 
 
 def test_device_map_patterns_uses_working_directory_to_construct_path():
-    flexmock(module.os.path).should_receive('exists').and_return(True)
+    flexmock(module).should_receive('get_existent_path_or_parent').replace_with(lambda path: path)
     flexmock(module.os).should_receive('stat').with_args('/foo').and_return(flexmock(st_dev=55))
     flexmock(module.os).should_receive('stat').with_args('/working/dir/bar').and_return(
         flexmock(st_dev=66)
@@ -304,7 +337,7 @@ def test_device_map_patterns_uses_working_directory_to_construct_path():
 
 
 def test_device_map_patterns_with_existing_device_id_does_not_overwrite_it():
-    flexmock(module.os.path).should_receive('exists').and_return(True)
+    flexmock(module).should_receive('get_existent_path_or_parent').replace_with(lambda path: path)
     flexmock(module.os).should_receive('stat').with_args('/foo').and_return(flexmock(st_dev=55))
     flexmock(module.os).should_receive('stat').with_args('/bar').and_return(flexmock(st_dev=100))
 

tests/unit/commands/test_borgmatic.py

@@ -1956,14 +1956,17 @@ def test_collect_configuration_run_summary_logs_info_for_success():
 
 
 def test_collect_configuration_run_summary_executes_hooks_for_create():
+    before_everything_hook = {'before': 'everything', 'run': ['echo hi']}
+    after_everything_hook = {'after': 'everything', 'run': ['echo hi']}
+    command_hooks = (before_everything_hook, after_everything_hook)
     flexmock(module.validate).should_receive('guard_configuration_contains_repository')
     flexmock(module.command).should_receive('filter_hooks').with_args(
-        object, before='everything', action_names=object
-    )
+        command_hooks, before='everything', action_names=object
+    ).and_return([before_everything_hook])
     flexmock(module.command).should_receive('filter_hooks').with_args(
-        object, after='everything', action_names=object, state_names=['finish']
-    )
-    flexmock(module.command).should_receive('execute_hooks')
+        command_hooks, after='everything', action_names=object, state_names=['finish']
+    ).and_return([after_everything_hook])
+    flexmock(module.command).should_receive('execute_hooks').twice()
     flexmock(module).should_receive('Log_prefix').and_return(flexmock())
     flexmock(module).should_receive('run_configuration').and_return([])
     arguments = {
@@ -1973,7 +1976,7 @@ def test_collect_configuration_run_summary_executes_hooks_for_create():
 
     logs = tuple(
         module.collect_configuration_run_summary_logs(
-            {'test.yaml': {}},
+            {'test.yaml': {'commands': command_hooks}},
             config_paths=['/tmp/test.yaml'],
             arguments=arguments,
             log_file_path=None,
@@ -1983,6 +1986,43 @@ def test_collect_configuration_run_summary_executes_hooks_for_create():
     assert {log.levelno for log in logs} == {logging.INFO}
 
 
+def test_collect_configuration_run_summary_deduplicates_everything_hooks_across_config_files():
+    before_everything_hook = {'before': 'everything', 'run': ['echo hi']}
+    after_everything_hook = {'after': 'everything', 'run': ['echo hi']}
+    command_hooks = (before_everything_hook, after_everything_hook)
+    flexmock(module.validate).should_receive('guard_configuration_contains_repository')
+    flexmock(module.command).should_receive('filter_hooks').with_args(
+        command_hooks, before='everything', action_names=object
+    ).and_return([before_everything_hook]).once()
+    flexmock(module.command).should_receive('filter_hooks').with_args(
+        (after_everything_hook,), before='everything', action_names=object
+    ).and_return([]).once()
+    flexmock(module.command).should_receive('filter_hooks').with_args(
+        command_hooks, after='everything', action_names=object, state_names=['finish']
+    ).and_return([after_everything_hook]).once()
+    flexmock(module.command).should_receive('filter_hooks').with_args(
+        (before_everything_hook,), after='everything', action_names=object, state_names=['finish']
+    ).and_return([]).once()
+    flexmock(module.command).should_receive('execute_hooks').twice()
+    flexmock(module).should_receive('Log_prefix').and_return(flexmock())
+    flexmock(module).should_receive('run_configuration').and_return([])
+    arguments = {
+        'create': flexmock(),
+        'global': flexmock(monitoring_verbosity=1, dry_run=False),
+    }
+
+    logs = tuple(
+        module.collect_configuration_run_summary_logs(
+            {'test.yaml': {'commands': command_hooks}, 'other.yaml': {'commands': command_hooks}},
+            config_paths=['/tmp/test.yaml', '/tmp/other.yaml'],
+            arguments=arguments,
+            log_file_path=None,
+        )
+    )
+
+    assert {log.levelno for log in logs} == {logging.INFO}
+
+
 def test_collect_configuration_run_summary_logs_info_for_success_with_extract():
     flexmock(module.validate).should_receive('guard_configuration_contains_repository')
     flexmock(module.command).should_receive('filter_hooks').with_args(
@@ -2105,13 +2145,16 @@ def test_collect_configuration_run_summary_logs_missing_configs_error():
 
 
 def test_collect_configuration_run_summary_logs_before_hook_error():
+    before_everything_hook = {'before': 'everything', 'run': ['echo hi']}
+    after_everything_hook = {'after': 'everything', 'run': ['echo hi']}
+    command_hooks = (before_everything_hook, after_everything_hook)
     flexmock(module.validate).should_receive('guard_configuration_contains_repository')
     flexmock(module.command).should_receive('filter_hooks').with_args(
         object, before='everything', action_names=object
-    )
+    ).and_return([before_everything_hook])
     flexmock(module.command).should_receive('filter_hooks').with_args(
         object, after='everything', action_names=object, state_names=['fail']
-    )
+    ).and_return([after_everything_hook])
     flexmock(module.command).should_receive('execute_hooks').and_raise(ValueError)
     expected_logs = (flexmock(),)
     flexmock(module).should_receive('log_error_records').and_return(expected_logs)
@@ -2122,7 +2165,7 @@ def test_collect_configuration_run_summary_logs_before_hook_error():
 
     logs = tuple(
         module.collect_configuration_run_summary_logs(
-            {'test.yaml': {}},
+            {'test.yaml': {'commands': command_hooks}},
             config_paths=['/tmp/test.yaml'],
             arguments=arguments,
             log_file_path=None,
@@ -2133,13 +2176,16 @@ def test_collect_configuration_run_summary_logs_before_hook_error():
 
 
 def test_collect_configuration_run_summary_logs_after_hook_error():
+    before_everything_hook = {'before': 'everything', 'run': ['echo hi']}
+    after_everything_hook = {'after': 'everything', 'run': ['echo hi']}
+    command_hooks = (before_everything_hook, after_everything_hook)
     flexmock(module.validate).should_receive('guard_configuration_contains_repository')
     flexmock(module.command).should_receive('filter_hooks').with_args(
         object, before='everything', action_names=object
-    )
+    ).and_return([before_everything_hook])
     flexmock(module.command).should_receive('filter_hooks').with_args(
         object, after='everything', action_names=object, state_names=['finish']
-    )
+    ).and_return([after_everything_hook])
     flexmock(module.command).should_receive('execute_hooks').and_return(None).and_raise(ValueError)
     flexmock(module).should_receive('Log_prefix').and_return(flexmock())
     flexmock(module).should_receive('run_configuration').and_return([])
@@ -2152,7 +2198,7 @@ def test_collect_configuration_run_summary_logs_after_hook_error():
 
     logs = tuple(
         module.collect_configuration_run_summary_logs(
-            {'test.yaml': {}},
+            {'test.yaml': {'commands': command_hooks}},
             config_paths=['/tmp/test.yaml'],
             arguments=arguments,
             log_file_path=None,

tests/unit/hooks/test_command.py

@@ -11,8 +11,16 @@ def test_interpolate_context_passes_through_command_without_variable():
     assert module.interpolate_context('pre-backup', 'ls', {'foo': 'bar'}) == 'ls'
 
 
-def test_interpolate_context_passes_through_command_with_unknown_variable():
+def test_interpolate_context_warns_and_passes_through_command_with_unknown_variable():
     command = 'ls {baz}'  # noqa: FS003
+    flexmock(module.logger).should_receive('warning').once()
+
+    assert module.interpolate_context('pre-backup', command, {'foo': 'bar'}) == command
+
+
+def test_interpolate_context_does_not_warn_and_passes_through_command_with_unknown_variable_matching_borg_placeholder():
+    command = 'ls {hostname}'  # noqa: FS003
+    flexmock(module.logger).should_receive('warning').never()
 
     assert module.interpolate_context('pre-backup', command, {'foo': 'bar'}) == command