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

This commit is contained in:
Dan Helfman 2019-10-01 12:23:16 -07:00
parent 6c617eddd5
commit 1d37b14356
7 changed files with 108 additions and 19 deletions

3
NEWS
View file

@ -1,3 +1,6 @@
1.3.23
* #174: More detailed error alerting via runtime context available in "on_error" hook.
1.3.22 1.3.22
* #144: When backups to one of several repositories fails, keep backing up to the other * #144: When backups to one of several repositories fails, keep backing up to the other
repositories and report errors afterwards. repositories and report errors afterwards.

View file

@ -48,7 +48,8 @@ def run_configuration(config_filename, config, arguments):
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 encountered_error = None
error_repository = ''
if 'create' in arguments: if 'create' in arguments:
try: try:
@ -60,7 +61,7 @@ def run_configuration(config_filename, config, arguments):
global_arguments.dry_run, global_arguments.dry_run,
) )
except (OSError, CalledProcessError) as error: except (OSError, CalledProcessError) as error:
encountered_error = True encountered_error = error
yield from make_error_log_records( yield from make_error_log_records(
'{}: Error running pre-backup hook'.format(config_filename), error '{}: Error running pre-backup hook'.format(config_filename), error
) )
@ -79,7 +80,8 @@ def run_configuration(config_filename, config, arguments):
repository_path=repository_path, repository_path=repository_path,
) )
except (OSError, CalledProcessError) as error: except (OSError, CalledProcessError) as error:
encountered_error = True encountered_error = error
error_repository = repository_path
yield from make_error_log_records( yield from make_error_log_records(
'{}: Error running actions for repository'.format(repository_path), error '{}: Error running actions for repository'.format(repository_path), error
) )
@ -94,7 +96,7 @@ def run_configuration(config_filename, config, arguments):
global_arguments.dry_run, global_arguments.dry_run,
) )
except (OSError, CalledProcessError) as error: except (OSError, CalledProcessError) as error:
encountered_error = True encountered_error = error
yield from make_error_log_records( yield from make_error_log_records(
'{}: Error running post-backup hook'.format(config_filename), error '{}: Error running post-backup hook'.format(config_filename), error
) )
@ -107,6 +109,9 @@ def run_configuration(config_filename, config, arguments):
config_filename, config_filename,
'on-error', 'on-error',
global_arguments.dry_run, global_arguments.dry_run,
repository=error_repository,
error=encountered_error,
output=getattr(encountered_error, 'output', ''),
) )
except (OSError, CalledProcessError) as error: except (OSError, CalledProcessError) as error:
yield from make_error_log_records( yield from make_error_log_records(

View file

@ -6,12 +6,26 @@ from borgmatic import execute
logger = logging.getLogger(__name__) 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, 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 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. 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 ValueError if the umask cannot be parsed.
Raise subprocesses.CalledProcessError if an error occurs in a hook. 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 '' 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: if len(commands) == 1:
logger.info( logger.info(
'{}: Running command for {} hook{}'.format(config_filename, description, dry_run_label) '{}: Running command for {} hook{}'.format(config_filename, description, dry_run_label)

View file

@ -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 a backup or a backup hook, but not if an error occurs during a
`before_everything` hook. `before_everything` hook.
## Error hooks
borgmatic also runs `on_error` hooks if an error occurs, either when creating 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: a backup or running a backup hook. See the [error alerting
documentation](https://torsion.org/borgmatic/docs/how-to/inspect-your-backups.md)
```yaml for more information.
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.
## Hook output ## Hook output

View file

@ -24,7 +24,7 @@ borgmatic --verbosity 2
If you're less concerned with progress during a backup, and you just want to 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 see the summary of archive statistics at the end, you can use the stats
option: option when performing a backup:
```bash ```bash
borgmatic --stats 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) file](https://torsion.org/borgmatic/docs/how-to/set-up-backups/#systemd)
already has this rate limit disabled. 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 ## Scripting borgmatic
To consume the output of borgmatic in other software, you can include an 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 ## Related documentation
* [Set up backups with borgmatic](https://torsion.org/borgmatic/docs/how-to/set-up-backups.md) * [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) * [Develop on borgmatic](https://torsion.org/borgmatic/docs/how-to/develop-on-borgmatic.md)

View file

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

View file

@ -5,7 +5,24 @@ from flexmock import flexmock
from borgmatic import hook as module 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(): 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( flexmock(module.execute).should_receive('execute_command').with_args(
[':'], output_log_level=logging.WARNING, shell=True [':'], output_log_level=logging.WARNING, shell=True
).once() ).once()
@ -14,6 +31,9 @@ def test_execute_hook_invokes_each_command():
def test_execute_hook_with_multiple_commands_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( flexmock(module.execute).should_receive('execute_command').with_args(
[':'], output_log_level=logging.WARNING, shell=True [':'], output_log_level=logging.WARNING, shell=True
).once() ).once()
@ -25,6 +45,9 @@ def test_execute_hook_with_multiple_commands_invokes_each_command():
def test_execute_hook_with_umask_sets_that_umask(): 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(0o77).and_return(0o22).once()
flexmock(module.os).should_receive('umask').with_args(0o22).once() flexmock(module.os).should_receive('umask').with_args(0o22).once()
flexmock(module.execute).should_receive('execute_command').with_args( 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(): 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() flexmock(module.execute).should_receive('execute_command').never()
module.execute_hook([':', 'true'], None, 'config.yaml', 'pre-backup', dry_run=True) 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(): 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( flexmock(module.execute).should_receive('execute_command').with_args(
[':'], output_log_level=logging.ERROR, shell=True [':'], output_log_level=logging.ERROR, shell=True
).once() ).once()