Log Borg --stats output as warning so it shows up at any verbosity level.

borgmatic/borg/create.py

@@ -162,4 +162,4 @@ def create_archive(
         + (('--json',) if json else ())
     )
 
-    return execute_command(full_command, capture_output=json)
+    return execute_command(full_command, capture_output=json, output_as_warning=stats and not json)

borgmatic/borg/execute.py

@@ -5,24 +5,28 @@ from borgmatic.logger import get_logger
 logger = get_logger(__name__)
 
 
-def execute_and_log_output(full_command):
+def execute_and_log_output(full_command, output_as_warning=False):
     process = subprocess.Popen(full_command, stdout=None, stderr=subprocess.PIPE)
 
     while process.poll() is None:
         line = process.stderr.readline().rstrip().decode()
         if line.startswith('borg: error:'):
             logger.error(line)
+        elif output_as_warning:
+            logger.warning(line)
         else:
             logger.info(line)
 
-    logger.info(process.stderr.read().rstrip().decode())
-    exit_code = process.poll()
+    remaining_output = process.stderr.read().rstrip().decode()
+    if remaining_output:
+        logger.info(remaining_output)
 
+    exit_code = process.poll()
     if exit_code != 0:
         raise subprocess.CalledProcessError(exit_code, full_command)
 
 
-def execute_command(full_command, capture_output=False):
+def execute_command(full_command, capture_output=False, output_as_warning=False):
     '''
     Execute the given command (a sequence of command/argument strings). If capture output is True,
     then return the command's output as a string.
@@ -33,4 +37,4 @@ def execute_command(full_command, capture_output=False):
         output = subprocess.check_output(full_command)
         return output.decode() if output is not None else None
     else:
-        execute_and_log_output(full_command)
+        execute_and_log_output(full_command, output_as_warning)

tests/unit/borg/test_create.py

@@ -166,7 +166,7 @@ def test_create_archive_calls_borg_with_parameters():
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        CREATE_COMMAND, capture_output=False
+        CREATE_COMMAND, capture_output=False, output_as_warning=False
     )
 
     module.create_archive(
@@ -191,7 +191,7 @@ def test_create_archive_with_patterns_calls_borg_with_patterns():
     flexmock(module).should_receive('_make_pattern_flags').and_return(pattern_flags)
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        CREATE_COMMAND + pattern_flags, capture_output=False
+        CREATE_COMMAND + pattern_flags, capture_output=False, output_as_warning=False
     )
 
     module.create_archive(
@@ -216,7 +216,7 @@ def test_create_archive_with_exclude_patterns_calls_borg_with_excludes():
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(exclude_flags)
     flexmock(module).should_receive('execute_command').with_args(
-        CREATE_COMMAND + exclude_flags, capture_output=False
+        CREATE_COMMAND + exclude_flags, capture_output=False, output_as_warning=False
     )
 
     module.create_archive(
@@ -239,7 +239,9 @@ def test_create_archive_with_log_info_calls_borg_with_info_parameter():
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        CREATE_COMMAND + ('--list', '--filter', 'AME-', '--info', '--stats'), capture_output=False
+        CREATE_COMMAND + ('--list', '--filter', 'AME-', '--info', '--stats'),
+        capture_output=False,
+        output_as_warning=False,
     )
     insert_logging_mock(logging.INFO)
 
@@ -263,7 +265,7 @@ def test_create_archive_with_log_info_and_json_suppresses_most_borg_output():
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        CREATE_COMMAND + ('--json',), capture_output=True
+        CREATE_COMMAND + ('--json',), capture_output=True, output_as_warning=False
     )
     insert_logging_mock(logging.INFO)
 
@@ -289,6 +291,7 @@ def test_create_archive_with_log_debug_calls_borg_with_debug_parameter():
     flexmock(module).should_receive('execute_command').with_args(
         CREATE_COMMAND + ('--list', '--filter', 'AME-', '--stats', '--debug', '--show-rc'),
         capture_output=False,
+        output_as_warning=False,
     )
     insert_logging_mock(logging.DEBUG)
 
@@ -311,7 +314,7 @@ def test_create_archive_with_log_debug_and_json_suppresses_most_borg_output():
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        CREATE_COMMAND + ('--json',), capture_output=True
+        CREATE_COMMAND + ('--json',), capture_output=True, output_as_warning=False
     )
     insert_logging_mock(logging.DEBUG)
 
@@ -336,7 +339,7 @@ def test_create_archive_with_dry_run_calls_borg_with_dry_run_parameter():
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        CREATE_COMMAND + ('--dry-run',), capture_output=False
+        CREATE_COMMAND + ('--dry-run',), capture_output=False, output_as_warning=False
     )
 
     module.create_archive(
@@ -361,7 +364,9 @@ def test_create_archive_with_dry_run_and_log_info_calls_borg_without_stats_param
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        CREATE_COMMAND + ('--list', '--filter', 'AME-', '--info', '--dry-run'), capture_output=False
+        CREATE_COMMAND + ('--list', '--filter', 'AME-', '--info', '--dry-run'),
+        capture_output=False,
+        output_as_warning=False,
     )
     insert_logging_mock(logging.INFO)
 
@@ -389,6 +394,7 @@ def test_create_archive_with_dry_run_and_log_debug_calls_borg_without_stats_para
     flexmock(module).should_receive('execute_command').with_args(
         CREATE_COMMAND + ('--list', '--filter', 'AME-', '--debug', '--show-rc', '--dry-run'),
         capture_output=False,
+        output_as_warning=False,
     )
     insert_logging_mock(logging.DEBUG)
 
@@ -411,7 +417,9 @@ def test_create_archive_with_checkpoint_interval_calls_borg_with_checkpoint_inte
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        CREATE_COMMAND + ('--checkpoint-interval', '600'), capture_output=False
+        CREATE_COMMAND + ('--checkpoint-interval', '600'),
+        capture_output=False,
+        output_as_warning=False,
     )
 
     module.create_archive(
@@ -433,7 +441,9 @@ def test_create_archive_with_chunker_params_calls_borg_with_chunker_params_param
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        CREATE_COMMAND + ('--chunker-params', '1,2,3,4'), capture_output=False
+        CREATE_COMMAND + ('--chunker-params', '1,2,3,4'),
+        capture_output=False,
+        output_as_warning=False,
     )
 
     module.create_archive(
@@ -455,7 +465,7 @@ def test_create_archive_with_compression_calls_borg_with_compression_parameters(
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        CREATE_COMMAND + ('--compression', 'rle'), capture_output=False
+        CREATE_COMMAND + ('--compression', 'rle'), capture_output=False, output_as_warning=False
     )
 
     module.create_archive(
@@ -477,7 +487,9 @@ def test_create_archive_with_remote_rate_limit_calls_borg_with_remote_ratelimit_
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        CREATE_COMMAND + ('--remote-ratelimit', '100'), capture_output=False
+        CREATE_COMMAND + ('--remote-ratelimit', '100'),
+        capture_output=False,
+        output_as_warning=False,
     )
 
     module.create_archive(
@@ -499,7 +511,7 @@ def test_create_archive_with_one_file_system_calls_borg_with_one_file_system_par
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        CREATE_COMMAND + ('--one-file-system',), capture_output=False
+        CREATE_COMMAND + ('--one-file-system',), capture_output=False, output_as_warning=False
     )
 
     module.create_archive(
@@ -522,7 +534,7 @@ def test_create_archive_with_numeric_owner_calls_borg_with_numeric_owner_paramet
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        CREATE_COMMAND + ('--numeric-owner',), capture_output=False
+        CREATE_COMMAND + ('--numeric-owner',), capture_output=False, output_as_warning=False
     )
 
     module.create_archive(
@@ -545,7 +557,7 @@ def test_create_archive_with_read_special_calls_borg_with_read_special_parameter
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        CREATE_COMMAND + ('--read-special',), capture_output=False
+        CREATE_COMMAND + ('--read-special',), capture_output=False, output_as_warning=False
     )
 
     module.create_archive(
@@ -568,7 +580,7 @@ def test_create_archive_with_bsd_flags_true_calls_borg_without_nobsdflags_parame
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        CREATE_COMMAND, capture_output=False
+        CREATE_COMMAND, capture_output=False, output_as_warning=False
     )
 
     module.create_archive(
@@ -591,7 +603,7 @@ def test_create_archive_with_bsd_flags_false_calls_borg_with_nobsdflags_paramete
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        CREATE_COMMAND + ('--nobsdflags',), capture_output=False
+        CREATE_COMMAND + ('--nobsdflags',), capture_output=False, output_as_warning=False
     )
 
     module.create_archive(
@@ -614,7 +626,9 @@ def test_create_archive_with_files_cache_calls_borg_with_files_cache_parameters(
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        CREATE_COMMAND + ('--files-cache', 'ctime,size'), capture_output=False
+        CREATE_COMMAND + ('--files-cache', 'ctime,size'),
+        capture_output=False,
+        output_as_warning=False,
     )
 
     module.create_archive(
@@ -637,7 +651,7 @@ def test_create_archive_with_local_path_calls_borg_via_local_path():
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        ('borg1',) + CREATE_COMMAND[1:], capture_output=False
+        ('borg1',) + CREATE_COMMAND[1:], capture_output=False, output_as_warning=False
     )
 
     module.create_archive(
@@ -660,7 +674,7 @@ def test_create_archive_with_remote_path_calls_borg_with_remote_path_parameters(
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        CREATE_COMMAND + ('--remote-path', 'borg1'), capture_output=False
+        CREATE_COMMAND + ('--remote-path', 'borg1'), capture_output=False, output_as_warning=False
     )
 
     module.create_archive(
@@ -683,7 +697,7 @@ def test_create_archive_with_umask_calls_borg_with_umask_parameters():
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        CREATE_COMMAND + ('--umask', '740'), capture_output=False
+        CREATE_COMMAND + ('--umask', '740'), capture_output=False, output_as_warning=False
     )
 
     module.create_archive(
@@ -705,7 +719,7 @@ def test_create_archive_with_lock_wait_calls_borg_with_lock_wait_parameters():
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        CREATE_COMMAND + ('--lock-wait', '5'), capture_output=False
+        CREATE_COMMAND + ('--lock-wait', '5'), capture_output=False, output_as_warning=False
     )
 
     module.create_archive(
@@ -720,6 +734,29 @@ def test_create_archive_with_lock_wait_calls_borg_with_lock_wait_parameters():
     )
 
 
+def test_create_archive_with_stats_calls_borg_with_stats_parameter():
+    flexmock(module).should_receive('_expand_directories').and_return(('foo', 'bar'))
+    flexmock(module).should_receive('_expand_home_directories').and_return(())
+    flexmock(module).should_receive('_write_pattern_file').and_return(None)
+    flexmock(module).should_receive('_make_pattern_flags').and_return(())
+    flexmock(module).should_receive('_make_exclude_flags').and_return(())
+    flexmock(module).should_receive('execute_command').with_args(
+        CREATE_COMMAND + ('--stats',), capture_output=False, output_as_warning=True
+    )
+
+    module.create_archive(
+        dry_run=False,
+        repository='repo',
+        location_config={
+            'source_directories': ['foo', 'bar'],
+            'repositories': ['repo'],
+            'exclude_patterns': None,
+        },
+        storage_config={},
+        stats=True,
+    )
+
+
 def test_create_archive_with_json_calls_borg_with_json_parameter():
     flexmock(module).should_receive('_expand_directories').and_return(('foo', 'bar'))
     flexmock(module).should_receive('_expand_home_directories').and_return(())
@@ -727,7 +764,7 @@ def test_create_archive_with_json_calls_borg_with_json_parameter():
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        CREATE_COMMAND + ('--json',), capture_output=True
+        CREATE_COMMAND + ('--json',), capture_output=True, output_as_warning=False
     ).and_return('[]')
 
     json_output = module.create_archive(
@@ -745,6 +782,32 @@ def test_create_archive_with_json_calls_borg_with_json_parameter():
     assert json_output == '[]'
 
 
+def test_create_archive_with_stats_and_json_calls_borg_without_stats_parameter():
+    flexmock(module).should_receive('_expand_directories').and_return(('foo', 'bar'))
+    flexmock(module).should_receive('_expand_home_directories').and_return(())
+    flexmock(module).should_receive('_write_pattern_file').and_return(None)
+    flexmock(module).should_receive('_make_pattern_flags').and_return(())
+    flexmock(module).should_receive('_make_exclude_flags').and_return(())
+    flexmock(module).should_receive('execute_command').with_args(
+        CREATE_COMMAND + ('--json',), capture_output=True, output_as_warning=False
+    ).and_return('[]')
+
+    json_output = module.create_archive(
+        dry_run=False,
+        repository='repo',
+        location_config={
+            'source_directories': ['foo', 'bar'],
+            'repositories': ['repo'],
+            'exclude_patterns': None,
+        },
+        storage_config={},
+        json=True,
+        stats=True,
+    )
+
+    assert json_output == '[]'
+
+
 def test_create_archive_with_source_directories_glob_expands():
     flexmock(module).should_receive('_expand_directories').and_return(('foo', 'food'))
     flexmock(module).should_receive('_expand_home_directories').and_return(())
@@ -754,6 +817,7 @@ def test_create_archive_with_source_directories_glob_expands():
     flexmock(module).should_receive('execute_command').with_args(
         ('borg', 'create', 'repo::{}'.format(DEFAULT_ARCHIVE_NAME), 'foo', 'food'),
         capture_output=False,
+        output_as_warning=False,
     )
     flexmock(module.glob).should_receive('glob').with_args('foo*').and_return(['foo', 'food'])
 
@@ -776,7 +840,9 @@ def test_create_archive_with_non_matching_source_directories_glob_passes_through
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        ('borg', 'create', 'repo::{}'.format(DEFAULT_ARCHIVE_NAME), 'foo*'), capture_output=False
+        ('borg', 'create', 'repo::{}'.format(DEFAULT_ARCHIVE_NAME), 'foo*'),
+        capture_output=False,
+        output_as_warning=False,
     )
     flexmock(module.glob).should_receive('glob').with_args('foo*').and_return([])
 
@@ -801,6 +867,7 @@ def test_create_archive_with_glob_calls_borg_with_expanded_directories():
     flexmock(module).should_receive('execute_command').with_args(
         ('borg', 'create', 'repo::{}'.format(DEFAULT_ARCHIVE_NAME), 'foo', 'food'),
         capture_output=False,
+        output_as_warning=False,
     )
 
     module.create_archive(
@@ -822,7 +889,9 @@ def test_create_archive_with_archive_name_format_calls_borg_with_archive_name():
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        ('borg', 'create', 'repo::ARCHIVE_NAME', 'foo', 'bar'), capture_output=False
+        ('borg', 'create', 'repo::ARCHIVE_NAME', 'foo', 'bar'),
+        capture_output=False,
+        output_as_warning=False,
     )
 
     module.create_archive(
@@ -844,7 +913,9 @@ def test_create_archive_with_archive_name_format_accepts_borg_placeholders():
     flexmock(module).should_receive('_make_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
     flexmock(module).should_receive('execute_command').with_args(
-        ('borg', 'create', 'repo::Documents_{hostname}-{now}', 'foo', 'bar'), capture_output=False
+        ('borg', 'create', 'repo::Documents_{hostname}-{now}', 'foo', 'bar'),
+        capture_output=False,
+        output_as_warning=False,
     )
 
     module.create_archive(

tests/unit/borg/test_execute.py

@@ -5,7 +5,9 @@ from borgmatic.borg import execute as module
 
 def test_execute_command_calls_full_command():
     full_command = ['foo', 'bar']
-    flexmock(module).should_receive('execute_and_log_output').with_args(full_command).once()
+    flexmock(module).should_receive('execute_and_log_output').with_args(
+        full_command, output_as_warning=False
+    ).once()
 
     output = module.execute_command(full_command)