Customize Healthchecks log level via borgmatic "--monitoring-verbosity" flag (#277).

NEWS

@@ -1,5 +1,6 @@
 1.4.23.dev0
  * #274: Add ~/.config/borgmatic.d as another configuration directory default.
+ * #277: Customize Healthchecks log level via borgmatic "--monitoring-verbosity" flag.
  * For "create" and "prune" actions, no longer list files or show detailed stats at verbosity 1. You
    can opt back in with "--files" or "--stats" flags.
 

borgmatic/commands/arguments.py

@@ -159,6 +159,13 @@ def parse_arguments(*unparsed_arguments):
         default=0,
         help='Log verbose progress to log file (from only errors to very verbose: -1, 0, 1, or 2). Only used when --log-file is given',
     )
+    global_group.add_argument(
+        '--monitoring-verbosity',
+        type=int,
+        choices=range(-1, 3),
+        default=1,
+        help='Log verbose progress to monitoring integrations that support logging (from only errors to very verbose: -1, 0, 1, or 2)',
+    )
     global_group.add_argument(
         '--log-file',
         type=str,

borgmatic/commands/borgmatic.py

@@ -53,6 +53,7 @@ def run_configuration(config_filename, config, arguments):
     encountered_error = None
     error_repository = ''
     prune_create_or_check = {'prune', 'create', 'check'}.intersection(arguments)
+    monitoring_log_level = verbosity_to_log_level(global_arguments.monitoring_verbosity)
 
     try:
         if prune_create_or_check:
@@ -62,6 +63,7 @@ def run_configuration(config_filename, config, arguments):
                 config_filename,
                 monitor.MONITOR_HOOK_NAMES,
                 monitor.State.START,
+                monitoring_log_level,
                 global_arguments.dry_run,
             )
         if 'create' in arguments:
@@ -132,6 +134,7 @@ def run_configuration(config_filename, config, arguments):
                     config_filename,
                     monitor.MONITOR_HOOK_NAMES,
                     monitor.State.FINISH,
+                    monitoring_log_level,
                     global_arguments.dry_run,
                 )
         except (OSError, CalledProcessError) as error:
@@ -158,6 +161,7 @@ def run_configuration(config_filename, config, arguments):
                 config_filename,
                 monitor.MONITOR_HOOK_NAMES,
                 monitor.State.FAIL,
+                monitoring_log_level,
                 global_arguments.dry_run,
             )
         except (OSError, CalledProcessError) as error:
@@ -601,6 +605,7 @@ def main():  # pragma: no cover
             verbosity_to_log_level(global_arguments.verbosity),
             verbosity_to_log_level(global_arguments.syslog_verbosity),
             verbosity_to_log_level(global_arguments.log_file_verbosity),
+            verbosity_to_log_level(global_arguments.monitoring_verbosity),
             global_arguments.log_file,
         )
     except (FileNotFoundError, PermissionError) as error:

borgmatic/hooks/cronhub.py

@@ -13,7 +13,7 @@ MONITOR_STATE_TO_CRONHUB = {
 }
 
 
-def ping_monitor(ping_url, config_filename, state, dry_run):
+def ping_monitor(ping_url, config_filename, state, monitoring_log_level, dry_run):
     '''
     Ping the given Cronhub URL, modified with the monitor.State. Use the given configuration
     filename in any log entries. If this is a dry run, then don't actually ping anything.

borgmatic/hooks/cronitor.py

@@ -13,7 +13,7 @@ MONITOR_STATE_TO_CRONITOR = {
 }
 
 
-def ping_monitor(ping_url, config_filename, state, dry_run):
+def ping_monitor(ping_url, config_filename, state, monitoring_log_level, dry_run):
     '''
     Ping the given Cronitor URL, modified with the monitor.State. Use the given configuration
     filename in any log entries. If this is a dry run, then don't actually ping anything.

borgmatic/hooks/healthchecks.py

@@ -22,13 +22,14 @@ class Forgetful_buffering_handler(logging.Handler):
     first) once a particular capacity in bytes is reached.
     '''
 
-    def __init__(self, byte_capacity):
+    def __init__(self, byte_capacity, log_level):
         super().__init__()
 
         self.byte_capacity = byte_capacity
         self.byte_count = 0
         self.buffer = []
         self.forgot = False
+        self.setLevel(log_level)
 
     def emit(self, record):
         message = record.getMessage() + '\n'
@@ -64,16 +65,18 @@ def format_buffered_logs_for_payload():
     return payload
 
 
-def ping_monitor(ping_url_or_uuid, config_filename, state, dry_run):
+def ping_monitor(ping_url_or_uuid, config_filename, state, monitoring_log_level, dry_run):
     '''
     Ping the given Healthchecks URL or UUID, modified with the monitor.State. Use the given
-    configuration filename in any log entries. If this is a dry run, then don't actually ping
+    configuration filename in any log entries, and log to Healthchecks with the giving log level.
-    anything.
+    If this is a dry run, then don't actually ping anything.
     '''
     if state is monitor.State.START:
         # Add a handler to the root logger that stores in memory the most recent logs emitted. That
         # way, we can send them all to Healthchecks upon a finish or failure state.
-        logging.getLogger().addHandler(Forgetful_buffering_handler(PAYLOAD_LIMIT_BYTES))
+        logging.getLogger().addHandler(
+            Forgetful_buffering_handler(PAYLOAD_LIMIT_BYTES, monitoring_log_level)
+        )
         payload = ''
 
     ping_url = (

borgmatic/logger.py

@@ -110,7 +110,11 @@ def color_text(color, message):
 
 
 def configure_logging(
-    console_log_level, syslog_log_level=None, log_file_log_level=None, log_file=None
+    console_log_level,
+    syslog_log_level=None,
+    log_file_log_level=None,
+    monitoring_log_level=None,
+    log_file=None,
 ):
     '''
     Configure logging to go to both the console and (syslog or log file). Use the given log levels,
@@ -122,6 +126,8 @@ def configure_logging(
         syslog_log_level = console_log_level
     if log_file_log_level is None:
         log_file_log_level = console_log_level
+    if monitoring_log_level is None:
+        monitoring_log_level = console_log_level
 
     # Log certain log levels to console stderr and others to stdout. This supports use cases like
     # grepping (non-error) output.
@@ -160,5 +166,6 @@ def configure_logging(
         handlers = (console_handler,)
 
     logging.basicConfig(
-        level=min(console_log_level, syslog_log_level, log_file_log_level), handlers=handlers
+        level=min(console_log_level, syslog_log_level, log_file_log_level, monitoring_log_level),
+        handlers=handlers,
     )

docs/how-to/monitor-your-backups.md

@@ -131,9 +131,9 @@ the `on_error` hooks run, also tacking on logs including the error itself. But
 the logs are only included for errors that occur when a `prune`, `create`, or
 `check` action is run.
 
-Note that borgmatic sends logs to Healthchecks by applying the maximum of any
+You can customize the verbosity of the logs that are sent to Healthchecks with
-other borgmatic verbosity levels (`--verbosity`, `--syslog-verbosity`, etc.),
+borgmatic's `--monitoring-verbosity` flag. The `--files` and `--stats` flags
-as there is not currently a dedicated Healthchecks verbosity setting.
+may also be of use. See `borgmatic --help` for more information.
 
 You can configure Healthchecks to notify you by a [variety of
 mechanisms](https://healthchecks.io/#welcome-integrations) when backups fail

tests/unit/commands/test_borgmatic.py

@@ -13,7 +13,7 @@ def test_run_configuration_runs_actions_for_each_repository():
         expected_results[1:]
     )
     config = {'location': {'repositories': ['foo', 'bar']}}
-    arguments = {'global': flexmock()}
+    arguments = {'global': flexmock(monitoring_verbosity=1)}
 
     results = list(module.run_configuration('test.yaml', config, arguments))
 
@@ -26,7 +26,7 @@ def test_run_configuration_calls_hooks_for_prune_action():
     flexmock(module.dispatch).should_receive('call_hooks').at_least().twice()
     flexmock(module).should_receive('run_actions').and_return([])
     config = {'location': {'repositories': ['foo']}}
-    arguments = {'global': flexmock(dry_run=False), 'prune': flexmock()}
+    arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'prune': flexmock()}
 
     list(module.run_configuration('test.yaml', config, arguments))
 
@@ -37,7 +37,7 @@ def test_run_configuration_executes_and_calls_hooks_for_create_action():
     flexmock(module.dispatch).should_receive('call_hooks').at_least().twice()
     flexmock(module).should_receive('run_actions').and_return([])
     config = {'location': {'repositories': ['foo']}}
-    arguments = {'global': flexmock(dry_run=False), 'create': flexmock()}
+    arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()}
 
     list(module.run_configuration('test.yaml', config, arguments))
 
@@ -48,7 +48,7 @@ def test_run_configuration_calls_hooks_for_check_action():
     flexmock(module.dispatch).should_receive('call_hooks').at_least().twice()
     flexmock(module).should_receive('run_actions').and_return([])
     config = {'location': {'repositories': ['foo']}}
-    arguments = {'global': flexmock(dry_run=False), 'check': flexmock()}
+    arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'check': flexmock()}
 
     list(module.run_configuration('test.yaml', config, arguments))
 
@@ -59,7 +59,7 @@ def test_run_configuration_does_not_trigger_hooks_for_list_action():
     flexmock(module.dispatch).should_receive('call_hooks').never()
     flexmock(module).should_receive('run_actions').and_return([])
     config = {'location': {'repositories': ['foo']}}
-    arguments = {'global': flexmock(dry_run=False), 'list': flexmock()}
+    arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'list': flexmock()}
 
     list(module.run_configuration('test.yaml', config, arguments))
 
@@ -72,7 +72,7 @@ def test_run_configuration_logs_actions_error():
     flexmock(module).should_receive('make_error_log_records').and_return(expected_results)
     flexmock(module).should_receive('run_actions').and_raise(OSError)
     config = {'location': {'repositories': ['foo']}}
-    arguments = {'global': flexmock(dry_run=False)}
+    arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False)}
 
     results = list(module.run_configuration('test.yaml', config, arguments))
 
@@ -86,7 +86,7 @@ def test_run_configuration_logs_pre_hook_error():
     flexmock(module).should_receive('make_error_log_records').and_return(expected_results)
     flexmock(module).should_receive('run_actions').never()
     config = {'location': {'repositories': ['foo']}}
-    arguments = {'global': flexmock(dry_run=False), 'create': flexmock()}
+    arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()}
 
     results = list(module.run_configuration('test.yaml', config, arguments))
 
@@ -103,7 +103,7 @@ def test_run_configuration_logs_post_hook_error():
     flexmock(module).should_receive('make_error_log_records').and_return(expected_results)
     flexmock(module).should_receive('run_actions').and_return([])
     config = {'location': {'repositories': ['foo']}}
-    arguments = {'global': flexmock(dry_run=False), 'create': flexmock()}
+    arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()}
 
     results = list(module.run_configuration('test.yaml', config, arguments))
 
@@ -119,7 +119,7 @@ def test_run_configuration_logs_on_error_hook_error():
     ).and_return(expected_results[1:])
     flexmock(module).should_receive('run_actions').and_raise(OSError)
     config = {'location': {'repositories': ['foo']}}
-    arguments = {'global': flexmock(dry_run=False), 'create': flexmock()}
+    arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()}
 
     results = list(module.run_configuration('test.yaml', config, arguments))
 
@@ -228,7 +228,7 @@ def test_collect_configuration_run_summary_logs_info_for_success():
 
 def test_collect_configuration_run_summary_executes_hooks_for_create():
     flexmock(module).should_receive('run_configuration').and_return([])
-    arguments = {'create': flexmock(), 'global': flexmock(dry_run=False)}
+    arguments = {'create': flexmock(), 'global': flexmock(monitoring_verbosity=1, dry_run=False)}
 
     logs = tuple(
         module.collect_configuration_run_summary_logs({'test.yaml': {}}, arguments=arguments)
@@ -305,7 +305,7 @@ def test_collect_configuration_run_summary_logs_pre_hook_error():
     flexmock(module.command).should_receive('execute_hook').and_raise(ValueError)
     expected_logs = (flexmock(),)
     flexmock(module).should_receive('make_error_log_records').and_return(expected_logs)
-    arguments = {'create': flexmock(), 'global': flexmock(dry_run=False)}
+    arguments = {'create': flexmock(), 'global': flexmock(monitoring_verbosity=1, dry_run=False)}
 
     logs = tuple(
         module.collect_configuration_run_summary_logs({'test.yaml': {}}, arguments=arguments)
@@ -319,7 +319,7 @@ def test_collect_configuration_run_summary_logs_post_hook_error():
     flexmock(module).should_receive('run_configuration').and_return([])
     expected_logs = (flexmock(),)
     flexmock(module).should_receive('make_error_log_records').and_return(expected_logs)
-    arguments = {'create': flexmock(), 'global': flexmock(dry_run=False)}
+    arguments = {'create': flexmock(), 'global': flexmock(monitoring_verbosity=1, dry_run=False)}
 
     logs = tuple(
         module.collect_configuration_run_summary_logs({'test.yaml': {}}, arguments=arguments)

tests/unit/hooks/test_cronhub.py

@@ -7,32 +7,42 @@ def test_ping_monitor_rewrites_ping_url_for_start_state():
     ping_url = 'https://example.com/start/abcdef'
     flexmock(module.requests).should_receive('get').with_args('https://example.com/start/abcdef')
 
-    module.ping_monitor(ping_url, 'config.yaml', module.monitor.State.START, dry_run=False)
+    module.ping_monitor(
+        ping_url, 'config.yaml', module.monitor.State.START, monitoring_log_level=1, dry_run=False
+    )
 
 
 def test_ping_monitor_rewrites_ping_url_and_state_for_start_state():
     ping_url = 'https://example.com/ping/abcdef'
     flexmock(module.requests).should_receive('get').with_args('https://example.com/start/abcdef')
 
-    module.ping_monitor(ping_url, 'config.yaml', module.monitor.State.START, dry_run=False)
+    module.ping_monitor(
+        ping_url, 'config.yaml', module.monitor.State.START, monitoring_log_level=1, dry_run=False
+    )
 
 
 def test_ping_monitor_rewrites_ping_url_for_finish_state():
     ping_url = 'https://example.com/start/abcdef'
     flexmock(module.requests).should_receive('get').with_args('https://example.com/finish/abcdef')
 
-    module.ping_monitor(ping_url, 'config.yaml', module.monitor.State.FINISH, dry_run=False)
+    module.ping_monitor(
+        ping_url, 'config.yaml', module.monitor.State.FINISH, monitoring_log_level=1, dry_run=False
+    )
 
 
 def test_ping_monitor_rewrites_ping_url_for_fail_state():
     ping_url = 'https://example.com/start/abcdef'
     flexmock(module.requests).should_receive('get').with_args('https://example.com/fail/abcdef')
 
-    module.ping_monitor(ping_url, 'config.yaml', module.monitor.State.FAIL, dry_run=False)
+    module.ping_monitor(
+        ping_url, 'config.yaml', module.monitor.State.FAIL, monitoring_log_level=1, dry_run=False
+    )
 
 
 def test_ping_monitor_dry_run_does_not_hit_ping_url():
     ping_url = 'https://example.com'
     flexmock(module.requests).should_receive('get').never()
 
-    module.ping_monitor(ping_url, 'config.yaml', module.monitor.State.START, dry_run=True)
+    module.ping_monitor(
+        ping_url, 'config.yaml', module.monitor.State.START, monitoring_log_level=1, dry_run=True
+    )

tests/unit/hooks/test_cronitor.py

@@ -7,25 +7,33 @@ def test_ping_monitor_hits_ping_url_for_start_state():
     ping_url = 'https://example.com'
     flexmock(module.requests).should_receive('get').with_args('{}/{}'.format(ping_url, 'run'))
 
-    module.ping_monitor(ping_url, 'config.yaml', module.monitor.State.START, dry_run=False)
+    module.ping_monitor(
+        ping_url, 'config.yaml', module.monitor.State.START, monitoring_log_level=1, dry_run=False
+    )
 
 
 def test_ping_monitor_hits_ping_url_for_finish_state():
     ping_url = 'https://example.com'
     flexmock(module.requests).should_receive('get').with_args('{}/{}'.format(ping_url, 'complete'))
 
-    module.ping_monitor(ping_url, 'config.yaml', module.monitor.State.FINISH, dry_run=False)
+    module.ping_monitor(
+        ping_url, 'config.yaml', module.monitor.State.FINISH, monitoring_log_level=1, dry_run=False
+    )
 
 
 def test_ping_monitor_hits_ping_url_for_fail_state():
     ping_url = 'https://example.com'
     flexmock(module.requests).should_receive('get').with_args('{}/{}'.format(ping_url, 'fail'))
 
-    module.ping_monitor(ping_url, 'config.yaml', module.monitor.State.FAIL, dry_run=False)
+    module.ping_monitor(
+        ping_url, 'config.yaml', module.monitor.State.FAIL, monitoring_log_level=1, dry_run=False
+    )
 
 
 def test_ping_monitor_dry_run_does_not_hit_ping_url():
     ping_url = 'https://example.com'
     flexmock(module.requests).should_receive('get').never()
 
-    module.ping_monitor(ping_url, 'config.yaml', module.monitor.State.START, dry_run=True)
+    module.ping_monitor(
+        ping_url, 'config.yaml', module.monitor.State.START, monitoring_log_level=1, dry_run=True
+    )

tests/unit/hooks/test_healthchecks.py

@@ -4,7 +4,7 @@ from borgmatic.hooks import healthchecks as module
 
 
 def test_forgetful_buffering_handler_emit_collects_log_records():
-    handler = module.Forgetful_buffering_handler(byte_capacity=100)
+    handler = module.Forgetful_buffering_handler(byte_capacity=100, log_level=1)
     handler.emit(flexmock(getMessage=lambda: 'foo'))
     handler.emit(flexmock(getMessage=lambda: 'bar'))
 
@@ -13,7 +13,7 @@ def test_forgetful_buffering_handler_emit_collects_log_records():
 
 
 def test_forgetful_buffering_handler_emit_forgets_log_records_when_capacity_reached():
-    handler = module.Forgetful_buffering_handler(byte_capacity=len('foo\nbar\n'))
+    handler = module.Forgetful_buffering_handler(byte_capacity=len('foo\nbar\n'), log_level=1)
     handler.emit(flexmock(getMessage=lambda: 'foo'))
     assert handler.buffer == ['foo\n']
     handler.emit(flexmock(getMessage=lambda: 'bar'))
@@ -26,7 +26,7 @@ def test_forgetful_buffering_handler_emit_forgets_log_records_when_capacity_reac
 
 
 def test_format_buffered_logs_for_payload_flattens_log_buffer():
-    handler = module.Forgetful_buffering_handler(byte_capacity=100)
+    handler = module.Forgetful_buffering_handler(byte_capacity=100, log_level=1)
     handler.buffer = ['foo\n', 'bar\n']
     flexmock(module.logging).should_receive('getLogger').and_return(flexmock(handlers=[handler]))
 
@@ -36,7 +36,7 @@ def test_format_buffered_logs_for_payload_flattens_log_buffer():
 
 
 def test_format_buffered_logs_for_payload_inserts_truncation_indicator_when_logs_forgotten():
-    handler = module.Forgetful_buffering_handler(byte_capacity=100)
+    handler = module.Forgetful_buffering_handler(byte_capacity=100, log_level=1)
     handler.buffer = ['foo\n', 'bar\n']
     handler.forgot = True
     flexmock(module.logging).should_receive('getLogger').and_return(flexmock(handlers=[handler]))
@@ -63,7 +63,13 @@ def test_ping_monitor_hits_ping_url_for_start_state():
         '{}/{}'.format(ping_url, 'start'), data=''.encode('utf-8')
     )
 
-    module.ping_monitor(ping_url, 'config.yaml', state=module.monitor.State.START, dry_run=False)
+    module.ping_monitor(
+        ping_url,
+        'config.yaml',
+        state=module.monitor.State.START,
+        monitoring_log_level=1,
+        dry_run=False,
+    )
 
 
 def test_ping_monitor_hits_ping_url_for_finish_state():
@@ -74,7 +80,13 @@ def test_ping_monitor_hits_ping_url_for_finish_state():
         ping_url, data=payload.encode('utf-8')
     )
 
-    module.ping_monitor(ping_url, 'config.yaml', state=module.monitor.State.FINISH, dry_run=False)
+    module.ping_monitor(
+        ping_url,
+        'config.yaml',
+        state=module.monitor.State.FINISH,
+        monitoring_log_level=1,
+        dry_run=False,
+    )
 
 
 def test_ping_monitor_hits_ping_url_for_fail_state():
@@ -85,7 +97,13 @@ def test_ping_monitor_hits_ping_url_for_fail_state():
         '{}/{}'.format(ping_url, 'fail'), data=payload.encode('utf')
     )
 
-    module.ping_monitor(ping_url, 'config.yaml', state=module.monitor.State.FAIL, dry_run=False)
+    module.ping_monitor(
+        ping_url,
+        'config.yaml',
+        state=module.monitor.State.FAIL,
+        monitoring_log_level=1,
+        dry_run=False,
+    )
 
 
 def test_ping_monitor_with_ping_uuid_hits_corresponding_url():
@@ -96,7 +114,13 @@ def test_ping_monitor_with_ping_uuid_hits_corresponding_url():
         'https://hc-ping.com/{}'.format(ping_uuid), data=payload.encode('utf-8')
     )
 
-    module.ping_monitor(ping_uuid, 'config.yaml', state=module.monitor.State.FINISH, dry_run=False)
+    module.ping_monitor(
+        ping_uuid,
+        'config.yaml',
+        state=module.monitor.State.FINISH,
+        monitoring_log_level=1,
+        dry_run=False,
+    )
 
 
 def test_ping_monitor_dry_run_does_not_hit_ping_url():
@@ -104,4 +128,10 @@ def test_ping_monitor_dry_run_does_not_hit_ping_url():
     ping_url = 'https://example.com'
     flexmock(module.requests).should_receive('post').never()
 
-    module.ping_monitor(ping_url, 'config.yaml', state=module.monitor.State.START, dry_run=True)
+    module.ping_monitor(
+        ping_url,
+        'config.yaml',
+        state=module.monitor.State.START,
+        monitoring_log_level=1,
+        dry_run=True,
+    )