Warn when an unsupported variable is used in a hook command (#420).

NEWS

@@ -1,4 +1,5 @@
 1.6.1.dev0
+ * #420: Warn when an unsupported variable is used in a hook command.
  * #528: Improve the error message when a configuration override contains an invalid value.
  * #531: BREAKING: When deep merging common configuration, merge colliding list values by appending
    them. Previously, one list replaced the other.

borgmatic/hooks/command.py

@@ -1,5 +1,6 @@
 import logging
 import os
+import re
 
 from borgmatic import execute
 
@@ -9,14 +10,19 @@ logger = logging.getLogger(__name__)
 SOFT_FAIL_EXIT_CODE = 75
 
 
-def interpolate_context(command, context):
+def interpolate_context(config_filename, hook_description, 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.
+    Given a config filename, a hook description, 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))
 
+    for unsupported_variable in re.findall(r'{\w+}', command):
+        logger.warn(
+            f"{config_filename}: Variable '{unsupported_variable}' is not supported in {hook_description} hook"
+        )
+
     return command
 
 
@@ -38,7 +44,9 @@ def execute_hook(commands, umask, config_filename, description, dry_run, **conte
     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]
+    commands = [
+        interpolate_context(config_filename, description, command, context) for command in commands
+    ]
 
     if len(commands) == 1:
         logger.info(

tests/unit/hooks/test_command.py

@@ -7,22 +7,34 @@ from borgmatic.hooks import command as module
 
 
 def test_interpolate_context_passes_through_command_without_variable():
-    assert module.interpolate_context('ls', {'foo': 'bar'}) == 'ls'
+    assert module.interpolate_context('test.yaml', 'pre-backup', 'ls', {'foo': 'bar'}) == 'ls'
 
 
 def test_interpolate_context_passes_through_command_with_unknown_variable():
-    assert module.interpolate_context('ls {baz}', {'foo': 'bar'}) == 'ls {baz}'
+    assert (
+        module.interpolate_context('test.yaml', 'pre-backup', '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'
+    assert (
+        module.interpolate_context('test.yaml', 'pre-backup', 'ls {foo}{baz} {baz}', context)
+        == 'ls barquux quux'
+    )
+
+
+def test_interpolate_context_does_not_touch_unknown_variables():
+    context = {'foo': 'bar', 'baz': 'quux'}
+
+    assert module.interpolate_context('test.yaml', 'pre-backup', 'ls {wtf}', context) == 'ls {wtf}'
 
 
 def test_execute_hook_invokes_each_command():
     flexmock(module).should_receive('interpolate_context').replace_with(
-        lambda command, context: command
+        lambda config_file, hook_description, command, context: command
     )
     flexmock(module.execute).should_receive('execute_command').with_args(
         [':'], output_log_level=logging.WARNING, shell=True
@@ -33,7 +45,7 @@ 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
+        lambda config_file, hook_description, command, context: command
     )
     flexmock(module.execute).should_receive('execute_command').with_args(
         [':'], output_log_level=logging.WARNING, shell=True
@@ -47,7 +59,7 @@ 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
+        lambda config_file, hook_description, 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()
@@ -60,7 +72,7 @@ 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
+        lambda config_file, hook_description, command, context: command
     )
     flexmock(module.execute).should_receive('execute_command').never()
 
@@ -73,7 +85,7 @@ 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
+        lambda config_file, hook_description, command, context: command
     )
     flexmock(module.execute).should_receive('execute_command').with_args(
         [':'], output_log_level=logging.ERROR, shell=True