From a20e1e95d8136fa31e6d06abffd2830eefdba658 Mon Sep 17 00:00:00 2001 From: Tobias Hodapp Date: Sat, 18 Nov 2023 01:26:14 +0100 Subject: [PATCH] Added debug message that logs borg version for every config --- borgmatic/commands/borgmatic.py | 3 + tests/unit/commands/test_borgmatic.py | 93 ++++++++++++++++----------- 2 files changed, 60 insertions(+), 36 deletions(-) diff --git a/borgmatic/commands/borgmatic.py b/borgmatic/commands/borgmatic.py index ab32aa88..e792273b 100644 --- a/borgmatic/commands/borgmatic.py +++ b/borgmatic/commands/borgmatic.py @@ -75,6 +75,9 @@ def run_configuration(config_filename, config, arguments): try: local_borg_version = borg_version.local_borg_version(config, local_path) + yield from log_error_records( + f'{config_filename}: Local Borg version: {local_borg_version}', levelno=logging.DEBUG + ) except (OSError, CalledProcessError, ValueError) as error: yield from log_error_records(f'{config_filename}: Error getting local Borg version', error) return diff --git a/tests/unit/commands/test_borgmatic.py b/tests/unit/commands/test_borgmatic.py index d7334f5c..06f3a3d5 100644 --- a/tests/unit/commands/test_borgmatic.py +++ b/tests/unit/commands/test_borgmatic.py @@ -10,10 +10,11 @@ from borgmatic.commands import borgmatic as module def test_run_configuration_runs_actions_for_each_repository(): flexmock(module).should_receive('verbosity_to_log_level').and_return(logging.INFO) + expected_results = [flexmock(), flexmock(), flexmock()] + flexmock(module).should_receive('log_error_records').and_return(expected_results[0]) flexmock(module.borg_version).should_receive('local_borg_version').and_return(flexmock()) - expected_results = [flexmock(), flexmock()] - flexmock(module).should_receive('run_actions').and_return(expected_results[:1]).and_return( - expected_results[1:] + flexmock(module).should_receive('run_actions').and_return(expected_results[1:2]).and_return( + expected_results[2:] ) config = {'repositories': [{'path': 'foo'}, {'path': 'bar'}]} arguments = {'global': flexmock(monitoring_verbosity=1)} @@ -52,7 +53,8 @@ def test_run_configuration_logs_monitor_start_error(): None ).and_return(None).and_return(None) expected_results = [flexmock()] - flexmock(module).should_receive('log_error_records').and_return(expected_results) + expected_results.append(expected_results[0]) + flexmock(module).should_receive('log_error_records').and_return(expected_results[0]) flexmock(module).should_receive('run_actions').never() config = {'repositories': ['foo']} arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()} @@ -67,14 +69,15 @@ def test_run_configuration_bails_for_monitor_start_soft_failure(): flexmock(module.borg_version).should_receive('local_borg_version').and_return(flexmock()) error = subprocess.CalledProcessError(borgmatic.hooks.command.SOFT_FAIL_EXIT_CODE, 'try again') flexmock(module.dispatch).should_receive('call_hooks').and_raise(error) - flexmock(module).should_receive('log_error_records').never() + expected_results = [flexmock()] + flexmock(module).should_receive('log_error_records').once().and_return(expected_results[0]) flexmock(module).should_receive('run_actions').never() config = {'repositories': ['foo']} arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()} results = list(module.run_configuration('test.yaml', config, arguments)) - assert results == [] + assert results == expected_results def test_run_configuration_logs_actions_error(): @@ -83,7 +86,8 @@ def test_run_configuration_logs_actions_error(): flexmock(module.command).should_receive('execute_hook') flexmock(module.dispatch).should_receive('call_hooks') expected_results = [flexmock()] - flexmock(module).should_receive('log_error_records').and_return(expected_results) + expected_results.append(expected_results[0]) + flexmock(module).should_receive('log_error_records').and_return(expected_results[0]) flexmock(module).should_receive('run_actions').and_raise(OSError) config = {'repositories': [{'path': 'foo'}]} arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False)} @@ -99,14 +103,15 @@ def test_run_configuration_bails_for_actions_soft_failure(): flexmock(module.dispatch).should_receive('call_hooks') error = subprocess.CalledProcessError(borgmatic.hooks.command.SOFT_FAIL_EXIT_CODE, 'try again') flexmock(module).should_receive('run_actions').and_raise(error) - flexmock(module).should_receive('log_error_records').never() + expected_results = [flexmock()] + flexmock(module).should_receive('log_error_records').once().and_return(expected_results) flexmock(module.command).should_receive('considered_soft_failure').and_return(True) config = {'repositories': [{'path': 'foo'}]} arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()} results = list(module.run_configuration('test.yaml', config, arguments)) - assert results == [] + assert results == expected_results def test_run_configuration_logs_monitor_log_error(): @@ -116,7 +121,8 @@ def test_run_configuration_logs_monitor_log_error(): None ).and_raise(OSError) expected_results = [flexmock()] - flexmock(module).should_receive('log_error_records').and_return(expected_results) + expected_results.append(expected_results[0]) + flexmock(module).should_receive('log_error_records').and_return(expected_results[0]) flexmock(module).should_receive('run_actions').and_return([]) config = {'repositories': [{'path': 'foo'}]} arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()} @@ -133,7 +139,8 @@ def test_run_configuration_bails_for_monitor_log_soft_failure(): flexmock(module.dispatch).should_receive('call_hooks').and_return(None).and_return( None ).and_raise(error) - flexmock(module).should_receive('log_error_records').never() + expected_results = [flexmock()] + flexmock(module).should_receive('log_error_records').once().and_return(expected_results) flexmock(module).should_receive('run_actions').and_return([]) flexmock(module.command).should_receive('considered_soft_failure').and_return(True) config = {'repositories': [{'path': 'foo'}]} @@ -141,7 +148,7 @@ def test_run_configuration_bails_for_monitor_log_soft_failure(): results = list(module.run_configuration('test.yaml', config, arguments)) - assert results == [] + assert results == expected_results def test_run_configuration_logs_monitor_finish_error(): @@ -151,7 +158,8 @@ def test_run_configuration_logs_monitor_finish_error(): None ).and_return(None).and_raise(OSError) expected_results = [flexmock()] - flexmock(module).should_receive('log_error_records').and_return(expected_results) + expected_results.append(expected_results[0]) + flexmock(module).should_receive('log_error_records').and_return(expected_results[0]) flexmock(module).should_receive('run_actions').and_return([]) config = {'repositories': [{'path': 'foo'}]} arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()} @@ -168,7 +176,8 @@ def test_run_configuration_bails_for_monitor_finish_soft_failure(): flexmock(module.dispatch).should_receive('call_hooks').and_return(None).and_return( None ).and_raise(None).and_raise(error) - flexmock(module).should_receive('log_error_records').never() + expected_results = [flexmock()] + flexmock(module).should_receive('log_error_records').once().and_return(expected_results) flexmock(module).should_receive('run_actions').and_return([]) flexmock(module.command).should_receive('considered_soft_failure').and_return(True) config = {'repositories': [{'path': 'foo'}]} @@ -176,7 +185,7 @@ def test_run_configuration_bails_for_monitor_finish_soft_failure(): results = list(module.run_configuration('test.yaml', config, arguments)) - assert results == [] + assert results == expected_results def test_run_configuration_does_not_call_monitoring_hooks_if_monitoring_hooks_are_disabled(): @@ -186,20 +195,22 @@ def test_run_configuration_does_not_call_monitoring_hooks_if_monitoring_hooks_ar flexmock(module.dispatch).should_receive('call_hooks').never() flexmock(module).should_receive('run_actions').and_return([]) + expected_results = [flexmock()] + flexmock(module).should_receive('log_error_records').once().and_return(expected_results) config = {'repositories': [{'path': 'foo'}]} arguments = {'global': flexmock(monitoring_verbosity=-2, dry_run=False), 'create': flexmock()} results = list(module.run_configuration('test.yaml', config, arguments)) - assert results == [] + assert results == expected_results def test_run_configuration_logs_on_error_hook_error(): flexmock(module).should_receive('verbosity_to_log_level').and_return(logging.INFO) flexmock(module.borg_version).should_receive('local_borg_version').and_return(flexmock()) flexmock(module.command).should_receive('execute_hook').and_raise(OSError) - expected_results = [flexmock(), flexmock()] - flexmock(module).should_receive('log_error_records').and_return( - expected_results[:1] - ).and_return(expected_results[1:]) + expected_results = [flexmock(), flexmock(), flexmock()] + flexmock(module).should_receive('log_error_records').and_return(expected_results[0]).and_return( + expected_results[1] + ).and_return(expected_results[2]) flexmock(module).should_receive('run_actions').and_raise(OSError) config = {'repositories': [{'path': 'foo'}]} arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()} @@ -214,8 +225,10 @@ def test_run_configuration_bails_for_on_error_hook_soft_failure(): flexmock(module.borg_version).should_receive('local_borg_version').and_return(flexmock()) error = subprocess.CalledProcessError(borgmatic.hooks.command.SOFT_FAIL_EXIT_CODE, 'try again') flexmock(module.command).should_receive('execute_hook').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[0]).and_return( + expected_results[1] + ) flexmock(module).should_receive('run_actions').and_raise(OSError) config = {'repositories': [{'path': 'foo'}]} arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()} @@ -231,11 +244,12 @@ def test_run_configuration_retries_soft_error(): flexmock(module.borg_version).should_receive('local_borg_version').and_return(flexmock()) flexmock(module.command).should_receive('execute_hook') flexmock(module).should_receive('run_actions').and_raise(OSError).and_return([]) - flexmock(module).should_receive('log_error_records').and_return([flexmock()]).once() + expected_results = [flexmock()] + flexmock(module).should_receive('log_error_records').and_return(expected_results).times(2) config = {'repositories': [{'path': 'foo'}], 'retries': 1} arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()} results = list(module.run_configuration('test.yaml', config, arguments)) - assert results == [] + assert results == expected_results def test_run_configuration_retries_hard_error(): @@ -243,18 +257,19 @@ def test_run_configuration_retries_hard_error(): flexmock(module).should_receive('verbosity_to_log_level').and_return(logging.INFO) flexmock(module.borg_version).should_receive('local_borg_version').and_return(flexmock()) flexmock(module.command).should_receive('execute_hook') + error_logs = [flexmock(), flexmock()] flexmock(module).should_receive('run_actions').and_raise(OSError).times(2) + flexmock(module).should_receive('log_error_records').and_return(error_logs[0]) flexmock(module).should_receive('log_error_records').with_args( 'foo: Error running actions for repository', OSError, levelno=logging.WARNING, log_command_error_output=True, ).and_return([flexmock()]) - error_logs = [flexmock()] flexmock(module).should_receive('log_error_records').with_args( 'foo: Error running actions for repository', OSError, - ).and_return(error_logs) + ).and_return(error_logs[1]) config = {'repositories': [{'path': 'foo'}], 'retries': 1} arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()} results = list(module.run_configuration('test.yaml', config, arguments)) @@ -266,13 +281,14 @@ def test_run_configuration_repos_ordered(): flexmock(module.borg_version).should_receive('local_borg_version').and_return(flexmock()) flexmock(module.command).should_receive('execute_hook') 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').and_return(expected_results[0]) flexmock(module).should_receive('log_error_records').with_args( 'foo: Error running actions for repository', OSError - ).and_return(expected_results[:1]).ordered() + ).and_return(expected_results[1]).ordered() flexmock(module).should_receive('log_error_records').with_args( 'bar: Error running actions for repository', OSError - ).and_return(expected_results[1:]).ordered() + ).and_return(expected_results[2]).ordered() config = {'repositories': [{'path': 'foo'}, {'path': 'bar'}]} arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()} results = list(module.run_configuration('test.yaml', config, arguments)) @@ -284,6 +300,8 @@ def test_run_configuration_retries_round_robin(): flexmock(module.borg_version).should_receive('local_borg_version').and_return(flexmock()) flexmock(module.command).should_receive('execute_hook') flexmock(module).should_receive('run_actions').and_raise(OSError).times(4) + version_log = [flexmock()] + flexmock(module).should_receive('log_error_records').and_return(version_log) flexmock(module).should_receive('log_error_records').with_args( 'foo: Error running actions for repository', OSError, @@ -310,7 +328,7 @@ def test_run_configuration_retries_round_robin(): } arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()} results = list(module.run_configuration('test.yaml', config, arguments)) - assert results == foo_error_logs + bar_error_logs + assert results == version_log + foo_error_logs + bar_error_logs def test_run_configuration_retries_one_passes(): @@ -320,6 +338,8 @@ def test_run_configuration_retries_one_passes(): flexmock(module).should_receive('run_actions').and_raise(OSError).and_raise(OSError).and_return( [] ).and_raise(OSError).times(4) + error_logs = [flexmock(), flexmock()] + flexmock(module).should_receive('log_error_records').and_return(error_logs[0]) flexmock(module).should_receive('log_error_records').with_args( 'foo: Error running actions for repository', OSError, @@ -332,10 +352,9 @@ def test_run_configuration_retries_one_passes(): levelno=logging.WARNING, log_command_error_output=True, ).and_return(flexmock()).ordered() - error_logs = [flexmock()] flexmock(module).should_receive('log_error_records').with_args( 'bar: Error running actions for repository', OSError - ).and_return(error_logs).ordered() + ).and_return(error_logs[1]).ordered() config = { 'repositories': [{'path': 'foo'}, {'path': 'bar'}], 'retries': 1, @@ -350,6 +369,8 @@ def test_run_configuration_retry_wait(): flexmock(module.borg_version).should_receive('local_borg_version').and_return(flexmock()) flexmock(module.command).should_receive('execute_hook') flexmock(module).should_receive('run_actions').and_raise(OSError).times(4) + error_logs = [flexmock(), flexmock()] + flexmock(module).should_receive('log_error_records').and_return(error_logs[0]) flexmock(module).should_receive('log_error_records').with_args( 'foo: Error running actions for repository', OSError, @@ -374,10 +395,9 @@ def test_run_configuration_retry_wait(): ).and_return([flexmock()]).ordered() flexmock(time).should_receive('sleep').with_args(30).and_return().ordered() - error_logs = [flexmock()] flexmock(module).should_receive('log_error_records').with_args( 'foo: Error running actions for repository', OSError - ).and_return(error_logs).ordered() + ).and_return(error_logs[1]).ordered() config = { 'repositories': [{'path': 'foo'}], 'retries': 3, @@ -395,6 +415,8 @@ def test_run_configuration_retries_timeout_multiple_repos(): flexmock(module).should_receive('run_actions').and_raise(OSError).and_raise(OSError).and_return( [] ).and_raise(OSError).times(4) + error_logs = [flexmock(), flexmock()] + flexmock(module).should_receive('log_error_records').and_return(error_logs[0]) flexmock(module).should_receive('log_error_records').with_args( 'foo: Error running actions for repository', OSError, @@ -413,10 +435,9 @@ def test_run_configuration_retries_timeout_multiple_repos(): # Sleep before retrying bar (and failing) flexmock(time).should_receive('sleep').with_args(10).and_return().ordered() - error_logs = [flexmock()] flexmock(module).should_receive('log_error_records').with_args( 'bar: Error running actions for repository', OSError - ).and_return(error_logs).ordered() + ).and_return(error_logs[1]).ordered() config = { 'repositories': [{'path': 'foo'}, {'path': 'bar'}], 'retries': 1,