When color output is disabled (explicitly or implicitly), don't prefix each log line with the log level (#863).

NEWS

@@ -1,9 +1,14 @@
+1.8.12.dev0
+ * #860: Fix interaction between environment variable interpolation in constants and shell escaping.
+ * #863: When color output is disabled (explicitly or implicitly), don't prefix each log line with
+   the log level.
+
 1.8.11
  * #815: Add optional Healthchecks auto-provisioning via "create_slug" option.
  * #851: Fix lack of file extraction when using "extract --strip-components all" on a path with a
    leading slash.
  * #854: Fix a traceback when the "data" consistency check is used.
- # #857: Fix a traceback with "check --only spot" when the "spot" check is unconfigured.
+ * #857: Fix a traceback with "check --only spot" when the "spot" check is unconfigured.
 
 1.8.10
  * #656 (beta): Add a "spot" consistency check that compares file counts and contents between your

borgmatic/config/constants.py

@@ -50,12 +50,15 @@ def apply_constants(value, constants, shell_escape=False):
             value[index] = apply_constants(list_value, constants, shell_escape)
     elif isinstance(value, dict):
         for option_name, option_value in value.items():
-            shell_escape = (
-                shell_escape
-                or option_name.startswith('before_')
-                or option_name.startswith('after_')
-                or option_name == 'on_error'
+            value[option_name] = apply_constants(
+                option_value,
+                constants,
+                shell_escape=(
+                    shell_escape
+                    or option_name.startswith('before_')
+                    or option_name.startswith('after_')
+                    or option_name == 'on_error'
+                ),
             )
-            value[option_name] = apply_constants(option_value, constants, shell_escape)
 
     return value

borgmatic/logger.py

@@ -88,6 +88,11 @@ class Multi_stream_handler(logging.Handler):
             handler.setLevel(level)
 
 
+class Console_no_color_formatter(logging.Formatter):
+    def format(self, record):
+        return record.msg
+
+
 class Console_color_formatter(logging.Formatter):
     def format(self, record):
         add_custom_log_levels()
@@ -198,6 +203,8 @@ def configure_logging(
 
     if color_enabled:
         console_handler.setFormatter(Console_color_formatter())
+    else:
+        console_handler.setFormatter(Console_no_color_formatter())
 
     console_handler.setLevel(console_log_level)
 

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

@@ -420,7 +420,8 @@ pipx](https://torsion.org/borgmatic/docs/how-to/set-up-backups/#installation),
 run the following to install Apprise so borgmatic can use it:
 
 ```bash
-sudo pipx install --force borgmatic[Apprise]
+sudo pipx uninstall borgmatic
+sudo pipx install borgmatic[Apprise]
 ```
 
 Omit `sudo` if borgmatic is installed as a non-root user.

setup.py

@@ -1,6 +1,6 @@
 from setuptools import find_packages, setup
 
-VERSION = '1.8.11'
+VERSION = '1.8.12.dev0'
 
 
 setup(

tests/unit/config/test_constants.py

@@ -50,6 +50,16 @@ def test_apply_constants_with_empty_constants_passes_through_value():
         ({'before_backup': '{inject}'}, {'before_backup': "'echo hi; naughty-command'"}),
         ({'after_backup': '{inject}'}, {'after_backup': "'echo hi; naughty-command'"}),
         ({'on_error': '{inject}'}, {'on_error': "'echo hi; naughty-command'"}),
+        (
+            {
+                'before_backup': '{env_pass}',
+                'postgresql_databases': [{'name': 'users', 'password': '{env_pass}'}],
+            },
+            {
+                'before_backup': "'${PASS}'",
+                'postgresql_databases': [{'name': 'users', 'password': '${PASS}'}],
+            },
+        ),
         (3, 3),
         (True, True),
         (False, False),
@@ -63,6 +73,7 @@ def test_apply_constants_makes_string_substitutions(value, expected_value):
         'int': 3,
         'bool': True,
         'inject': 'echo hi; naughty-command',
+        'env_pass': '${PASS}',
     }
 
     assert module.apply_constants(value, constants) == expected_value

tests/unit/test_logger.py

@@ -217,10 +217,11 @@ def test_add_logging_level_skips_global_setting_if_already_set():
 def test_configure_logging_with_syslog_log_level_probes_for_log_socket_on_linux():
     flexmock(module).should_receive('add_custom_log_levels')
     flexmock(module.logging).ANSWER = module.ANSWER
+    fake_formatter = flexmock()
+    flexmock(module).should_receive('Console_color_formatter').and_return(fake_formatter)
     multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
-    multi_stream_handler.should_receive('setFormatter').once()
+    multi_stream_handler.should_receive('setFormatter').with_args(fake_formatter).once()
     flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
-    flexmock(module).should_receive('Console_color_formatter')
     flexmock(module).should_receive('interactive_console').and_return(False)
     flexmock(module.logging).should_receive('basicConfig').with_args(
         level=logging.DEBUG, handlers=list
@@ -237,10 +238,11 @@ def test_configure_logging_with_syslog_log_level_probes_for_log_socket_on_linux(
 def test_configure_logging_with_syslog_log_level_probes_for_log_socket_on_macos():
     flexmock(module).should_receive('add_custom_log_levels')
     flexmock(module.logging).ANSWER = module.ANSWER
+    fake_formatter = flexmock()
+    flexmock(module).should_receive('Console_color_formatter').and_return(fake_formatter)
     multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
-    multi_stream_handler.should_receive('setFormatter').once()
+    multi_stream_handler.should_receive('setFormatter').with_args(fake_formatter).once()
     flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
-    flexmock(module).should_receive('Console_color_formatter')
     flexmock(module).should_receive('interactive_console').and_return(False)
     flexmock(module.logging).should_receive('basicConfig').with_args(
         level=logging.DEBUG, handlers=list
@@ -258,10 +260,11 @@ def test_configure_logging_with_syslog_log_level_probes_for_log_socket_on_macos(
 def test_configure_logging_with_syslog_log_level_probes_for_log_socket_on_freebsd():
     flexmock(module).should_receive('add_custom_log_levels')
     flexmock(module.logging).ANSWER = module.ANSWER
+    fake_formatter = flexmock()
+    flexmock(module).should_receive('Console_color_formatter').and_return(fake_formatter)
     multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
-    multi_stream_handler.should_receive('setFormatter').once()
+    multi_stream_handler.should_receive('setFormatter').with_args(fake_formatter).once()
     flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
-    flexmock(module).should_receive('Console_color_formatter')
     flexmock(module).should_receive('interactive_console').and_return(False)
     flexmock(module.logging).should_receive('basicConfig').with_args(
         level=logging.DEBUG, handlers=list
@@ -280,10 +283,11 @@ def test_configure_logging_with_syslog_log_level_probes_for_log_socket_on_freebs
 def test_configure_logging_without_syslog_log_level_skips_syslog():
     flexmock(module).should_receive('add_custom_log_levels')
     flexmock(module.logging).ANSWER = module.ANSWER
+    fake_formatter = flexmock()
+    flexmock(module).should_receive('Console_color_formatter').and_return(fake_formatter)
     multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
-    multi_stream_handler.should_receive('setFormatter').once()
+    multi_stream_handler.should_receive('setFormatter').with_args(fake_formatter).once()
     flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
-    flexmock(module).should_receive('Console_color_formatter')
     flexmock(module.logging).should_receive('basicConfig').with_args(
         level=logging.INFO, handlers=list
     )
@@ -296,10 +300,11 @@ def test_configure_logging_without_syslog_log_level_skips_syslog():
 def test_configure_logging_skips_syslog_if_not_found():
     flexmock(module).should_receive('add_custom_log_levels')
     flexmock(module.logging).ANSWER = module.ANSWER
+    fake_formatter = flexmock()
+    flexmock(module).should_receive('Console_color_formatter').and_return(fake_formatter)
     multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
-    multi_stream_handler.should_receive('setFormatter').once()
+    multi_stream_handler.should_receive('setFormatter').with_args(fake_formatter).once()
     flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
-    flexmock(module).should_receive('Console_color_formatter')
     flexmock(module.logging).should_receive('basicConfig').with_args(
         level=logging.INFO, handlers=list
     )
@@ -312,8 +317,10 @@ def test_configure_logging_skips_syslog_if_not_found():
 def test_configure_logging_skips_log_file_if_log_file_logging_is_disabled():
     flexmock(module).should_receive('add_custom_log_levels')
     flexmock(module.logging).DISABLED = module.DISABLED
+    fake_formatter = flexmock()
+    flexmock(module).should_receive('Console_color_formatter').and_return(fake_formatter)
     multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
-    multi_stream_handler.should_receive('setFormatter').once()
+    multi_stream_handler.should_receive('setFormatter').with_args(fake_formatter).once()
     flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
 
     flexmock(module.logging).should_receive('basicConfig').with_args(
@@ -331,8 +338,10 @@ def test_configure_logging_skips_log_file_if_log_file_logging_is_disabled():
 def test_configure_logging_to_log_file_instead_of_syslog():
     flexmock(module).should_receive('add_custom_log_levels')
     flexmock(module.logging).ANSWER = module.ANSWER
+    fake_formatter = flexmock()
+    flexmock(module).should_receive('Console_color_formatter').and_return(fake_formatter)
     multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
-    multi_stream_handler.should_receive('setFormatter').once()
+    multi_stream_handler.should_receive('setFormatter').with_args(fake_formatter).once()
     flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
 
     flexmock(module.logging).should_receive('basicConfig').with_args(
@@ -356,8 +365,10 @@ def test_configure_logging_to_log_file_instead_of_syslog():
 def test_configure_logging_to_both_log_file_and_syslog():
     flexmock(module).should_receive('add_custom_log_levels')
     flexmock(module.logging).ANSWER = module.ANSWER
+    fake_formatter = flexmock()
+    flexmock(module).should_receive('Console_color_formatter').and_return(fake_formatter)
     multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
-    multi_stream_handler.should_receive('setFormatter').once()
+    multi_stream_handler.should_receive('setFormatter').with_args(fake_formatter).once()
     flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
 
     flexmock(module.logging).should_receive('basicConfig').with_args(
@@ -387,8 +398,10 @@ def test_configure_logging_to_log_file_formats_with_custom_log_format():
     flexmock(module.logging).should_receive('Formatter').with_args(
         '{message}', style='{'  # noqa: FS003
     ).once()
+    fake_formatter = flexmock()
+    flexmock(module).should_receive('Console_color_formatter').and_return(fake_formatter)
     multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
-    multi_stream_handler.should_receive('setFormatter').once()
+    multi_stream_handler.should_receive('setFormatter').with_args(fake_formatter).once()
     flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
 
     flexmock(module).should_receive('interactive_console').and_return(False)
@@ -413,8 +426,10 @@ def test_configure_logging_to_log_file_formats_with_custom_log_format():
 def test_configure_logging_skips_log_file_if_argument_is_none():
     flexmock(module).should_receive('add_custom_log_levels')
     flexmock(module.logging).ANSWER = module.ANSWER
+    fake_formatter = flexmock()
+    flexmock(module).should_receive('Console_color_formatter').and_return(fake_formatter)
     multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
-    multi_stream_handler.should_receive('setFormatter').once()
+    multi_stream_handler.should_receive('setFormatter').with_args(fake_formatter).once()
     flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
 
     flexmock(module.logging).should_receive('basicConfig').with_args(
@@ -426,11 +441,14 @@ def test_configure_logging_skips_log_file_if_argument_is_none():
     module.configure_logging(console_log_level=logging.INFO, log_file=None)
 
 
-def test_configure_logging_skips_console_color_formatter_if_color_disabled():
+def test_configure_logging_uses_console_no_color_formatter_if_color_disabled():
     flexmock(module).should_receive('add_custom_log_levels')
     flexmock(module.logging).ANSWER = module.ANSWER
+    fake_formatter = flexmock()
+    flexmock(module).should_receive('Console_color_formatter').never()
+    flexmock(module).should_receive('Console_no_color_formatter').and_return(fake_formatter)
     multi_stream_handler = flexmock(setLevel=lambda level: None, level=logging.INFO)
-    multi_stream_handler.should_receive('setFormatter').never()
+    multi_stream_handler.should_receive('setFormatter').with_args(fake_formatter).once()
     flexmock(module).should_receive('Multi_stream_handler').and_return(multi_stream_handler)
 
     flexmock(module.logging).should_receive('basicConfig').with_args(