Rework logging/verbosity system #90

Merged
witten merged 12 commits from :master into master 2018-09-08 20:53:38 +00:00
18 changed files with 81 additions and 34 deletions
Showing only changes of commit 9628e385a6 - Show all commits

13
NEWS
View File

@ -1,4 +1,15 @@
1.2.1.dev0
1.2.3.dev0
* #87: Support for Borg create --checkpoint-interval via "checkpoint_interval" option in
borgmatic's storage configuration.
* #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.
1.2.2
* #85: Fix compatibility issue between pykwalify and ruamel.yaml 0.15.52, which manifested in
borgmatic as a pykwalify RuleError.
1.2.1
* Skip before/after backup hooks when only doing --prune, --check, --list, and/or --info.
* #71: Support for XDG_CONFIG_HOME environment variable for specifying alternate user ~/.config/
path.

View File

@ -89,12 +89,13 @@ def check_archives(repository, storage_config, consistency_config, local_path='b
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 = ()
if logger.isEnabledFor(logging.INFO):
verbosity_flags = ('--info',)
if logger.isEnabledFor(logging.DEBUG):
verbosity_flags = ('--debug',)
verbosity_flags = ('--debug', '--show-rc')
prefix = consistency_config.get('prefix')
full_command = (

View File

@ -113,6 +113,7 @@ def create_archive(
pattern_file = _write_pattern_file(location_config.get('patterns'))
exclude_file = _write_pattern_file(_expand_directories(location_config.get('exclude_patterns')))
checkpoint_interval = storage_config.get('checkpoint_interval', None)
compression = storage_config.get('compression', None)
remote_rate_limit = storage_config.get('remote_rate_limit', None)
umask = storage_config.get('umask', None)
@ -138,6 +139,7 @@ def create_archive(
location_config,
exclude_file.name if exclude_file else None,
)
+ (('--checkpoint-interval', str(checkpoint_interval)) if checkpoint_interval else ())
+ (('--compression', compression) if compression else ())
+ (('--remote-ratelimit', str(remote_rate_limit)) if remote_rate_limit else ())
+ (('--one-file-system',) if location_config.get('one_file_system') else ())
@ -147,7 +149,7 @@ def create_archive(
+ (('--umask', str(umask)) if umask else ())
+ (('--lock-wait', str(lock_wait)) if lock_wait else ())
+ (('--list', '--filter', 'AME', '--info', '--stats') if logger.isEnabledFor(logging.INFO) else ())

You'll need to retain the logic that omits --stats during a dry run, because --stats and --dry-run can't be specified together. More info here: https://borgbackup.readthedocs.io/en/stable/usage/create.html#description

You'll need to retain the logic that omits `--stats` during a dry run, because `--stats` and `--dry-run` can't be specified together. More info here: https://borgbackup.readthedocs.io/en/stable/usage/create.html#description
Outdated
Review

Oh, wasn't aware of that, done.

Oh, wasn't aware of that, done.
+ (('--debug', ) if logger.isEnabledFor(logging.DEBUG) else ())
+ (('--debug', '--show-rc') if logger.isEnabledFor(logging.DEBUG) else ())

For options which are mutually exclusive for DEBUG and INFO, like --debug --info, I let the latter option overwrite the first.

Does that mean Borg just ignores the --info and respects only the --debug flag?

> For options which are mutually exclusive for DEBUG and INFO, like --debug --info, I let the latter option overwrite the first. Does that mean Borg just ignores the `--info` and respects only the `--debug` flag?
Outdated
Review

Exactly. Unfortunately I am not sure if this is documented behavior of borg or python argparse. I think best will be to ask borg's mailing list. Even cooler would be to not call the borg executable, but use a python API. But that leads us too far... ;-)

Exactly. Unfortunately I am not sure if this is documented behavior of borg or python argparse. I think best will be to ask borg's mailing list. Even cooler would be to not call the borg executable, but use a python API. But that leads us too far... ;-)

If you wanted to avoid relying on the undocumented behavior (--debug overriding --info), one idea is that you could break out the construction of flags to a separate if/elif similar to the code elsewhere. For instance, something like:

 verbosity_flags = ()

 if logger.isEnabledFor(logging.DEBUG):
     verbosity_flags = ('--list', '--filter', 'AME', '--debug', '--show-rc')
 elif logger.isEnabledFor(logging.INFO):
     verbosity_flags = ('--list', '--filter', 'AME', '--info')

Another option would be to use getEffectiveLevel() instead of isEnabledFor() to sidestep falling through the hierarchy from DEBUG to INFO. That also has the side benefit of letting you keep things inline and non-imperative:

+ (('--list', '--filter', 'AME') if logger.isEnabledFor(logging.INFO) else ())
+ (('--info',) if logger.getEffectiveLevel() == logging.INFO else ())
+ (('--debug', '--show-rc') if logger.getEffectiveLevel() == logging.DEBUG else ())
If you wanted to avoid relying on the undocumented behavior (`--debug` overriding `--info`), one idea is that you could break out the construction of flags to a separate `if`/`elif` similar to the code elsewhere. For instance, something like: ```python verbosity_flags = () if logger.isEnabledFor(logging.DEBUG): verbosity_flags = ('--list', '--filter', 'AME', '--debug', '--show-rc') elif logger.isEnabledFor(logging.INFO): verbosity_flags = ('--list', '--filter', 'AME', '--info') ``` Another option would be to use `getEffectiveLevel()` instead of `isEnabledFor()` to sidestep falling through the hierarchy from `DEBUG` to `INFO`. That also has the side benefit of letting you keep things inline and non-imperative: ```python + (('--list', '--filter', 'AME') if logger.isEnabledFor(logging.INFO) else ()) + (('--info',) if logger.getEffectiveLevel() == logging.INFO else ()) + (('--debug', '--show-rc') if logger.getEffectiveLevel() == logging.DEBUG else ()) ```
Outdated
Review

I already thought about using getEffectiveLevel. I would use it only for --info. More generally: only for parameters that should not be enabled at a higher log level. --debug should also be enabled if the log level is even higher than debug (not used, but it should be possible).

I have addressed this in the recent commit.

I already thought about using `getEffectiveLevel`. I would use it *only* for `--info`. More generally: only for parameters that should not be enabled at a higher log level. `--debug` should also be enabled if the log level is even higher than debug (not used, but it should be possible). I have addressed this in the recent commit.

Looks great, thanks!

Looks great, thanks!
+ (('--dry-run',) if dry_run else ())
)

View File

@ -14,7 +14,7 @@ def extract_last_archive_dry_run(repository, lock_wait=None, local_path='borg',
remote_path_flags = ('--remote-path', remote_path) if remote_path else ()
lock_wait_flags = ('--lock-wait', str(lock_wait)) if lock_wait else ()
if logger.isEnabledFor(logging.DEBUG):
verbosity_flags = ('--debug',)
verbosity_flags = ('--debug', '--show-rc')
elif logger.isEnabledFor(logging.INFO):
verbosity_flags = ('--info',)
else:

View File

@ -7,7 +7,7 @@ logger = logging.getLogger(__name__)
def display_archives_info(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)
@ -17,7 +17,7 @@ def display_archives_info(repository, storage_config, local_path='borg', remote_
+ (('--remote-path', remote_path) if remote_path else ())
+ (('--lock-wait', str(lock_wait)) if lock_wait else ())
+ (('--info',) if logger.isEnabledFor(logging.INFO) else ())
+ (('--debug',) if logger.isEnabledFor(logging.DEBUG) else ())
+ (('--debug', '--show-rc') if logger.isEnabledFor(logging.DEBUG) else ())
+ (('--json',) if json else ())
)

View File

@ -17,7 +17,7 @@ def list_archives(repository, storage_config, local_path='borg', remote_path=Non
+ (('--remote-path', remote_path) if remote_path else ())
+ (('--lock-wait', str(lock_wait)) if lock_wait else ())
+ (('--info',) if logger.isEnabledFor(logging.INFO) else ())
+ (('--debug',) if logger.isEnabledFor(logging.DEBUG) else ())
+ (('--debug', '--show-rc') if logger.isEnabledFor(logging.DEBUG) else ())
+ (('--json',) if json else ())
)
logger.debug(' '.join(full_command))

View File

@ -54,7 +54,7 @@ def prune_archives(dry_run, repository, storage_config, retention_config, local_
+ (('--lock-wait', str(lock_wait)) if lock_wait else ())
+ (('--stats',) if logger.isEnabledFor(logging.INFO) else ())
+ (('--info',) if logger.isEnabledFor(logging.INFO) else ())

Any reason not to combine these two lines?

Any reason not to combine these two lines?
Outdated
Review

Not really. Done.

Not really. Done.
+ (('--debug', '--list') if logger.isEnabledFor(logging.DEBUG) else ())
+ (('--debug', '--list', '--show-rc') if logger.isEnabledFor(logging.DEBUG) else ())
+ (('--dry-run',) if dry_run else ())
)

View File

@ -81,7 +81,7 @@ def parse_arguments(*arguments):
dest='json',
default=False,
action='store_true',
help='Output results from the --list option as json',
help='Output results from the --list or --info options as json',
)
parser.add_argument(
'-n', '--dry-run',

View File

@ -124,6 +124,13 @@ map:
punctuation, so it parses correctly. And backslash any quote or backslash
literals as well.
example: "!\"#$%&'()*+,-./:;<=>?@[\\]^_`{|}~"
checkpoint_interval:
type: int
desc: |
Number of seconds between each checkpoint during a long-running backup. See
https://borgbackup.readthedocs.io/en/stable/faq.html#if-a-backup-stops-mid-way-does-the-already-backed-up-data-stay-there
for details. Defaults to checkpoints every 1800 seconds (30 minutes).
example: 1800
compression:
type: scalar
desc: |

View File

@ -74,8 +74,8 @@ def parse_configuration(config_filename, schema_filename):
logging.getLogger('pykwalify').setLevel(logging.ERROR)
try:
config = yaml.round_trip_load(open(config_filename))
schema = yaml.round_trip_load(open(schema_filename))
config = yaml.safe_load(open(config_filename))
schema = yaml.safe_load(open(schema_filename))
except yaml.error.YAMLError as error:
raise Validation_error(config_filename, (str(error),))

View File

@ -177,7 +177,7 @@ def test_check_archives_with_verbosity_lots_calls_borg_with_debug_parameter():
flexmock(module).should_receive('_make_check_flags').and_return(())
insert_logging_mock(logging.DEBUG)
insert_subprocess_mock(
('borg', 'check', 'repo', '--debug'),
('borg', 'check', 'repo', '--debug', '--show-rc'),
stdout=None, stderr=STDOUT,
)

View File

@ -296,7 +296,7 @@ def test_create_archive_with_verbosity_lots_calls_borg_with_debug_parameter():
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 + ('--list', '--filter', 'AME', '--info', '--stats', '--debug'))
insert_subprocess_mock(CREATE_COMMAND + ('--list', '--filter', 'AME', '--info', '--stats', '--debug', '--show-rc'))
insert_logging_mock(logging.DEBUG)
module.create_archive(
@ -358,9 +358,9 @@ def test_create_archive_with_dry_run_and_verbosity_lots_calls_borg_without_stats
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 + ('--list', '--filter', 'AME', '--info', '--stats', '--debug', '--dry-run'))
insert_subprocess_mock(CREATE_COMMAND + ('--list', '--filter', 'AME', '--info', '--stats', '--debug', '--show-rc', '--dry-run'))
insert_logging_mock(logging.DEBUG)
module.create_archive(
dry_run=True,
repository='repo',
@ -373,6 +373,25 @@ def test_create_archive_with_dry_run_and_verbosity_lots_calls_borg_without_stats
)
def test_create_archive_with_checkpoint_interval_calls_borg_with_checkpoint_interval_parameters():
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 + ('--checkpoint-interval', '600'))
module.create_archive(
dry_run=False,
repository='repo',
location_config={
'source_directories': ['foo', 'bar'],
'repositories': ['repo'],
'exclude_patterns': None,
},
storage_config={'checkpoint_interval': 600},
)
def test_create_archive_with_compression_calls_borg_with_compression_parameters():
flexmock(module).should_receive('_expand_directories').and_return(('foo', 'bar')).and_return(())
flexmock(module).should_receive('_write_pattern_file').and_return(None)

View File

@ -76,11 +76,11 @@ def test_extract_last_archive_dry_run_with_verbosity_some_should_call_borg_with_
def test_extract_last_archive_dry_run_with_verbosity_lots_should_call_borg_with_debug_parameter():
flexmock(sys.stdout).encoding = 'utf-8'
insert_subprocess_check_output_mock(
('borg', 'list', '--short', 'repo', '--debug'),
('borg', 'list', '--short', 'repo', '--debug', '--show-rc'),
result='archive1\narchive2\n'.encode('utf-8'),
)
insert_subprocess_mock(
('borg', 'extract', '--dry-run', 'repo::archive2', '--debug', '--list'),
('borg', 'extract', '--dry-run', 'repo::archive2', '--debug', '--show-rc', '--list'),
)
insert_logging_mock(logging.DEBUG)

View File

@ -37,7 +37,7 @@ def test_display_archives_info_with_verbosity_some_calls_borg_with_info_paramete
def test_display_archives_info_with_verbosity_lots_calls_borg_with_debug_parameter():
insert_subprocess_mock(INFO_COMMAND + ('--info', '--debug',))
insert_subprocess_mock(INFO_COMMAND + ('--info', '--debug', '--show-rc'))
insert_logging_mock(logging.DEBUG)
module.display_archives_info(

View File

@ -39,9 +39,9 @@ def test_list_archives_with_verbosity_some_calls_borg_with_info_parameter():
def test_list_archives_with_verbosity_lots_calls_borg_with_debug_parameter():
insert_subprocess_mock(LIST_COMMAND + ('--info', '--debug',))
insert_subprocess_mock(LIST_COMMAND + ('--info', '--debug', '--show-rc'))
insert_logging_mock(logging.DEBUG)
module.list_archives(
repository='repo',
storage_config={},

View File

@ -96,9 +96,9 @@ def test_prune_archives_with_verbosity_lots_calls_borg_with_debug_parameter():
flexmock(module).should_receive('_make_prune_flags').with_args(retention_config).and_return(
BASE_PRUNE_FLAGS,
)
insert_subprocess_mock(PRUNE_COMMAND + ('--stats', '--info', '--debug', '--list'))
insert_subprocess_mock(PRUNE_COMMAND + ('--stats', '--info', '--debug', '--list', '--show-rc'))
insert_logging_mock(logging.DEBUG)
module.prune_archives(
repository='repo',
storage_config={},

View File

@ -22,22 +22,29 @@ for sub_command in prune create check list info; do
sort borgmatic_borg_flags > borgmatic_borg_flags.sorted
mv borgmatic_borg_flags.sorted borgmatic_borg_flags
for line in $(borg $sub_command --help | awk -v RS= '/^usage:/') ; do
for word in $(borg $sub_command --help | grep '^ -') ; do
# Exclude a bunch of flags that borgmatic actually supports, but don't get exercised by the
# generated sample config, and also flags that don't make sense to support.
echo "$line" | grep -- -- | sed -r 's/(\[|\])//g' \
| grep -v '^-h$' \
echo "$word" | grep ^-- | sed -e 's/,$//' \
| grep -v '^--archives-only$' \
| grep -v '^--repository-only$' \
| grep -v '^--stats$' \
| grep -v '^--list$' \
| grep -v '^--critical$' \
| grep -v '^--error$' \
| grep -v '^--warning$' \
| grep -v '^--info$' \
| grep -v '^--debug$' \
| grep -v '^--dry-run$' \
| grep -v '^--error$' \
| grep -v '^--help$' \
| grep -v '^--info$' \
| grep -v '^--list$' \
| grep -v '^--nobsdflags$' \
| grep -v '^--pattern$' \
| grep -v '^--repository-only$' \
| grep -v '^--show-rc$' \
| grep -v '^--stats$' \
| grep -v '^--verbose$' \
| grep -v '^--warning$' \
| grep -v '^-h$' \
>> all_borg_flags
done
sort all_borg_flags > all_borg_flags.sorted
mv all_borg_flags.sorted all_borg_flags

View File

@ -1,7 +1,7 @@
from setuptools import setup, find_packages
VERSION = '1.2.1.dev0'
VERSION = '1.2.3.dev0'
setup(
@ -32,7 +32,7 @@ setup(
'atticmatic',
],
install_requires=(
'pykwalify>=1.6.0',
'pykwalify>=1.6.0,<14.06',
'ruamel.yaml>0.15.0,<0.16.0',
'setuptools',
),