Rework logging/verbosity system (#90)

Looks great, merged! Thanks again for all your hard work here.

AUTHORS

@@ -1,11 +1,12 @@
 Dan Helfman <witten@torsion.org>: Main developer
 
 Alexander Görtz: Python 3 compatibility
+Florian Lindner: Logging rewrite
 Henning Schroeder: Copy editing
 Johannes Feichtner: Support for user hooks
 Michele Lazzeri: Custom archive names
+Nick Whyte: Support prefix filtering for archive consistency checks
 newtonne: Read encryption password from external file
 Robin `ypid` Schneider: Support additional options of Borg
 Scott Squires: Custom archive names
 Thomas LÉVEIL: Support for a keep_minutely prune option. Support for the --json option
-Nick Whyte: Support prefix filtering for archive consistency checks

NEWS

@@ -4,6 +4,8 @@
  * #88: Fix declared pykwalify compatibility version range in setup.py to prevent use of ancient
    versions of pykwalify with large version numbers.
  * #89: Pass --show-rc option to Borg when at highest verbosity level.
+ * #90: Rewrite of logging system. Now verbosity flags passed to borg are derived from borgmatic's
+   log level. Note that the output of borgmatic might slightly change.
 
 1.2.2
  * #85: Fix compatibility issue between pykwalify and ruamel.yaml 0.15.52, which manifested in

borgmatic/borg/check.py

@@ -3,7 +3,6 @@ import os
 import subprocess
 
 from borgmatic.borg import extract
-from borgmatic.verbosity import VERBOSITY_SOME, VERBOSITY_LOTS
 
 
 DEFAULT_CHECKS = ('repository', 'archives')
@@ -74,12 +73,10 @@ def _make_check_flags(checks, check_last=None, prefix=None):
     ) + last_flags + prefix_flags
 
 
-def check_archives(verbosity, repository, storage_config, consistency_config, local_path='borg',
+def check_archives(repository, storage_config, consistency_config, local_path='borg', remote_path=None):
-                   remote_path=None):
     '''
-    Given a verbosity flag, a local or remote repository path, a storage config dict, a consistency
+    Given a local or remote repository path, a storage config dict, a consistency config dict, 
-    config dict, and a local/remote commands to run, check the contained Borg archives for
+    and a local/remote commands to run, check the contained Borg archives for consistency.
-    consistency.
 
     If there are no consistency checks to run, skip running them.
     '''
@@ -91,10 +88,13 @@ def check_archives(verbosity, repository, storage_config, consistency_config, lo
         remote_path_flags = ('--remote-path', remote_path) if remote_path else ()
         lock_wait = storage_config.get('lock_wait', None)
         lock_wait_flags = ('--lock-wait', str(lock_wait)) if lock_wait else ()
-        verbosity_flags = {
+
-            VERBOSITY_SOME: ('--info',),
+        verbosity_flags = ()
-            VERBOSITY_LOTS: ('--debug', '--show-rc'),
+        if logger.isEnabledFor(logging.INFO):
-        }.get(verbosity, ())
+            verbosity_flags = ('--info',)
+        if logger.isEnabledFor(logging.DEBUG):
+            verbosity_flags = ('--debug', '--show-rc')
+
         prefix = consistency_config.get('prefix')
 
         full_command = (
@@ -109,4 +109,4 @@ def check_archives(verbosity, repository, storage_config, consistency_config, lo
         subprocess.check_call(full_command, stdout=stdout, stderr=subprocess.STDOUT)
 
     if 'extract' in checks:
-        extract.extract_last_archive_dry_run(verbosity, repository, lock_wait, local_path, remote_path)
+        extract.extract_last_archive_dry_run(repository, lock_wait, local_path, remote_path)

borgmatic/borg/create.py

@@ -5,8 +5,6 @@ import os
 import subprocess
 import tempfile
 
-from borgmatic.verbosity import VERBOSITY_SOME, VERBOSITY_LOTS
-
 
 logger = logging.getLogger(__name__)
 
@@ -105,7 +103,7 @@ def _make_exclude_flags(location_config, exclude_filename=None):
 
 
 def create_archive(
-    verbosity, dry_run, repository, location_config, storage_config, local_path='borg', remote_path=None,
+    dry_run, repository, location_config, storage_config, local_path='borg', remote_path=None,
 ):
     '''
     Given vebosity/dry-run flags, a local or remote repository path, a location config dict, and a
@@ -150,10 +148,10 @@ def create_archive(
         + (('--remote-path', remote_path) if remote_path else ())
         + (('--umask', str(umask)) if umask else ())
         + (('--lock-wait', str(lock_wait)) if lock_wait else ())
-        + {
+        + (('--list', '--filter', 'AME',) if logger.isEnabledFor(logging.INFO) else ())
-            VERBOSITY_SOME: ('--info',) if dry_run else ('--info', '--stats'),
+        + (( '--info',) if logger.getEffectiveLevel() == logging.INFO else ())
-            VERBOSITY_LOTS: ('--debug', '--list', '--show-rc') if dry_run else ('--debug', '--list', '--show-rc', '--stats'),
+        + (('--stats',) if not dry_run and logger.isEnabledFor(logging.INFO) else ())
-        }.get(verbosity, ())
+        + (('--debug', '--show-rc') if logger.isEnabledFor(logging.DEBUG) else ())
         + (('--dry-run',) if dry_run else ())
     )
 

borgmatic/borg/extract.py

@@ -2,23 +2,23 @@ import logging
 import sys
 import subprocess
 
-from borgmatic.verbosity import VERBOSITY_SOME, VERBOSITY_LOTS
-
 
 logger = logging.getLogger(__name__)
 
 
-def extract_last_archive_dry_run(verbosity, repository, lock_wait=None, local_path='borg', remote_path=None):
+def extract_last_archive_dry_run(repository, lock_wait=None, local_path='borg', remote_path=None):
     '''
     Perform an extraction dry-run of just the most recent archive. If there are no archives, skip
     the dry-run.
     '''
     remote_path_flags = ('--remote-path', remote_path) if remote_path else ()
     lock_wait_flags = ('--lock-wait', str(lock_wait)) if lock_wait else ()
-    verbosity_flags = {
+    verbosity_flags = ()
-        VERBOSITY_SOME: ('--info',),
+    if logger.isEnabledFor(logging.DEBUG):
-        VERBOSITY_LOTS: ('--debug', '--show-rc'),
+        verbosity_flags = ('--debug', '--show-rc')
-    }.get(verbosity, ())
+    elif logger.isEnabledFor(logging.INFO):
+        verbosity_flags = ('--info',)
+    
 
     full_list_command = (
         local_path, 'list',
@@ -32,7 +32,7 @@ def extract_last_archive_dry_run(verbosity, repository, lock_wait=None, local_pa
     if not last_archive_name:
         return
 
-    list_flag = ('--list',) if verbosity == VERBOSITY_LOTS else ()
+    list_flag = ('--list',) if logger.isEnabledFor(logging.DEBUG) else ()
     full_extract_command = (
         local_path, 'extract',
         '--dry-run',

borgmatic/borg/info.py

@@ -1,17 +1,13 @@
 import logging
 import subprocess
 
-from borgmatic.verbosity import VERBOSITY_SOME, VERBOSITY_LOTS
-
 
 logger = logging.getLogger(__name__)
 
 
-def display_archives_info(
+def display_archives_info(repository, storage_config, local_path='borg', remote_path=None, json=False):
-    verbosity, repository, storage_config, local_path='borg', remote_path=None, json=False
-):
     '''
-    Given a verbosity flag, a local or remote repository path, and a storage config dict,
+    Given a local or remote repository path, and a storage config dict,
     display summary information for Borg archives in the repository.
     '''
     lock_wait = storage_config.get('lock_wait', None)
@@ -20,11 +16,9 @@ def display_archives_info(
         (local_path, 'info', repository)
         + (('--remote-path', remote_path) if remote_path else ())
         + (('--lock-wait', str(lock_wait)) if lock_wait else ())
+        + (('--info',)  if logger.getEffectiveLevel() == logging.INFO else ())
+        + (('--debug', '--show-rc') if logger.isEnabledFor(logging.DEBUG) else ())
         + (('--json',) if json else ())
-        + {
-            VERBOSITY_SOME: ('--info',),
-            VERBOSITY_LOTS: ('--debug', '--show-rc'),
-        }.get(verbosity, ())
     )
 
     logger.debug(' '.join(full_command))

borgmatic/borg/list.py

@@ -1,17 +1,13 @@
 import logging
 import subprocess
 
-from borgmatic.verbosity import VERBOSITY_SOME, VERBOSITY_LOTS
-
 
 logger = logging.getLogger(__name__)
 
 
-def list_archives(
+def list_archives(repository, storage_config, local_path='borg', remote_path=None, json=False):
-    verbosity, repository, storage_config, local_path='borg', remote_path=None, json=False
-):
     '''
-    Given a verbosity flag, a local or remote repository path, and a storage config dict,
+    Given a local or remote repository path, and a storage config dict,
     list Borg archives in the repository.
     '''
     lock_wait = storage_config.get('lock_wait', None)
@@ -20,13 +16,10 @@ def list_archives(
         (local_path, 'list', repository)
         + (('--remote-path', remote_path) if remote_path else ())
         + (('--lock-wait', str(lock_wait)) if lock_wait else ())
+        + (('--info',)  if logger.getEffectiveLevel() == logging.INFO  else ())
+        + (('--debug', '--show-rc') if logger.isEnabledFor(logging.DEBUG) else ())
         + (('--json',) if json else ())
-        + {
-            VERBOSITY_SOME: ('--info',),
-            VERBOSITY_LOTS: ('--debug', '--show-rc'),
-        }.get(verbosity, ())
     )
-
     logger.debug(' '.join(full_command))
 
     output = subprocess.check_output(full_command)

borgmatic/borg/prune.py

@@ -1,7 +1,6 @@
 import logging
 import subprocess
 
-from borgmatic.verbosity import VERBOSITY_SOME, VERBOSITY_LOTS
 
 
 logger = logging.getLogger(__name__)
@@ -32,10 +31,9 @@ def _make_prune_flags(retention_config):
     )
 
 
-def prune_archives(verbosity, dry_run, repository, storage_config, retention_config,
+def prune_archives(dry_run, repository, storage_config, retention_config, local_path='borg', remote_path=None):
-                   local_path='borg', remote_path=None):
     '''
-    Given verbosity/dry-run flags, a local or remote repository path, a storage config dict, and a
+    Given dry-run flag, a local or remote repository path, a storage config dict, and a
     retention config dict, prune Borg archives according to the retention policy specified in that
     configuration.
     '''
@@ -54,10 +52,9 @@ def prune_archives(verbosity, dry_run, repository, storage_config, retention_con
         + (('--remote-path', remote_path) if remote_path else ())
         + (('--umask', str(umask)) if umask else ())
         + (('--lock-wait', str(lock_wait)) if lock_wait else ())
-        + {
+        + (('--stats',) if not dry_run and logger.isEnabledFor(logging.INFO) else ())
-            VERBOSITY_SOME: ('--info', '--stats',),
+        + (( '--info',) if logger.getEffectiveLevel() == logging.INFO else ())
-            VERBOSITY_LOTS: ('--debug', '--stats', '--list', '--show-rc'),
+        + (('--debug', '--list', '--show-rc') if logger.isEnabledFor(logging.DEBUG) else ())
-        }.get(verbosity, ())
         + (('--dry-run',) if dry_run else ())
     )
 

borgmatic/commands/borgmatic.py

@@ -10,7 +10,7 @@ from borgmatic.borg import check as borg_check, create as borg_create, prune as
 from borgmatic.commands import hook
 from borgmatic.config import collect, convert, validate
 from borgmatic.signals import configure_signals
-from borgmatic.verbosity import VERBOSITY_SOME, VERBOSITY_LOTS, verbosity_to_log_level
+from borgmatic.verbosity import verbosity_to_log_level
 
 
 logger = logging.getLogger(__name__)
@@ -165,7 +165,6 @@ def _run_commands_on_repository(
     if args.prune:
         logger.info('{}: Pruning archives{}'.format(repository, dry_run_label))
         borg_prune.prune_archives(
-            args.verbosity,
             args.dry_run,
             repository,
             storage,
@@ -176,7 +175,6 @@ def _run_commands_on_repository(
     if args.create:
         logger.info('{}: Creating archive{}'.format(repository, dry_run_label))
         borg_create.create_archive(
-            args.verbosity,
             args.dry_run,
             repository,
             location,
@@ -187,7 +185,6 @@ def _run_commands_on_repository(
     if args.check:
         logger.info('{}: Running consistency checks'.format(repository))
         borg_check.check_archives(
-            args.verbosity,
             repository,
             storage,
             consistency,
@@ -197,7 +194,6 @@ def _run_commands_on_repository(
     if args.list:
         logger.info('{}: Listing archives'.format(repository))
         output = borg_list.list_archives(
-            args.verbosity,
             repository,
             storage,
             local_path=local_path,
@@ -211,7 +207,6 @@ def _run_commands_on_repository(
     if args.info:
         logger.info('{}: Displaying summary info for archives'.format(repository))
         output = borg_info.display_archives_info(
-            args.verbosity,
             repository,
             storage,
             local_path=local_path,

borgmatic/tests/unit/borg/test_check.py

@@ -1,12 +1,11 @@
 from subprocess import STDOUT
-import sys
+import logging, sys
 
 from flexmock import flexmock
 import pytest
 
 from borgmatic.borg import check as module
-from borgmatic.verbosity import VERBOSITY_SOME, VERBOSITY_LOTS
+from borgmatic.tests.unit.test_verbosity import insert_logging_mock
-
 
 def insert_subprocess_mock(check_call_command, **kwargs):
     subprocess = flexmock(module.subprocess)
@@ -125,7 +124,6 @@ def test_check_archives_calls_borg_with_parameters(checks):
     flexmock(module.os).should_receive('devnull')
 
     module.check_archives(
-        verbosity=None,
         repository='repo',
         storage_config={},
         consistency_config=consistency_config,
@@ -142,43 +140,42 @@ def test_check_archives_with_extract_check_calls_extract_only():
     insert_subprocess_never()
 
     module.check_archives(
-        verbosity=None,
         repository='repo',
         storage_config={},
         consistency_config=consistency_config,
     )
 
 
-def test_check_archives_with_verbosity_some_calls_borg_with_info_parameter():
+def test_check_archives_with_log_info_calls_borg_with_info_parameter():
     checks = ('repository',)
     consistency_config = {'check_last': None}
     flexmock(module).should_receive('_parse_checks').and_return(checks)
     flexmock(module).should_receive('_make_check_flags').and_return(())
+    insert_logging_mock(logging.INFO)
     insert_subprocess_mock(
         ('borg', 'check', 'repo', '--info'),
         stdout=None, stderr=STDOUT,
     )
 
     module.check_archives(
-        verbosity=VERBOSITY_SOME,
         repository='repo',
         storage_config={},
         consistency_config=consistency_config,
     )
 
 
-def test_check_archives_with_verbosity_lots_calls_borg_with_debug_parameter():
+def test_check_archives_with_log_debug_calls_borg_with_debug_parameter():
     checks = ('repository',)
     consistency_config = {'check_last': None}
     flexmock(module).should_receive('_parse_checks').and_return(checks)
     flexmock(module).should_receive('_make_check_flags').and_return(())
+    insert_logging_mock(logging.DEBUG)
     insert_subprocess_mock(
         ('borg', 'check', 'repo', '--debug', '--show-rc'),
         stdout=None, stderr=STDOUT,
     )
 
     module.check_archives(
-        verbosity=VERBOSITY_LOTS,
         repository='repo',
         storage_config={},
         consistency_config=consistency_config,
@@ -191,7 +188,6 @@ def test_check_archives_without_any_checks_bails():
     insert_subprocess_never()
 
     module.check_archives(
-        verbosity=None,
         repository='repo',
         storage_config={},
         consistency_config=consistency_config,
@@ -213,7 +209,6 @@ def test_check_archives_with_local_path_calls_borg_via_local_path():
     flexmock(module.os).should_receive('devnull')
 
     module.check_archives(
-        verbosity=None,
         repository='repo',
         storage_config={},
         consistency_config=consistency_config,
@@ -236,7 +231,6 @@ def test_check_archives_with_remote_path_calls_borg_with_remote_path_parameters(
     flexmock(module.os).should_receive('devnull')
 
     module.check_archives(
-        verbosity=None,
         repository='repo',
         storage_config={},
         consistency_config=consistency_config,
@@ -259,7 +253,6 @@ def test_check_archives_with_lock_wait_calls_borg_with_lock_wait_parameters():
     flexmock(module.os).should_receive('devnull')
 
     module.check_archives(
-        verbosity=None,
         repository='repo',
         storage_config={'lock_wait': 5},
         consistency_config=consistency_config,
@@ -283,7 +276,6 @@ def test_check_archives_with_retention_prefix():
     flexmock(module.os).should_receive('devnull')
 
     module.check_archives(
-        verbosity=None,
         repository='repo',
         storage_config={},
         consistency_config=consistency_config,

borgmatic/tests/unit/borg/test_create.py

@@ -1,9 +1,9 @@
-import os
+import logging, os
 
 from flexmock import flexmock
 
 from borgmatic.borg import create as module
-from borgmatic.verbosity import VERBOSITY_SOME, VERBOSITY_LOTS
+from borgmatic.tests.unit.test_verbosity import insert_logging_mock
 
 
 def test_initialize_environment_with_passcommand_should_set_environment():
@@ -216,7 +216,6 @@ def test_create_archive_calls_borg_with_parameters():
     insert_subprocess_mock(CREATE_COMMAND)
 
     module.create_archive(
-        verbosity=None,
         dry_run=False,
         repository='repo',
         location_config={
@@ -237,7 +236,6 @@ def test_create_archive_with_patterns_calls_borg_with_patterns():
     insert_subprocess_mock(CREATE_COMMAND + pattern_flags)
 
     module.create_archive(
-        verbosity=None,
         dry_run=False,
         repository='repo',
         location_config={
@@ -258,7 +256,6 @@ def test_create_archive_with_exclude_patterns_calls_borg_with_excludes():
     insert_subprocess_mock(CREATE_COMMAND + exclude_flags)
 
     module.create_archive(
-        verbosity=None,
         dry_run=False,
         repository='repo',
         location_config={
@@ -270,16 +267,16 @@ def test_create_archive_with_exclude_patterns_calls_borg_with_excludes():
     )
 
 
-def test_create_archive_with_verbosity_some_calls_borg_with_info_parameter():
+def test_create_archive_with_log_info_calls_borg_with_info_parameter():
     flexmock(module).should_receive('_expand_directories').and_return(('foo', 'bar')).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_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
-    insert_subprocess_mock(CREATE_COMMAND + ('--info', '--stats',))
+    insert_subprocess_mock(CREATE_COMMAND + ('--list', '--filter', 'AME', '--info', '--stats',))
+    insert_logging_mock(logging.INFO)
     
     module.create_archive(
-        verbosity=VERBOSITY_SOME,
         dry_run=False,
         repository='repo',
         location_config={
@@ -291,15 +288,15 @@ def test_create_archive_with_verbosity_some_calls_borg_with_info_parameter():
     )
 
 
-def test_create_archive_with_verbosity_lots_calls_borg_with_debug_parameter():
+def test_create_archive_with_log_debug_calls_borg_with_debug_parameter():
     flexmock(module).should_receive('_expand_directories').and_return(('foo', 'bar')).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(())
-    insert_subprocess_mock(CREATE_COMMAND + ('--debug', '--list', '--show-rc', '--stats'))
+    insert_subprocess_mock(CREATE_COMMAND + ('--list', '--filter', 'AME','--stats', '--debug', '--show-rc'))
+    insert_logging_mock(logging.DEBUG)
 
     module.create_archive(
-        verbosity=VERBOSITY_LOTS,
         dry_run=False,
         repository='repo',
         location_config={
@@ -320,7 +317,6 @@ def test_create_archive_with_dry_run_calls_borg_with_dry_run_parameter():
     insert_subprocess_mock(CREATE_COMMAND + ('--dry-run',))
 
     module.create_archive(
-        verbosity=None,
         dry_run=True,
         repository='repo',
         location_config={
@@ -332,16 +328,18 @@ def test_create_archive_with_dry_run_calls_borg_with_dry_run_parameter():
     )
 
 
-def test_create_archive_with_dry_run_and_verbosity_some_calls_borg_without_stats_parameter():
+def test_create_archive_with_dry_run_and_log_info_calls_borg_without_stats_parameter():
+    """ --dry-run and --stats are mutually exclusive, see:
+    https://borgbackup.readthedocs.io/en/stable/usage/create.html#description """
     flexmock(module).should_receive('_expand_directories').and_return(('foo', 'bar')).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_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
-    insert_subprocess_mock(CREATE_COMMAND + ('--info', '--dry-run'))
+    insert_subprocess_mock(CREATE_COMMAND + ('--list', '--filter', 'AME', '--info', '--dry-run'))
+    insert_logging_mock(logging.INFO)
 
     module.create_archive(
-        verbosity=VERBOSITY_SOME,
         dry_run=True,
         repository='repo',
         location_config={
@@ -353,16 +351,18 @@ def test_create_archive_with_dry_run_and_verbosity_some_calls_borg_without_stats
     )
 
 
-def test_create_archive_with_dry_run_and_verbosity_lots_calls_borg_without_stats_parameter():
+def test_create_archive_with_dry_run_and_log_debug_calls_borg_without_stats_parameter():
+    """ --dry-run and --stats are mutually exclusive, see:
+    https://borgbackup.readthedocs.io/en/stable/usage/create.html#description """
     flexmock(module).should_receive('_expand_directories').and_return(('foo', 'bar')).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_pattern_flags').and_return(())
     flexmock(module).should_receive('_make_exclude_flags').and_return(())
-    insert_subprocess_mock(CREATE_COMMAND + ('--debug', '--list', '--show-rc', '--dry-run'))
+    insert_subprocess_mock(CREATE_COMMAND + ('--list', '--filter', 'AME', '--debug', '--show-rc', '--dry-run'))
+    insert_logging_mock(logging.DEBUG)
 
     module.create_archive(
-        verbosity=VERBOSITY_LOTS,
         dry_run=True,
         repository='repo',
         location_config={
@@ -382,7 +382,6 @@ def test_create_archive_with_checkpoint_interval_calls_borg_with_checkpoint_inte
     insert_subprocess_mock(CREATE_COMMAND + ('--checkpoint-interval', '600'))
 
     module.create_archive(
-        verbosity=None,
         dry_run=False,
         repository='repo',
         location_config={
@@ -402,7 +401,6 @@ def test_create_archive_with_compression_calls_borg_with_compression_parameters(
     insert_subprocess_mock(CREATE_COMMAND + ('--compression', 'rle'))
 
     module.create_archive(
-        verbosity=None,
         dry_run=False,
         repository='repo',
         location_config={
@@ -422,7 +420,6 @@ def test_create_archive_with_remote_rate_limit_calls_borg_with_remote_ratelimit_
     insert_subprocess_mock(CREATE_COMMAND + ('--remote-ratelimit', '100'))
 
     module.create_archive(
-        verbosity=None,
         dry_run=False,
         repository='repo',
         location_config={
@@ -442,7 +439,6 @@ def test_create_archive_with_one_file_system_calls_borg_with_one_file_system_par
     insert_subprocess_mock(CREATE_COMMAND + ('--one-file-system',))
 
     module.create_archive(
-        verbosity=None,
         dry_run=False,
         repository='repo',
         location_config={
@@ -463,7 +459,6 @@ def test_create_archive_with_bsd_flags_true_calls_borg_without_nobsdflags_parame
     insert_subprocess_mock(CREATE_COMMAND)
 
     module.create_archive(
-        verbosity=None,
         dry_run=False,
         repository='repo',
         location_config={
@@ -484,7 +479,6 @@ def test_create_archive_with_bsd_flags_false_calls_borg_with_nobsdflags_paramete
     insert_subprocess_mock(CREATE_COMMAND + ('--nobsdflags',))
 
     module.create_archive(
-        verbosity=None,
         dry_run=False,
         repository='repo',
         location_config={
@@ -505,7 +499,6 @@ def test_create_archive_with_files_cache_calls_borg_with_files_cache_parameters(
     insert_subprocess_mock(CREATE_COMMAND + ('--files-cache', 'ctime,size'))
 
     module.create_archive(
-        verbosity=None,
         dry_run=False,
         repository='repo',
         location_config={
@@ -526,7 +519,6 @@ def test_create_archive_with_local_path_calls_borg_via_local_path():
     insert_subprocess_mock(('borg1',) + CREATE_COMMAND[1:])
 
     module.create_archive(
-        verbosity=None,
         dry_run=False,
         repository='repo',
         location_config={
@@ -547,7 +539,6 @@ def test_create_archive_with_remote_path_calls_borg_with_remote_path_parameters(
     insert_subprocess_mock(CREATE_COMMAND + ('--remote-path', 'borg1'))
 
     module.create_archive(
-        verbosity=None,
         dry_run=False,
         repository='repo',
         location_config={
@@ -568,7 +559,6 @@ def test_create_archive_with_umask_calls_borg_with_umask_parameters():
     insert_subprocess_mock(CREATE_COMMAND + ('--umask', '740'))
 
     module.create_archive(
-        verbosity=None,
         dry_run=False,
         repository='repo',
         location_config={
@@ -588,7 +578,6 @@ def test_create_archive_with_lock_wait_calls_borg_with_lock_wait_parameters():
     insert_subprocess_mock(CREATE_COMMAND + ('--lock-wait', '5'))
 
     module.create_archive(
-        verbosity=None,
         dry_run=False,
         repository='repo',
         location_config={
@@ -609,7 +598,6 @@ def test_create_archive_with_source_directories_glob_expands():
     flexmock(module.glob).should_receive('glob').with_args('foo*').and_return(['foo', 'food'])
 
     module.create_archive(
-        verbosity=None,
         dry_run=False,
         repository='repo',
         location_config={
@@ -630,7 +618,6 @@ def test_create_archive_with_non_matching_source_directories_glob_passes_through
     flexmock(module.glob).should_receive('glob').with_args('foo*').and_return([])
 
     module.create_archive(
-        verbosity=None,
         dry_run=False,
         repository='repo',
         location_config={
@@ -650,7 +637,6 @@ def test_create_archive_with_glob_calls_borg_with_expanded_directories():
     insert_subprocess_mock(('borg', 'create', 'repo::{}'.format(DEFAULT_ARCHIVE_NAME), 'foo', 'food'))
 
     module.create_archive(
-        verbosity=None,
         dry_run=False,
         repository='repo',
         location_config={
@@ -670,7 +656,6 @@ def test_create_archive_with_archive_name_format_calls_borg_with_archive_name():
     insert_subprocess_mock(('borg', 'create', 'repo::ARCHIVE_NAME', 'foo', 'bar'))
 
     module.create_archive(
-        verbosity=None,
         dry_run=False,
         repository='repo',
         location_config={
@@ -692,7 +677,6 @@ def test_create_archive_with_archive_name_format_accepts_borg_placeholders():
     insert_subprocess_mock(('borg', 'create', 'repo::Documents_{hostname}-{now}', 'foo', 'bar'))
 
     module.create_archive(
-        verbosity=None,
         dry_run=False,
         repository='repo',
         location_config={

borgmatic/tests/unit/borg/test_extract.py

@@ -1,9 +1,10 @@
-import sys
+import logging, sys
 
 from flexmock import flexmock
 
 from borgmatic.borg import extract as module
 from borgmatic.verbosity import VERBOSITY_SOME, VERBOSITY_LOTS
+from borgmatic.tests.unit.test_verbosity import insert_logging_mock
 
 
 def insert_subprocess_mock(check_call_command, **kwargs):
@@ -32,7 +33,6 @@ def test_extract_last_archive_dry_run_should_call_borg_with_last_archive():
     )
 
     module.extract_last_archive_dry_run(
-        verbosity=None,
         repository='repo',
         lock_wait=None,
     )
@@ -47,13 +47,12 @@ def test_extract_last_archive_dry_run_without_any_archives_should_bail():
     insert_subprocess_never()
 
     module.extract_last_archive_dry_run(
-        verbosity=None,
         repository='repo',
         lock_wait=None,
     )
 
 
-def test_extract_last_archive_dry_run_with_verbosity_some_should_call_borg_with_info_parameter():
+def test_extract_last_archive_dry_run_with_log_info_should_call_borg_with_info_parameter():
     flexmock(sys.stdout).encoding = 'utf-8'
     insert_subprocess_check_output_mock(
         ('borg', 'list', '--short', 'repo', '--info'),
@@ -62,15 +61,15 @@ def test_extract_last_archive_dry_run_with_verbosity_some_should_call_borg_with_
     insert_subprocess_mock(
         ('borg', 'extract', '--dry-run', 'repo::archive2', '--info'),
     )
+    insert_logging_mock(logging.INFO)
 
     module.extract_last_archive_dry_run(
-        verbosity=VERBOSITY_SOME,
         repository='repo',
         lock_wait=None,
     )
 
 
-def test_extract_last_archive_dry_run_with_verbosity_lots_should_call_borg_with_debug_parameter():
+def test_extract_last_archive_dry_run_with_log_debug_should_call_borg_with_debug_parameter():
     flexmock(sys.stdout).encoding = 'utf-8'
     insert_subprocess_check_output_mock(
         ('borg', 'list', '--short', 'repo', '--debug', '--show-rc'),
@@ -79,9 +78,9 @@ def test_extract_last_archive_dry_run_with_verbosity_lots_should_call_borg_with_
     insert_subprocess_mock(
         ('borg', 'extract', '--dry-run', 'repo::archive2', '--debug', '--show-rc', '--list'),
     )
+    insert_logging_mock(logging.DEBUG)
 
     module.extract_last_archive_dry_run(
-        verbosity=VERBOSITY_LOTS,
         repository='repo',
         lock_wait=None,
     )
@@ -98,7 +97,6 @@ def test_extract_last_archive_dry_run_should_call_borg_via_local_path():
     )
 
     module.extract_last_archive_dry_run(
-        verbosity=None,
         repository='repo',
         lock_wait=None,
         local_path='borg1',
@@ -116,7 +114,6 @@ def test_extract_last_archive_dry_run_should_call_borg_with_remote_path_paramete
     )
 
     module.extract_last_archive_dry_run(
-        verbosity=None,
         repository='repo',
         lock_wait=None,
         remote_path='borg1',
@@ -134,7 +131,6 @@ def test_extract_last_archive_dry_run_should_call_borg_with_lock_wait_parameters
     )
 
     module.extract_last_archive_dry_run(
-        verbosity=None,
         repository='repo',
         lock_wait=5,
     )

borgmatic/tests/unit/borg/test_info.py

@@ -1,9 +1,10 @@
+import logging
 from collections import OrderedDict
 
 from flexmock import flexmock
 
 from borgmatic.borg import info as module
-from borgmatic.verbosity import VERBOSITY_SOME, VERBOSITY_LOTS
+from borgmatic.tests.unit.test_verbosity import insert_logging_mock
 
 
 def insert_subprocess_mock(check_call_command, **kwargs):
@@ -18,29 +19,27 @@ def test_display_archives_info_calls_borg_with_parameters():
     insert_subprocess_mock(INFO_COMMAND)
 
     module.display_archives_info(
-        verbosity=None,
         repository='repo',
         storage_config={},
     )
 
 
-def test_display_archives_info_with_verbosity_some_calls_borg_with_info_parameter():
+def test_display_archives_info_with_log_info_calls_borg_with_info_parameter():
     insert_subprocess_mock(INFO_COMMAND + ('--info',))
-
+    insert_logging_mock(logging.INFO)
     module.display_archives_info(
         repository='repo',
         storage_config={},
-        verbosity=VERBOSITY_SOME,
     )
 
 
-def test_display_archives_info_with_verbosity_lots_calls_borg_with_debug_parameter():
+def test_display_archives_info_with_log_debug_calls_borg_with_debug_parameter():
     insert_subprocess_mock(INFO_COMMAND + ('--debug', '--show-rc'))
+    insert_logging_mock(logging.DEBUG)
 
     module.display_archives_info(
         repository='repo',
         storage_config={},
-        verbosity=VERBOSITY_LOTS,
     )
 
 
@@ -48,7 +47,6 @@ def test_display_archives_info_with_json_calls_borg_with_json_parameter():
     insert_subprocess_mock(INFO_COMMAND + ('--json',))
 
     module.display_archives_info(
-        verbosity=None,
         repository='repo',
         storage_config={},
         json=True,
@@ -59,7 +57,6 @@ def test_display_archives_info_with_local_path_calls_borg_via_local_path():
     insert_subprocess_mock(('borg1',) + INFO_COMMAND[1:])
 
     module.display_archives_info(
-        verbosity=None,
         repository='repo',
         storage_config={},
         local_path='borg1',
@@ -70,7 +67,6 @@ def test_display_archives_info_with_remote_path_calls_borg_with_remote_path_para
     insert_subprocess_mock(INFO_COMMAND + ('--remote-path', 'borg1'))
 
     module.display_archives_info(
-        verbosity=None,
         repository='repo',
         storage_config={},
         remote_path='borg1',
@@ -82,7 +78,6 @@ def test_display_archives_info_with_lock_wait_calls_borg_with_lock_wait_paramete
     insert_subprocess_mock(INFO_COMMAND + ('--lock-wait', '5'))
 
     module.display_archives_info(
-        verbosity=None,
         repository='repo',
         storage_config=storage_config,
     )

borgmatic/tests/unit/borg/test_list.py

@@ -1,9 +1,10 @@
+import logging
 from collections import OrderedDict
 
 from flexmock import flexmock
 
 from borgmatic.borg import list as module
-from borgmatic.verbosity import VERBOSITY_SOME, VERBOSITY_LOTS
+from borgmatic.tests.unit.test_verbosity import insert_logging_mock
 
 
 def insert_subprocess_mock(check_call_command, **kwargs):
@@ -18,29 +19,28 @@ def test_list_archives_calls_borg_with_parameters():
     insert_subprocess_mock(LIST_COMMAND)
 
     module.list_archives(
-        verbosity=None,
         repository='repo',
         storage_config={},
     )
 
 
-def test_list_archives_with_verbosity_some_calls_borg_with_info_parameter():
+def test_list_archives_with_log_info_calls_borg_with_info_parameter():
     insert_subprocess_mock(LIST_COMMAND + ('--info',))
+    insert_logging_mock(logging.INFO)
 
     module.list_archives(
         repository='repo',
         storage_config={},
-        verbosity=VERBOSITY_SOME,
     )
 
 
-def test_list_archives_with_verbosity_lots_calls_borg_with_debug_parameter():
+def test_list_archives_with_log_debug_calls_borg_with_debug_parameter():
     insert_subprocess_mock(LIST_COMMAND + ('--debug', '--show-rc'))
+    insert_logging_mock(logging.DEBUG)
 
     module.list_archives(
         repository='repo',
         storage_config={},
-        verbosity=VERBOSITY_LOTS,
     )
 
 
@@ -48,7 +48,6 @@ def test_list_archives_with_json_calls_borg_with_json_parameter():
     insert_subprocess_mock(LIST_COMMAND + ('--json',))
 
     module.list_archives(
-        verbosity=None,
         repository='repo',
         storage_config={},
         json=True,
@@ -59,7 +58,6 @@ def test_list_archives_with_local_path_calls_borg_via_local_path():
     insert_subprocess_mock(('borg1',) + LIST_COMMAND[1:])
 
     module.list_archives(
-        verbosity=None,
         repository='repo',
         storage_config={},
         local_path='borg1',
@@ -70,7 +68,6 @@ def test_list_archives_with_remote_path_calls_borg_with_remote_path_parameters()
     insert_subprocess_mock(LIST_COMMAND + ('--remote-path', 'borg1'))
 
     module.list_archives(
-        verbosity=None,
         repository='repo',
         storage_config={},
         remote_path='borg1',
@@ -82,7 +79,6 @@ def test_list_archives_with_lock_wait_calls_borg_with_lock_wait_parameters():
     insert_subprocess_mock(LIST_COMMAND + ('--lock-wait', '5'))
 
     module.list_archives(
-        verbosity=None,
         repository='repo',
         storage_config=storage_config,
     )

borgmatic/tests/unit/borg/test_prune.py

@@ -1,9 +1,10 @@
+import logging
 from collections import OrderedDict
 
 from flexmock import flexmock
 
 from borgmatic.borg import prune as module
-from borgmatic.verbosity import VERBOSITY_SOME, VERBOSITY_LOTS
+from borgmatic.tests.unit.test_verbosity import insert_logging_mock
 
 
 def insert_subprocess_mock(check_call_command, **kwargs):
@@ -11,6 +12,7 @@ def insert_subprocess_mock(check_call_command, **kwargs):
     subprocess.should_receive('check_call').with_args(check_call_command, **kwargs).once()
 
 
+
 BASE_PRUNE_FLAGS = (
     ('--keep-daily', '1'),
     ('--keep-weekly', '2'),
@@ -63,7 +65,6 @@ def test_prune_archives_calls_borg_with_parameters():
     insert_subprocess_mock(PRUNE_COMMAND)
 
     module.prune_archives(
-        verbosity=None,
         dry_run=False,
         repository='repo',
         storage_config={},
@@ -71,33 +72,33 @@ def test_prune_archives_calls_borg_with_parameters():
     )
 
 
-def test_prune_archives_with_verbosity_some_calls_borg_with_info_parameter():
+def test_prune_archives_with_log_info_calls_borg_with_info_parameter():
     retention_config = flexmock()
     flexmock(module).should_receive('_make_prune_flags').with_args(retention_config).and_return(
         BASE_PRUNE_FLAGS,
     )
-    insert_subprocess_mock(PRUNE_COMMAND + ('--info', '--stats',))
+    insert_subprocess_mock(PRUNE_COMMAND + ('--stats', '--info',))
+    insert_logging_mock(logging.INFO)
 
     module.prune_archives(
         repository='repo',
         storage_config={},
-        verbosity=VERBOSITY_SOME,
         dry_run=False,
         retention_config=retention_config,
     )
 
 
-def test_prune_archives_with_verbosity_lots_calls_borg_with_debug_parameter():
+def test_prune_archives_with_log_debug_calls_borg_with_debug_parameter():
     retention_config = flexmock()
     flexmock(module).should_receive('_make_prune_flags').with_args(retention_config).and_return(
         BASE_PRUNE_FLAGS,
     )
-    insert_subprocess_mock(PRUNE_COMMAND + ('--debug', '--stats', '--list', '--show-rc'))
+    insert_subprocess_mock(PRUNE_COMMAND + ('--stats', '--debug', '--list', '--show-rc'))
+    insert_logging_mock(logging.DEBUG)
 
     module.prune_archives(
         repository='repo',
         storage_config={},
-        verbosity=VERBOSITY_LOTS,
         dry_run=False,
         retention_config=retention_config,
     )
@@ -113,7 +114,6 @@ def test_prune_archives_with_dry_run_calls_borg_with_dry_run_parameter():
     module.prune_archives(
         repository='repo',
         storage_config={},
-        verbosity=None,
         dry_run=True,
         retention_config=retention_config,
     )
@@ -127,7 +127,6 @@ def test_prune_archives_with_local_path_calls_borg_via_local_path():
     insert_subprocess_mock(('borg1',) + PRUNE_COMMAND[1:])
 
     module.prune_archives(
-        verbosity=None,
         dry_run=False,
         repository='repo',
         storage_config={},
@@ -144,7 +143,6 @@ def test_prune_archives_with_remote_path_calls_borg_with_remote_path_parameters(
     insert_subprocess_mock(PRUNE_COMMAND + ('--remote-path', 'borg1'))
 
     module.prune_archives(
-        verbosity=None,
         dry_run=False,
         repository='repo',
         storage_config={},
@@ -162,7 +160,6 @@ def test_prune_archives_with_umask_calls_borg_with_umask_parameters():
     insert_subprocess_mock(PRUNE_COMMAND + ('--umask', '077'))
 
     module.prune_archives(
-        verbosity=None,
         dry_run=False,
         repository='repo',
         storage_config=storage_config,
@@ -179,7 +176,6 @@ def test_prune_archives_with_lock_wait_calls_borg_with_lock_wait_parameters():
     insert_subprocess_mock(PRUNE_COMMAND + ('--lock-wait', '5'))
 
     module.prune_archives(
-        verbosity=None,
         dry_run=False,
         repository='repo',
         storage_config=storage_config,

borgmatic/tests/unit/test_verbosity.py

@@ -1,10 +1,19 @@
 import logging
 
+from flexmock import flexmock
+
 from borgmatic import verbosity as module
 
+def insert_logging_mock(log_level):
+    """ Mocks the isEnabledFor from python logging. """
+    logging = flexmock(module.logging.Logger)
+    logging.should_receive('isEnabledFor').replace_with(lambda lvl : lvl >= log_level)
+    logging.should_receive('getEffectiveLevel').replace_with(lambda: log_level)
+
 
 def test_verbosity_to_log_level_maps_known_verbosity_to_log_level():
     assert module.verbosity_to_log_level(module.VERBOSITY_SOME) == logging.INFO
+    assert module.verbosity_to_log_level(module.VERBOSITY_LOTS) == logging.DEBUG
 
 
 def test_verbosity_to_log_level_maps_unknown_verbosity_to_warning_level():