Fix for the Loki monitoring hook not respecting the monitoring verbosity (#1257).

NEWS

@@ -3,6 +3,7 @@
    to install borgmatic. Consider this binary a beta feature.
  * #1286: Fix a regression in which running borgmatic with no arguments and no configuration files
    doesn't error as expected.
+ * #1257: Fix for the Loki monitoring hook not respecting the monitoring verbosity.
  * When Borg exits with a warning exit code, show a description of it, so you don't have to lookup
    the code.
  * Split out borgmatic installation documentation to its own page, so it's easier to find.

borgmatic/commands/borgmatic.py

@@ -1123,7 +1123,7 @@ def main(extra_summary_logs=()):  # pragma: no cover
         exit_with_help_link()
     except SystemExit as error:
         if error.code == 0:
-            raise error
+            raise
 
         configure_logging(logging.CRITICAL)
         logger.critical(f"Error parsing arguments: {' '.join(sys.argv)}")

borgmatic/config/arguments.py

@@ -116,7 +116,7 @@ def convert_value_type(value, option_type):
         raise ValueError(f'Argument value "{value}" is invalid: {error.problem}')
 
     if not isinstance(parsed_value, borgmatic.config.schema.parse_type(option_type)):
-        raise ValueError(f'Argument value "{value}" is not of the expected type: {option_type}')
+        raise ValueError(f'Argument value "{value}" is not of the expected type: {option_type}')  # noqa: TRY004
 
     return parsed_value
 

borgmatic/config/load.py

@@ -84,7 +84,7 @@ def raise_retain_node_error(loader, node):
     Also raise ValueError if a scalar node is given, as "!retain" is not supported on scalar nodes.
     '''
     if isinstance(node, (ruamel.yaml.nodes.MappingNode, ruamel.yaml.nodes.SequenceNode)):
-        raise ValueError(
+        raise ValueError(  # noqa: TRY004
             'The !retain tag may only be used within a configuration file containing a merged !include tag.',
         )
 

borgmatic/execute.py

@@ -681,7 +681,7 @@ def execute_command_and_capture_output(
         return
 
     with borgmatic.logger.Log_prefix(None):  # Log command output without any prefix.
-        captured_lines = log_outputs(
+        yield from log_outputs(
             (process,),
             (input_file,),
             None,
@@ -690,8 +690,6 @@ def execute_command_and_capture_output(
             capture_stderr=capture_stderr,
         )
 
-    yield from captured_lines
-
 
 def execute_command_with_processes(
     full_command,
@@ -754,12 +752,10 @@ def execute_command_with_processes(
         raise
 
     with borgmatic.logger.Log_prefix(None):  # Log command output without any prefix.
-        captured_lines = log_outputs(
+        yield from log_outputs(
             (*processes, command_process),
             (input_file, output_file),
             output_log_level,
             borg_local_path,
             borg_exit_codes,
         )
-
-    yield from captured_lines

borgmatic/hooks/monitoring/loki.py

@@ -88,16 +88,17 @@ class Loki_log_handler(logging.Handler):
     A log handler that sends logs to Loki.
     '''
 
-    def __init__(self, url, send_logs, dry_run):
+    def __init__(self, url, send_logs, log_level, dry_run):
         '''
         Given a URL to send logs to, whether all borgmatic logs should be sent (or just explicitly
-        added messages from this hook), and whether this is a dry run, create an instance of
-        Loki_log_buffer.
+        added messages from this hook), the log level to use (influencing which logs get sent), and
+        whether this is a dry run, create an instance of Loki_log_buffer.
         '''
         super().__init__()
 
         self.buffer = Loki_log_buffer(url, dry_run)
         self.send_logs = send_logs
+        self.setLevel(log_level)
 
     def emit(self, record):
         '''
@@ -138,7 +139,7 @@ def initialize_monitor(hook_config, config, config_filename, monitoring_log_leve
     Add a handler to the root logger to regularly send the logs to Loki.
     '''
     url = hook_config.get('url')
-    loki = Loki_log_handler(url, hook_config.get('send_logs', False), dry_run)
+    loki = Loki_log_handler(url, hook_config.get('send_logs', False), monitoring_log_level, dry_run)
 
     for key, value in hook_config.get('labels').items():
         if value == '__hostname':
@@ -150,7 +151,9 @@ def initialize_monitor(hook_config, config, config_filename, monitoring_log_leve
         else:
             loki.add_label(key, value)
 
-    logging.getLogger().addHandler(loki)
+    global_logger = logging.getLogger()
+    global_logger.addHandler(loki)
+    global_logger.setLevel(min(handler.level for handler in global_logger.handlers))
 
 
 def ping_monitor(hook_config, config, config_filename, state, monitoring_log_level, dry_run):
@@ -166,9 +169,11 @@ def destroy_monitor(hook_config, config, monitoring_log_level, dry_run):
     '''
     Remove the monitor handler that was added to the root logger.
     '''
-    logger = logging.getLogger()
+    global_logger = logging.getLogger()
 
-    for handler in tuple(logger.handlers):
+    for handler in tuple(global_logger.handlers):
         if isinstance(handler, Loki_log_handler):
             handler.flush()
-            logger.removeHandler(handler)
+            global_logger.removeHandler(handler)
+
+    global_logger.setLevel(min(handler.level for handler in global_logger.handlers))

tests/integration/hooks/monitoring/test_loki.py

@@ -8,7 +8,7 @@ from borgmatic.hooks.monitoring import loki as module
 
 
 def test_loki_log_handler_raw_with_send_logs_posts_to_server_after_buffer_full():
-    handler = module.Loki_log_handler(flexmock(), send_logs=True, dry_run=False)
+    handler = module.Loki_log_handler(flexmock(), send_logs=True, log_level=10, dry_run=False)
     flexmock(module.requests).should_receive('post').and_return(
         flexmock(raise_for_status=lambda: ''),
     ).once()
@@ -18,7 +18,7 @@ def test_loki_log_handler_raw_with_send_logs_posts_to_server_after_buffer_full()
 
 
 def test_loki_log_handler_raw_without_send_logs_posts_to_server_without_buffering():
-    handler = module.Loki_log_handler(flexmock(), send_logs=False, dry_run=False)
+    handler = module.Loki_log_handler(flexmock(), send_logs=False, log_level=10, dry_run=False)
     flexmock(module.requests).should_receive('post').and_return(
         flexmock(raise_for_status=lambda: ''),
     ).times(3)
@@ -28,7 +28,7 @@ def test_loki_log_handler_raw_without_send_logs_posts_to_server_without_bufferin
 
 
 def test_loki_log_handler_raw_post_failure_does_not_raise():
-    handler = module.Loki_log_handler(flexmock(), send_logs=True, dry_run=False)
+    handler = module.Loki_log_handler(flexmock(), send_logs=True, log_level=10, dry_run=False)
     flexmock(module.requests).should_receive('post').and_return(
         flexmock(raise_for_status=lambda: (_ for _ in ()).throw(requests.RequestException())),
     ).once()
@@ -46,7 +46,10 @@ def test_initialize_monitor_replaces_labels():
         'labels': {'hostname': '__hostname', 'config': '__config', 'config_full': '__config_path'},
     }
     config_filename = '/mock/path/test.yaml'
-    module.initialize_monitor(hook_config, flexmock(), config_filename, flexmock(), dry_run=False)
+    flexmock(module.logging.getLogger()).should_receive('setLevel')
+    module.initialize_monitor(
+        hook_config, flexmock(), config_filename, monitoring_log_level=10, dry_run=False
+    )
 
     for handler in tuple(logging.getLogger().handlers):
         if isinstance(handler, module.Loki_log_handler):
@@ -63,11 +66,12 @@ def test_initialize_monitor_adds_log_handler():
     Assert that calling initialize_monitor adds our logger to the root logger.
     '''
     hook_config = {'url': 'http://localhost:3100/loki/api/v1/push', 'labels': {'app': 'borgmatic'}}
+    flexmock(module.logging.getLogger()).should_receive('setLevel')
     module.initialize_monitor(
         hook_config,
         flexmock(),
         config_filename='test.yaml',
-        monitoring_log_level=flexmock(),
+        monitoring_log_level=10,
         dry_run=True,
     )
 
@@ -99,7 +103,10 @@ def test_ping_monitor_sends_log_message():
 
     flexmock(module.requests).should_receive('post').replace_with(post)
 
-    module.initialize_monitor(hook_config, flexmock(), config_filename, flexmock(), dry_run=False)
+    flexmock(module.logging.getLogger()).should_receive('setLevel')
+    module.initialize_monitor(
+        hook_config, flexmock(), config_filename, monitoring_log_level=10, dry_run=False
+    )
     module.ping_monitor(
         hook_config,
         flexmock(),
@@ -108,7 +115,7 @@ def test_ping_monitor_sends_log_message():
         flexmock(),
         dry_run=False,
     )
-    module.destroy_monitor(hook_config, flexmock(), flexmock(), dry_run=False)
+    module.destroy_monitor(hook_config, flexmock(), monitoring_log_level=10, dry_run=False)
 
     assert post_called
 
@@ -121,9 +128,11 @@ def test_destroy_monitor_removes_log_handler():
     config_filename = 'test.yaml'
     flexmock(module.requests).should_receive('post').never()
 
-    module.initialize_monitor(hook_config, flexmock(), config_filename, flexmock(), dry_run=False)
-    module.destroy_monitor(hook_config, flexmock(), flexmock(), dry_run=False)
+    flexmock(module.logging.getLogger()).should_receive('setLevel')
+    module.initialize_monitor(
+        hook_config, flexmock(), config_filename, monitoring_log_level=10, dry_run=False
+    )
+    module.destroy_monitor(hook_config, flexmock(), monitoring_log_level=10, dry_run=False)
 
     for handler in tuple(logging.getLogger().handlers):
-        if isinstance(handler, module.Loki_log_handler):
-            raise AssertionError()
+        assert not isinstance(handler, module.Loki_log_handler)

tests/unit/config/test_normalize.py

@@ -47,11 +47,6 @@ from borgmatic.config import normalize as module
             {'prefix': 'foo'},
             True,
         ),
-        (
-            {'location': {'prefix': 'foo'}, 'consistency': {'prefix': 'foo'}},
-            {'prefix': 'foo'},
-            True,
-        ),
         (
             {'location': {'prefix': 'foo'}, 'consistency': {'bar': 'baz'}},
             {'prefix': 'foo', 'bar': 'baz'},
@@ -62,11 +57,6 @@ from borgmatic.config import normalize as module
             {'umask': 'foo'},
             True,
         ),
-        (
-            {'storage': {'umask': 'foo'}, 'hooks': {'umask': 'foo'}},
-            {'umask': 'foo'},
-            True,
-        ),
         (
             {'storage': {'umask': 'foo'}, 'hooks': {'bar': 'baz'}},
             {'umask': 'foo', 'bar': 'baz'},
@@ -288,11 +278,6 @@ def test_normalize_commands_moves_individual_command_hooks_to_unified_commands(
             {'checks': [{'name': 'archives'}]},
             True,
         ),
-        (
-            {'checks': ['archives']},
-            {'checks': [{'name': 'archives'}]},
-            True,
-        ),
         (
             {'numeric_owner': False},
             {'numeric_ids': False},

tests/unit/hooks/monitoring/test_loki.py

@@ -50,10 +50,7 @@ def test_loki_log_buffer_json_serializes_log_lines():
     assert json.loads(buffer.to_request())['streams'][0]['values'][0][1] == 'Some test log line'
 
 
-def test_loki_log_handler_add_label_gets_labels():
-    '''
-    Assert that adding labels works.
-    '''
+def test_loki_log_buffer_add_label_gets_labels():
     buffer = module.Loki_log_buffer(flexmock(), dry_run=False)
 
     buffer.add_label('test', 'label')
@@ -64,22 +61,20 @@ def test_loki_log_handler_add_label_gets_labels():
 
 
 def test_loki_log_handler_emit_with_send_logs_records_log_message():
-    handler = module.Loki_log_handler(flexmock(), send_logs=True, dry_run=False)
+    handler = module.Loki_log_handler(flexmock(), send_logs=True, log_level=10, dry_run=False)
     flexmock(handler).should_receive('raw').once()
 
     handler.emit(flexmock(getMessage=lambda: 'Some test log line'))
 
 
 def test_loki_log_handler_emit_without_send_logs_skips_log_message():
-    handler = module.Loki_log_handler(flexmock(), send_logs=False, dry_run=False)
+    handler = module.Loki_log_handler(flexmock(), send_logs=False, log_level=10, dry_run=False)
     flexmock(handler).should_receive('raw').never()
 
     handler.emit(flexmock(getMessage=lambda: 'Some test log line'))
 
 
 def test_loki_log_handler_flush_with_empty_buffer_does_not_raise():
-    '''
-    Test that flushing an empty buffer does indeed nothing.
-    '''
-    handler = module.Loki_log_handler(flexmock(), send_logs=False, dry_run=False)
+    handler = module.Loki_log_handler(flexmock(), send_logs=False, log_level=10, dry_run=False)
+
     handler.flush()

tests/unit/test_execute.py

@@ -31,8 +31,6 @@ def test_command_is_borg_matches_local_path_to_command(command, borg_local_path,
         (False, 1, None, module.Exit_status.ERROR),
         (True, 1, None, module.Exit_status.WARNING),
         (False, 100, None, module.Exit_status.ERROR),
-        (False, 2, None, module.Exit_status.ERROR),
-        (True, 2, None, module.Exit_status.ERROR),
         (True, 100, None, module.Exit_status.WARNING),
         (False, 0, None, module.Exit_status.SUCCESS),
         (True, 0, None, module.Exit_status.SUCCESS),