diff --git a/NEWS b/NEWS index e83b7d7c..ddf12237 100644 --- a/NEWS +++ b/NEWS @@ -1,3 +1,7 @@ +2.0.3.dev0 + * #1065: Fix a regression in monitoring hooks in which an error pinged the finish state instead of + the fail state. + 2.0.2 * #1035: Document potential performance issues and workarounds with the ZFS, Btrfs, and LVM hooks: https://torsion.org/borgmatic/docs/how-to/snapshot-your-filesystems/ diff --git a/borgmatic/commands/borgmatic.py b/borgmatic/commands/borgmatic.py index 9a886be3..d5415f8b 100644 --- a/borgmatic/commands/borgmatic.py +++ b/borgmatic/commands/borgmatic.py @@ -279,8 +279,19 @@ def run_configuration(config_filename, config, config_paths, arguments): encountered_error = error error_repository = repository + # Re-raise any error, so that the Monitoring_hooks context manager wrapping this + # code can see the error and act accordingly. Do this here rather than as soon as + # the error is encountered so that an error with one repository doesn't prevent + # other repositories from running. + if encountered_error: + raise encountered_error + except (OSError, CalledProcessError, ValueError) as error: - yield from log_error_records('Error running configuration', error) + # No need to repeat logging of the error if it was already logged above. + if error_repository: + yield from log_error_records('Error running configuration') + else: + yield from log_error_records('Error running configuration', error) encountered_error = error diff --git a/pyproject.toml b/pyproject.toml index 9df97fb9..65455544 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -1,6 +1,6 @@ [project] name = "borgmatic" -version = "2.0.2" +version = "2.0.3.dev0" authors = [ { name="Dan Helfman", email="witten@torsion.org" }, ] diff --git a/tests/integration/commands/test_borgmatic.py b/tests/integration/commands/test_borgmatic.py index 901e5d55..601c5f82 100644 --- a/tests/integration/commands/test_borgmatic.py +++ b/tests/integration/commands/test_borgmatic.py @@ -12,3 +12,59 @@ def test_borgmatic_version_matches_news_version(): news_version = open('NEWS').readline() assert borgmatic_version == news_version + + +def test_run_configuration_without_error_pings_monitoring_hooks_start_and_finish(): + config = {'repositories': [{'path': 'foo'}]} + arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()} + flexmock(module.borg_version).should_receive('local_borg_version').and_return(flexmock()) + flexmock(module).should_receive('run_actions').and_return([]) + flexmock(module.dispatch).should_receive('call_hooks') + flexmock(module.dispatch).should_receive('call_hooks').with_args( + 'ping_monitor', + config, + module.dispatch.Hook_type.MONITORING, + 'test.yaml', + module.monitor.State.START, + object, + object, + ).once() + flexmock(module.dispatch).should_receive('call_hooks').with_args( + 'ping_monitor', + config, + module.dispatch.Hook_type.MONITORING, + 'test.yaml', + module.monitor.State.FINISH, + object, + object, + ).once() + + list(module.run_configuration('test.yaml', config, ['/tmp/test.yaml'], arguments)) + + +def test_run_configuration_with_action_error_pings_monioring_hooks_start_and_fail(): + config = {'repositories': [{'path': 'foo'}]} + arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()} + flexmock(module.borg_version).should_receive('local_borg_version').and_return(flexmock()) + flexmock(module).should_receive('run_actions').and_raise(OSError) + flexmock(module.dispatch).should_receive('call_hooks') + flexmock(module.dispatch).should_receive('call_hooks').with_args( + 'ping_monitor', + config, + module.dispatch.Hook_type.MONITORING, + 'test.yaml', + module.monitor.State.START, + object, + object, + ).once() + flexmock(module.dispatch).should_receive('call_hooks').with_args( + 'ping_monitor', + config, + module.dispatch.Hook_type.MONITORING, + 'test.yaml', + module.monitor.State.FAIL, + object, + object, + ).once() + + list(module.run_configuration('test.yaml', config, ['/tmp/test.yaml'], arguments)) diff --git a/tests/unit/commands/test_borgmatic.py b/tests/unit/commands/test_borgmatic.py index b5ab13d4..85a5ceea 100644 --- a/tests/unit/commands/test_borgmatic.py +++ b/tests/unit/commands/test_borgmatic.py @@ -465,8 +465,10 @@ def test_run_configuration_logs_actions_error(): flexmock(module).should_receive('Monitoring_hooks').and_return(flexmock()) flexmock(module.command).should_receive('Before_after_hooks').and_return(flexmock()) flexmock(module.borg_version).should_receive('local_borg_version').and_return(flexmock()) - expected_results = [flexmock()] - flexmock(module).should_receive('log_error_records').and_return(expected_results) + expected_results = [flexmock(), flexmock()] + flexmock(module).should_receive('log_error_records').and_return( + expected_results[:1] + ).and_return(expected_results[1:]) flexmock(module).should_receive('Log_prefix').and_return(flexmock()) flexmock(module).should_receive('run_actions').and_raise(OSError) flexmock(module.command).should_receive('filter_hooks') @@ -532,7 +534,7 @@ def test_run_configuration_logs_on_error_hook_error(): expected_results = [flexmock(), flexmock()] flexmock(module).should_receive('log_error_records').and_return( expected_results[:1] - ).and_return(expected_results[1:]) + ).and_return(expected_results[1:2]).and_return(expected_results[2:]) flexmock(module).should_receive('Log_prefix').and_return(flexmock()) flexmock(module).should_receive('run_actions').and_raise(OSError) config = {'repositories': [{'path': 'foo'}]} @@ -601,8 +603,10 @@ def test_run_configuration_bails_for_on_error_hook_soft_failure(): error = subprocess.CalledProcessError(borgmatic.hooks.command.SOFT_FAIL_EXIT_CODE, 'try again') flexmock(module.command).should_receive('filter_hooks') flexmock(module.command).should_receive('execute_hooks').and_raise(error) - expected_results = [flexmock()] - flexmock(module).should_receive('log_error_records').and_return(expected_results) + expected_results = [flexmock(), flexmock()] + flexmock(module).should_receive('log_error_records').and_return( + expected_results[:1] + ).and_return(expected_results[1:]) flexmock(module).should_receive('Log_prefix').and_return(flexmock()) flexmock(module).should_receive('run_actions').and_raise(OSError) config = {'repositories': [{'path': 'foo'}]} @@ -654,11 +658,14 @@ def test_run_configuration_retries_hard_error(): levelno=logging.WARNING, log_command_error_output=True, ).and_return([flexmock()]) - error_logs = [flexmock()] + error_logs = [flexmock(), flexmock()] flexmock(module).should_receive('log_error_records').with_args( 'Error running actions for repository', OSError, - ).and_return(error_logs) + ).and_return(error_logs[:1]).ordered() + flexmock(module).should_receive('log_error_records').with_args( + 'Error running configuration', + ).and_return(error_logs[1:]).ordered() flexmock(module.command).should_receive('filter_hooks') flexmock(module.command).should_receive('execute_hooks') config = {'repositories': [{'path': 'foo'}], 'retries': 1} @@ -680,13 +687,16 @@ def test_run_configuration_retries_repositories_in_order(): flexmock(module.borg_version).should_receive('local_borg_version').and_return(flexmock()) flexmock(module).should_receive('Log_prefix').and_return(flexmock()) flexmock(module).should_receive('run_actions').and_raise(OSError).times(2) - expected_results = [flexmock(), flexmock()] + expected_results = [flexmock(), flexmock(), flexmock()] flexmock(module).should_receive('log_error_records').with_args( 'Error running actions for repository', OSError ).and_return(expected_results[:1]).ordered() flexmock(module).should_receive('log_error_records').with_args( 'Error running actions for repository', OSError - ).and_return(expected_results[1:]).ordered() + ).and_return(expected_results[1:2]).ordered() + flexmock(module).should_receive('log_error_records').with_args( + 'Error running configuration', + ).and_return(expected_results[2:]).ordered() flexmock(module.command).should_receive('filter_hooks') flexmock(module.command).should_receive('execute_hooks') config = {'repositories': [{'path': 'foo'}, {'path': 'bar'}]} @@ -728,6 +738,10 @@ def test_run_configuration_retries_round_robin(): flexmock(module).should_receive('log_error_records').with_args( 'Error running actions for repository', OSError ).and_return(bar_error_logs).ordered() + config_error_logs = [flexmock()] + flexmock(module).should_receive('log_error_records').with_args( + 'Error running configuration', + ).and_return(config_error_logs).ordered() flexmock(module.command).should_receive('filter_hooks') flexmock(module.command).should_receive('execute_hooks') config = { @@ -741,7 +755,7 @@ def test_run_configuration_retries_round_robin(): results = list(module.run_configuration('test.yaml', config, ['/tmp/test.yaml'], arguments)) - assert results == foo_error_logs + bar_error_logs + assert results == foo_error_logs + bar_error_logs + config_error_logs def test_run_configuration_with_one_retry(): @@ -766,10 +780,13 @@ def test_run_configuration_with_one_retry(): levelno=logging.WARNING, log_command_error_output=True, ).and_return(flexmock()).ordered() - error_logs = [flexmock()] + error_logs = [flexmock(), flexmock()] flexmock(module).should_receive('log_error_records').with_args( 'Error running actions for repository', OSError - ).and_return(error_logs).ordered() + ).and_return(error_logs[:1]).ordered() + flexmock(module).should_receive('log_error_records').with_args( + 'Error running configuration', + ).and_return(error_logs[1:]).ordered() flexmock(module.command).should_receive('filter_hooks') flexmock(module.command).should_receive('execute_hooks') config = { @@ -818,10 +835,13 @@ def test_run_configuration_with_retry_wait_does_backoff_after_each_retry(): ).and_return([flexmock()]).ordered() flexmock(time).should_receive('sleep').with_args(30).and_return().ordered() - error_logs = [flexmock()] + error_logs = [flexmock(), flexmock()] flexmock(module).should_receive('log_error_records').with_args( 'Error running actions for repository', OSError - ).and_return(error_logs).ordered() + ).and_return(error_logs[:1]).ordered() + flexmock(module).should_receive('log_error_records').with_args( + 'Error running configuration', + ).and_return(error_logs[1:]).ordered() flexmock(module.command).should_receive('filter_hooks') flexmock(module.command).should_receive('execute_hooks') config = { @@ -867,10 +887,13 @@ def test_run_configuration_with_multiple_repositories_retries_with_timeout(): # Sleep before retrying bar (and failing) flexmock(time).should_receive('sleep').with_args(10).and_return().ordered() - error_logs = [flexmock()] + error_logs = [flexmock(), flexmock()] flexmock(module).should_receive('log_error_records').with_args( 'Error running actions for repository', OSError - ).and_return(error_logs).ordered() + ).and_return(error_logs[:1]).ordered() + flexmock(module).should_receive('log_error_records').with_args( + 'Error running configuration', + ).and_return(error_logs[1:]).ordered() flexmock(module.command).should_receive('filter_hooks') flexmock(module.command).should_receive('execute_hooks') config = {