Adding logging to hook execution!

borgmatic/commands/borgmatic.py

@@ -102,7 +102,7 @@ def main():  # pragma: no cover
 
             try:
                 create.initialize(storage)
-                hook.execute_hook(hooks.get('before_backup'))
+                hook.execute_hook(hooks.get('before_backup'), config_filename, 'pre-backup')
 
                 for repository in location['repositories']:
                     if args.prune:
@@ -120,9 +120,9 @@ def main():  # pragma: no cover
                         logger.info('{}: Running consistency checks'.format(repository))
                         check.check_archives(args.verbosity, repository, consistency, remote_path=remote_path)
 
-                hook.execute_hook(hooks.get('after_backup'))
+                hook.execute_hook(hooks.get('after_backup'), config_filename, 'post-backup')
             except (OSError, CalledProcessError):
-                hook.execute_hook(hooks.get('on_error'))
+                hook.execute_hook(hooks.get('on_error'), config_filename, 'on-error')
                 raise
     except (ValueError, OSError, CalledProcessError) as error:
         print(error, file=sys.stderr)

borgmatic/commands/hook.py

@@ -1,7 +1,20 @@
+import logging
 import subprocess
 
 
-def execute_hook(commands):
-    if commands:
-        for cmd in commands:
-            subprocess.check_call(cmd, shell=True)
+logger = logging.getLogger(__name__)
+
+
+def execute_hook(commands, config_filename, description):
+    if not commands:
+        logger.debug('{}: No commands to run for {} hook'.format(config_filename, description))
+        return
+
+    if len(commands) == 1:
+        logger.info('{}: Running command for {} hook'.format(config_filename, description))
+    else:
+        logger.info('{}: Running {} commands for {} hook'.format(config_filename, len(commands), description))
+
+    for command in commands:
+        logger.debug('{}: Hook command: {}'.format(config_filename, command))
+        subprocess.check_call(command, shell=True)

borgmatic/tests/integration/config/test_validate.py

@@ -15,13 +15,18 @@ def test_schema_filename_returns_plausable_path():
     assert schema_path.endswith('/schema.yaml')
 
 
-def mock_config_and_schema(config_yaml):
+def mock_config_and_schema(config_yaml, schema_yaml=None):
     '''
-    Set up mocks for the config config YAML string and the default schema so that the code under
-    test consumes them when parsing the configuration.
+    Set up mocks for the given config config YAML string and the schema YAML string, or the default
+    schema if no schema is provided. The idea is that that the code under test consumes these mocks
+    when parsing the configuration.
     '''
     config_stream = io.StringIO(config_yaml)
-    schema_stream = open(module.schema_filename())
+    if schema_yaml is None:
+        schema_stream = open(module.schema_filename())
+    else:
+        schema_stream = io.StringIO(schema_yaml)
+
     builtins = flexmock(sys.modules['builtins'])
     builtins.should_receive('open').with_args('config.yaml').and_return(config_stream)
     builtins.should_receive('open').with_args('schema.yaml').and_return(schema_stream)
@@ -81,6 +86,35 @@ def test_parse_configuration_passes_through_quoted_punctuation():
     }
 
 
+def test_parse_configuration_with_schema_lacking_examples_does_not_raise():
+    mock_config_and_schema(
+        '''
+        location:
+            source_directories:
+                - /home
+
+            repositories:
+                - hostname.borg
+        ''',
+        '''
+        map:
+            location:
+                required: true
+                map:
+                    source_directories:
+                        required: true
+                        seq:
+                            - type: scalar
+                    repositories:
+                        required: true
+                        seq:
+                            - type: scalar
+        '''
+    )
+
+    module.parse_configuration('config.yaml', 'schema.yaml')
+
+
 def test_parse_configuration_raises_for_missing_config_file():
     with pytest.raises(FileNotFoundError):
         module.parse_configuration('config.yaml', 'schema.yaml')

borgmatic/tests/unit/borg/test_hook.py

@@ -7,4 +7,16 @@ def test_execute_hook_invokes_each_command():
     subprocess = flexmock(module.subprocess)
     subprocess.should_receive('check_call').with_args(':', shell=True).once()
 
-    module.execute_hook([':'])
+    module.execute_hook([':'], 'config.yaml', 'pre-backup')
+
+
+def test_execute_hook_with_multiple_commands_invokes_each_command():
+    subprocess = flexmock(module.subprocess)
+    subprocess.should_receive('check_call').with_args(':', shell=True).once()
+    subprocess.should_receive('check_call').with_args('true', shell=True).once()
+
+    module.execute_hook([':', 'true'], 'config.yaml', 'pre-backup')
+
+
+def test_execute_hook_with_empty_commands_does_not_raise():
+    module.execute_hook([], 'config.yaml', 'post-backup')