Rework logging/verbosity system #90
3
AUTHORS
3
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
|
||||
|
|
|
|||
|
|
@ -148,7 +148,8 @@ 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', '--info', '--stats') if logger.isEnabledFor(logging.INFO) else ())
|
||||
+ (('--list', '--filter', 'AME', '--info') if logger.isEnabledFor(logging.INFO) else ())
|
||||
|
|
||||
+ (('--stats',) if not dry_run and logger.isEnabledFor(logging.INFO) else ())
|
||||
witten
commented
Does that mean Borg just ignores the > 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?
floli
commented
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... ;-)
witten
commented
If you wanted to avoid relying on the undocumented behavior ( Another option would be to use 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 ())
```
floli
commented
I already thought about using 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.
witten
commented
Looks great, thanks! Looks great, thanks!
|
||||
+ (('--debug', '--show-rc') if logger.isEnabledFor(logging.DEBUG) else ())
|
||||
+ (('--dry-run',) if dry_run else ())
|
||||
)
|
||||
|
|
|
|||
|
|
@ -52,8 +52,7 @@ def prune_archives(dry_run, repository, storage_config, retention_config, local_
|
|||
+ (('--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 logger.isEnabledFor(logging.INFO) else ())
|
||||
+ (('--info',) if logger.isEnabledFor(logging.INFO) else ())
|
||||
+ (('--stats', '--info') if logger.isEnabledFor(logging.INFO) else ())
|
||||
+ (('--debug', '--list', '--show-rc') if logger.isEnabledFor(logging.DEBUG) else ())
|
||||
|
witten
commented
Any reason not to combine these two lines? Any reason not to combine these two lines?
floli
commented
Not really. Done. Not really. Done.
|
||||
+ (('--dry-run',) if dry_run else ())
|
||||
)
|
||||
|
|
|
|||
|
|
@ -92,7 +92,7 @@ def parse_arguments(*arguments):
|
|||
parser.add_argument(
|
||||
'-v', '--verbosity',
|
||||
type=int,
|
||||
help='Display verbose progress (1 for INFO, 2 for DEBUG)',
|
||||
help='Display verbose progress (1 for some, 2 for lots)',
|
||||
|
witten
commented
Might be nice to leave these as "some" and "lots", if only because not all users are Python programmers, and so won't necessarily be familiar with Python log levels. (I don't feel strongly about this.) Might be nice to leave these as "some" and "lots", if only because not all users are Python programmers, and so won't necessarily be familiar with Python log levels. (I don't feel strongly about this.)
floli
commented
INFO and DEBUG are pretty much universal for log levels. But I am fine and have changed it back to some and lots. Done. INFO and DEBUG are pretty much universal for log levels. But I am fine and have changed it back to some and lots. Done.
|
||||
)
|
||||
|
||||
args = parser.parse_args(arguments)
|
||||
|
|
@ -121,7 +121,7 @@ def run_configuration(config_filename, args): # pragma: no cover
|
|||
Parse a single configuration file, and execute its defined pruning, backups, and/or consistency
|
||||
checks.
|
||||
'''
|
||||
logger.debug('{}: Parsing configuration file'.format(config_filename))
|
||||
logger.info('{}: Parsing configuration file'.format(config_filename))
|
||||
|
witten
commented
Any reason for the switch to Any reason for the switch to `debug` here? I think the idea with it being `info` is that you could easily see what borgmatic is doing with just the first (`-v 1`) verbosity level. Especially useful if you've got multiple configuration files and you want to see what's being done for each.
floli
commented
Definitely a matter of taste here. Switched it back to info, as you proposed. Definitely a matter of taste here. Switched it back to info, as you proposed.
|
||||
config = validate.parse_configuration(config_filename, validate.schema_filename())
|
||||
(location, storage, retention, consistency, hooks) = (
|
||||
config.get(section_name, {})
|
||||
|
|
|
|||
|
|
@ -5,7 +5,7 @@ from flexmock import flexmock
|
|||
import pytest
|
||||
|
||||
from borgmatic.borg import check as module
|
||||
|
||||
from borgmatic.tests.unit.test_verbosity import insert_logging_mock
|
||||
|
||||
def insert_subprocess_mock(check_call_command, **kwargs):
|
||||
subprocess = flexmock(module.subprocess)
|
||||
|
|
@ -16,12 +16,6 @@ def insert_subprocess_never():
|
|||
subprocess = flexmock(module.subprocess)
|
||||
subprocess.should_receive('check_call').never()
|
||||
|
||||
|
||||
def insert_logging_mock(log_level):
|
||||
logging = flexmock(module.logging.Logger)
|
||||
logging.should_receive('isEnabledFor').replace_with(lambda x : x >= log_level)
|
||||
|
||||
|
||||
|
||||
def test_parse_checks_returns_them_as_tuple():
|
||||
checks = module._parse_checks({'checks': ['foo', 'disabled', 'bar']})
|
||||
|
|
|
|||
|
|
@ -3,10 +3,7 @@ import logging, os
|
|||
from flexmock import flexmock
|
||||
|
||||
from borgmatic.borg import create as module
|
||||
|
||||
def insert_logging_mock(log_level):
|
||||
logging = flexmock(module.logging.Logger)
|
||||
logging.should_receive('isEnabledFor').replace_with(lambda x : x >= log_level)
|
||||
from borgmatic.tests.unit.test_verbosity import insert_logging_mock
|
||||
|
||||
|
||||
def test_initialize_environment_with_passcommand_should_set_environment():
|
||||
|
|
@ -332,12 +329,14 @@ 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():
|
||||
""" --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 + ('--list', '--filter', 'AME', '--info', '--stats', '--dry-run'))
|
||||
insert_subprocess_mock(CREATE_COMMAND + ('--list', '--filter', 'AME', '--info', '--dry-run'))
|
||||
insert_logging_mock(logging.INFO)
|
||||
|
||||
module.create_archive(
|
||||
|
|
@ -353,12 +352,14 @@ 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():
|
||||
""" --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 + ('--list', '--filter', 'AME', '--info', '--stats', '--debug', '--show-rc', '--dry-run'))
|
||||
insert_subprocess_mock(CREATE_COMMAND + ('--list', '--filter', 'AME', '--info', '--debug', '--show-rc', '--dry-run'))
|
||||
insert_logging_mock(logging.DEBUG)
|
||||
|
||||
module.create_archive(
|
||||
|
|
|
|||
|
|
@ -4,6 +4,7 @@ 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):
|
||||
|
|
@ -21,11 +22,6 @@ def insert_subprocess_check_output_mock(check_output_command, result, **kwargs):
|
|||
subprocess.should_receive('check_output').with_args(check_output_command, **kwargs).and_return(result).once()
|
||||
|
||||
|
||||
def insert_logging_mock(log_level):
|
||||
logging = flexmock(module.logging.Logger)
|
||||
logging.should_receive('isEnabledFor').replace_with(lambda x : x >= log_level)
|
||||
|
||||
|
||||
def test_extract_last_archive_dry_run_should_call_borg_with_last_archive():
|
||||
flexmock(sys.stdout).encoding = 'utf-8'
|
||||
|
witten
commented
Given that this occurs several times, you could factor it out into a common test file. For instance, the existing Given that this occurs several times, you could factor it out into a common test file. For instance, the existing `borgmatic/tests/unit/test_verbosity.py` might be a good candidate.
floli
commented
Yeah, already had this on my agenda. Done now. Yeah, already had this on my agenda. Done now.
|
||||
insert_subprocess_check_output_mock(
|
||||
|
|
|
|||
|
|
@ -4,16 +4,13 @@ from collections import OrderedDict
|
|||
from flexmock import flexmock
|
||||
|
||||
from borgmatic.borg import info as module
|
||||
from borgmatic.tests.unit.test_verbosity import insert_logging_mock
|
||||
|
||||
|
||||
def insert_subprocess_mock(check_call_command, **kwargs):
|
||||
subprocess = flexmock(module.subprocess)
|
||||
subprocess.should_receive('check_output').with_args(check_call_command, **kwargs).once()
|
||||
|
||||
def insert_logging_mock(log_level):
|
||||
logging = flexmock(module.logging.Logger)
|
||||
logging.should_receive('isEnabledFor').replace_with(lambda x : x >= log_level)
|
||||
|
||||
|
||||
INFO_COMMAND = ('borg', 'info', 'repo')
|
||||
|
||||
|
|
|
|||
|
|
@ -4,17 +4,13 @@ from collections import OrderedDict
|
|||
from flexmock import flexmock
|
||||
|
||||
from borgmatic.borg import list as module
|
||||
from borgmatic.tests.unit.test_verbosity import insert_logging_mock
|
||||
|
||||
|
||||
def insert_subprocess_mock(check_call_command, **kwargs):
|
||||
subprocess = flexmock(module.subprocess)
|
||||
subprocess.should_receive('check_output').with_args(check_call_command, **kwargs).once()
|
||||
|
||||
def insert_logging_mock(log_level):
|
||||
logging = flexmock(module.logging.Logger)
|
||||
logging.should_receive('isEnabledFor').replace_with(lambda x : x >= log_level)
|
||||
|
||||
|
||||
|
||||
LIST_COMMAND = ('borg', 'list', 'repo')
|
||||
|
||||
|
|
|
|||
|
|
@ -4,6 +4,7 @@ from collections import OrderedDict
|
|||
from flexmock import flexmock
|
||||
|
||||
from borgmatic.borg import prune as module
|
||||
from borgmatic.tests.unit.test_verbosity import insert_logging_mock
|
||||
|
||||
|
||||
def insert_subprocess_mock(check_call_command, **kwargs):
|
||||
|
|
@ -11,10 +12,6 @@ def insert_subprocess_mock(check_call_command, **kwargs):
|
|||
subprocess.should_receive('check_call').with_args(check_call_command, **kwargs).once()
|
||||
|
||||
|
||||
def insert_logging_mock(log_level):
|
||||
logging = flexmock(module.logging.Logger)
|
||||
logging.should_receive('isEnabledFor').replace_with(lambda x : x >= log_level)
|
||||
|
||||
|
||||
BASE_PRUNE_FLAGS = (
|
||||
('--keep-daily', '1'),
|
||||
|
|
|
|||
|
|
@ -1,11 +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)
|
||||
|
||||
|
witten
commented
Note that the name of this test function is now incorrect! Note that the name of this test function is now incorrect!
floli
commented
Done. Also added an assertion to the previous function to test that Done. Also added an assertion to the previous function to test that `VERBOSTIY_LOTS` maps to `DEBUG`.
|
||||
|
||||
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():
|
||||
def test_verbosity_to_log_level_maps_unknown_verbosity_to_info_level():
|
||||
assert module.verbosity_to_log_level('my pants') == logging.INFO
|
||||
|
|
|
|||
Loading…
Reference in New Issue
You'll need to retain the logic that omits
--statsduring a dry run, because--statsand--dry-runcan't be specified together. More info here: https://borgbackup.readthedocs.io/en/stable/usage/create.html#descriptionOh, wasn't aware of that, done.