From 6b265f2a53a07be5796d72c525baacef0424482e Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Antoine=20Beaupr=C3=A9?= Date: Mon, 23 Nov 2015 12:00:57 -0500 Subject: [PATCH 01/11] alias --verbose to --log-level=info print_verbose is now simply logger.info() and is always displayed if log level allows it. this affects only the `prune` and `mount` commands which were the only users of the --verbose option. the additional display is which archives are kept and pruned and a single message when the fileystem is mounted. files iteration in create and extract is now printed through a separate function which will be later controled through a topical flag. --- borg/archiver.py | 31 +++++++++++++------------------ 1 file changed, 13 insertions(+), 18 deletions(-) diff --git a/borg/archiver.py b/borg/archiver.py index 1c066d954..e7c9cb572 100644 --- a/borg/archiver.py +++ b/borg/archiver.py @@ -51,9 +51,8 @@ class ToggleAction(argparse.Action): class Archiver: - def __init__(self, verbose=False, lock_wait=None): + def __init__(self, lock_wait=None): self.exit_code = EXIT_SUCCESS - self.verbose = verbose self.lock_wait = lock_wait def open_repository(self, location, create=False, exclusive=False, lock=True): @@ -74,10 +73,8 @@ class Archiver: self.exit_code = EXIT_WARNING # we do not terminate here, so it is a warning logger.warning(msg) - def print_verbose(self, msg, *args): - if self.verbose: - msg = args and msg % args or msg - logger.info(msg) + def print_file_status(self, status, path): + logger.info("1s %s", status, remove_surrogates(path)) def do_serve(self, args): """Start in server mode. This command is usually not used manually. @@ -166,7 +163,7 @@ class Archiver: self.print_warning('%s: %s', path, e) else: status = '-' - self.print_verbose("%1s %s", status, remove_surrogates(path)) + self.print_file_status(status, path) continue path = os.path.normpath(path) if args.one_file_system: @@ -265,9 +262,7 @@ class Archiver: status = '?' # need to add a status code somewhere else: status = '-' # dry run, item was not backed up - # output ALL the stuff - it can be easily filtered using grep. - # even stuff considered unchanged might be interesting. - self.print_verbose("%1s %s", status, remove_surrogates(path)) + self.print_file_status(status, path) def do_extract(self, args): """Extract archive contents""" @@ -295,7 +290,7 @@ class Archiver: if not args.dry_run: while dirs and not item[b'path'].startswith(dirs[-1][b'path']): archive.extract_item(dirs.pop(-1), stdout=stdout) - self.print_verbose(remove_surrogates(orig_path)) + logger.info(remove_surrogates(orig_path)) try: if dry_run: archive.extract_item(item, dry_run=True) @@ -381,7 +376,7 @@ class Archiver: else: archive = None operations = FuseOperations(key, repository, manifest, archive) - self.print_verbose("Mounting filesystem") + logger.info("Mounting filesystem") try: operations.mount(args.mountpoint, args.options, args.foreground) except RuntimeError: @@ -484,12 +479,12 @@ class Archiver: to_delete = [a for a in archives if a not in keep] stats = Statistics() for archive in keep: - self.print_verbose('Keeping archive: %s' % format_archive(archive)) + logger.info('Keeping archive: %s' % format_archive(archive)) for archive in to_delete: if args.dry_run: - self.print_verbose('Would prune: %s' % format_archive(archive)) + logger.info('Would prune: %s' % format_archive(archive)) else: - self.print_verbose('Pruning archive: %s' % format_archive(archive)) + logger.info('Pruning archive: %s' % format_archive(archive)) Archive(repository, key, manifest, archive.name, cache).delete(stats) if to_delete and not args.dry_run: manifest.write() @@ -666,8 +661,9 @@ class Archiver: def build_parser(self, args=None, prog=None): common_parser = argparse.ArgumentParser(add_help=False, prog=prog) - common_parser.add_argument('-v', '--verbose', dest='verbose', action='store_true', default=False, - help='verbose output') + common_parser.add_argument('-v', '--verbose', dest='log_level', + action='store_const', const='info', default='info', + help='verbose output, same as --log-level=info') common_parser.add_argument('--log-level', dest='log_level', default='info', metavar='LEVEL', choices=('debug', 'info', 'warning', 'error', 'critical'), help='set the log level to LEVEL, default: %(default)s)') @@ -1180,7 +1176,6 @@ class Archiver: def run(self, args): os.umask(args.umask) # early, before opening files - self.verbose = args.verbose self.lock_wait = args.lock_wait RemoteRepository.remote_path = args.remote_path RemoteRepository.umask = args.umask From 9899eaf241b1e6351733bf1d2db68046edec5994 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Antoine=20Beaupr=C3=A9?= Date: Mon, 23 Nov 2015 12:10:21 -0500 Subject: [PATCH 02/11] silence file listing unless --changed is present --- borg/archiver.py | 6 +++++- borg/testsuite/archiver.py | 21 +++++++++++++++++++++ 2 files changed, 26 insertions(+), 1 deletion(-) diff --git a/borg/archiver.py b/borg/archiver.py index e7c9cb572..15c6caf85 100644 --- a/borg/archiver.py +++ b/borg/archiver.py @@ -74,7 +74,8 @@ class Archiver: logger.warning(msg) def print_file_status(self, status, path): - logger.info("1s %s", status, remove_surrogates(path)) + if self.args.changed: + logger.info("%1s %s" % (status, remove_surrogates(path))) def do_serve(self, args): """Start in server mode. This command is usually not used manually. @@ -801,6 +802,8 @@ class Archiver: help="""toggle progress display while creating the archive, showing Original, Compressed and Deduplicated sizes, followed by the Number of files seen and the path being processed, default: %(default)s""") + subparser.add_argument('--changed', action='store_true', dest='changed', default=False, + help="""display which files were added to the archive""") subparser.add_argument('-e', '--exclude', dest='excludes', type=ExcludePattern, action='append', metavar="PATTERN", help='exclude paths matching PATTERN') @@ -1171,6 +1174,7 @@ class Archiver: args = self.preprocess_args(args) parser = self.build_parser(args) args = parser.parse_args(args or ['-h']) + self.args = args update_excludes(args) return args diff --git a/borg/testsuite/archiver.py b/borg/testsuite/archiver.py index 9d78988c6..a066f6ec1 100644 --- a/borg/testsuite/archiver.py +++ b/borg/testsuite/archiver.py @@ -723,6 +723,27 @@ class ArchiverTestCase(ArchiverTestCaseBase): # http://borgbackup.readthedocs.org/en/latest/faq.html#i-am-seeing-a-added-status-for-a-unchanged-file self.assert_in("A input/file2", output) + def test_create_topical(self): + self.create_regular_file('file1', size=1024 * 80) + self.cmd('init', self.repository_location) + # no listing by default + output = self.cmd('create', self.repository_location + '::test', 'input') + self.assert_not_in('file1', output) + # shouldn't be listed even if unchanged + output = self.cmd('create', self.repository_location + '::test0', 'input') + self.assert_not_in('file1', output) + # should list the file as unchanged + #output = self.cmd('create', '--unchanged', self.repository_location + '::test1', 'input') + #self.assert_in('file1', output) + # should *not* list the file as changed + #output = self.cmd('create', '--changed', self.repository_location + '::test2', 'input') + #self.assert_not_in('file1', output) + # change the file + self.create_regular_file('file1', size=1024 * 100) + # should list the file as changed + output = self.cmd('create', '--changed', self.repository_location + '::test3', 'input') + self.assert_in('file1', output) + def test_cmdline_compatibility(self): self.create_regular_file('file1', size=1024 * 80) self.cmd('init', self.repository_location) From 8d3d1c22d68b21b09553417fce08b938e9404ae6 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Antoine=20Beaupr=C3=A9?= Date: Mon, 23 Nov 2015 12:38:11 -0500 Subject: [PATCH 03/11] silence borg by default this also prints file status on stderr directly, bypassing the logger as we do with other topical flags (like progress and status) --- borg/archiver.py | 6 +++--- borg/testsuite/archiver.py | 6 +++--- 2 files changed, 6 insertions(+), 6 deletions(-) diff --git a/borg/archiver.py b/borg/archiver.py index 15c6caf85..6c2875d1b 100644 --- a/borg/archiver.py +++ b/borg/archiver.py @@ -75,7 +75,7 @@ class Archiver: def print_file_status(self, status, path): if self.args.changed: - logger.info("%1s %s" % (status, remove_surrogates(path))) + print("%1s %s" % (status, remove_surrogates(path)), file=sys.stderr) def do_serve(self, args): """Start in server mode. This command is usually not used manually. @@ -663,9 +663,9 @@ class Archiver: def build_parser(self, args=None, prog=None): common_parser = argparse.ArgumentParser(add_help=False, prog=prog) common_parser.add_argument('-v', '--verbose', dest='log_level', - action='store_const', const='info', default='info', + action='store_const', const='info', default='warning', help='verbose output, same as --log-level=info') - common_parser.add_argument('--log-level', dest='log_level', default='info', metavar='LEVEL', + common_parser.add_argument('--log-level', dest='log_level', default='warning', metavar='LEVEL', choices=('debug', 'info', 'warning', 'error', 'critical'), help='set the log level to LEVEL, default: %(default)s)') common_parser.add_argument('--lock-wait', dest='lock_wait', type=int, metavar='N', default=1, diff --git a/borg/testsuite/archiver.py b/borg/testsuite/archiver.py index a066f6ec1..c458f97f5 100644 --- a/borg/testsuite/archiver.py +++ b/borg/testsuite/archiver.py @@ -947,13 +947,13 @@ class ArchiverCheckTestCase(ArchiverTestCaseBase): return archive, repository def test_check_usage(self): - output = self.cmd('check', self.repository_location, exit_code=0) + output = self.cmd('check', '--log-level=info', self.repository_location, exit_code=0) self.assert_in('Starting repository check', output) self.assert_in('Starting archive consistency check', output) - output = self.cmd('check', '--repository-only', self.repository_location, exit_code=0) + output = self.cmd('check', '--log-level=info', '--repository-only', self.repository_location, exit_code=0) self.assert_in('Starting repository check', output) self.assert_not_in('Starting archive consistency check', output) - output = self.cmd('check', '--archives-only', self.repository_location, exit_code=0) + output = self.cmd('check', '--log-level=info', '--archives-only', self.repository_location, exit_code=0) self.assert_not_in('Starting repository check', output) self.assert_in('Starting archive consistency check', output) From a062e8f821af35075f4d4a4c0372e8560f792775 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Antoine=20Beaupr=C3=A9?= Date: Mon, 23 Nov 2015 12:52:24 -0500 Subject: [PATCH 04/11] update documentation to follow changes --- docs/usage.rst | 8 +------- 1 file changed, 1 insertion(+), 7 deletions(-) diff --git a/docs/usage.rst b/docs/usage.rst index 1db3bc594..57702452a 100644 --- a/docs/usage.rst +++ b/docs/usage.rst @@ -21,12 +21,6 @@ Supported levels: ``debug``, ``info``, ``warning``, ``error``, ``critical``. All log messages created with at least the given level will be output. -Amount of informational output -~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ - -For some subcommands, using the ``-v`` or ``--verbose`` option will give you -more informational output (at ``info`` level). - Return codes ~~~~~~~~~~~~ @@ -435,7 +429,7 @@ Here are misc. notes about topics that are maybe not covered in enough detail in Item flags ~~~~~~~~~~ -`borg create -v` outputs a verbose list of all files, directories and other +`borg create --changed` outputs a verbose list of all files, directories and other file system items it considered. For each item, it prefixes a single-letter flag that indicates type and/or status of the item. From fce5aed5bbab6c23299cb30da2d40aa515155245 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Antoine=20Beaupr=C3=A9?= Date: Mon, 23 Nov 2015 17:30:49 -0500 Subject: [PATCH 05/11] move changed with other topical flags we need to have a sane default there otherwise the option may not be defined in some sub-commands and will crash --- borg/archiver.py | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/borg/archiver.py b/borg/archiver.py index 6c2875d1b..1c396a920 100644 --- a/borg/archiver.py +++ b/borg/archiver.py @@ -74,7 +74,7 @@ class Archiver: logger.warning(msg) def print_file_status(self, status, path): - if self.args.changed: + if self.changed: print("%1s %s" % (status, remove_surrogates(path)), file=sys.stderr) def do_serve(self, args): @@ -1174,13 +1174,14 @@ class Archiver: args = self.preprocess_args(args) parser = self.build_parser(args) args = parser.parse_args(args or ['-h']) - self.args = args update_excludes(args) return args def run(self, args): os.umask(args.umask) # early, before opening files self.lock_wait = args.lock_wait + self.changed = getattr(args, 'changed', False) + self.unchanged = getattr(args, 'unchanged', False) RemoteRepository.remote_path = args.remote_path RemoteRepository.umask = args.umask setup_logging(level=args.log_level) # do not use loggers before this! From 1785ca54ba82ba851905478446d9bf00a3f9f597 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Antoine=20Beaupr=C3=A9?= Date: Mon, 23 Nov 2015 19:54:30 -0500 Subject: [PATCH 06/11] do not display unchanged files by default add a --unchanged topical file to display those files --- borg/archiver.py | 10 ++++++++-- borg/testsuite/archiver.py | 11 +++++++---- 2 files changed, 15 insertions(+), 6 deletions(-) diff --git a/borg/archiver.py b/borg/archiver.py index 1c396a920..eefe81369 100644 --- a/borg/archiver.py +++ b/borg/archiver.py @@ -74,8 +74,12 @@ class Archiver: logger.warning(msg) def print_file_status(self, status, path): - if self.changed: - print("%1s %s" % (status, remove_surrogates(path)), file=sys.stderr) + if status == 'U': + if self.unchanged: + print("%1s %s" % (status, remove_surrogates(path)), file=sys.stderr) + else: + if self.changed: + print("%1s %s" % (status, remove_surrogates(path)), file=sys.stderr) def do_serve(self, args): """Start in server mode. This command is usually not used manually. @@ -804,6 +808,8 @@ class Archiver: and the path being processed, default: %(default)s""") subparser.add_argument('--changed', action='store_true', dest='changed', default=False, help="""display which files were added to the archive""") + subparser.add_argument('--unchanged', action='store_true', dest='unchanged', default=False, + help="""display which files were *not* added to the archive""") subparser.add_argument('-e', '--exclude', dest='excludes', type=ExcludePattern, action='append', metavar="PATTERN", help='exclude paths matching PATTERN') diff --git a/borg/testsuite/archiver.py b/borg/testsuite/archiver.py index c458f97f5..fcabb35d8 100644 --- a/borg/testsuite/archiver.py +++ b/borg/testsuite/archiver.py @@ -724,7 +724,10 @@ class ArchiverTestCase(ArchiverTestCaseBase): self.assert_in("A input/file2", output) def test_create_topical(self): + now = time.time() self.create_regular_file('file1', size=1024 * 80) + os.utime('input/file1', (now-5, now-5)) + self.create_regular_file('file2', size=1024 * 80) self.cmd('init', self.repository_location) # no listing by default output = self.cmd('create', self.repository_location + '::test', 'input') @@ -733,11 +736,11 @@ class ArchiverTestCase(ArchiverTestCaseBase): output = self.cmd('create', self.repository_location + '::test0', 'input') self.assert_not_in('file1', output) # should list the file as unchanged - #output = self.cmd('create', '--unchanged', self.repository_location + '::test1', 'input') - #self.assert_in('file1', output) + output = self.cmd('create', '--unchanged', self.repository_location + '::test1', 'input') + self.assert_in('file1', output) # should *not* list the file as changed - #output = self.cmd('create', '--changed', self.repository_location + '::test2', 'input') - #self.assert_not_in('file1', output) + output = self.cmd('create', '--changed', self.repository_location + '::test2', 'input') + self.assert_not_in('file1', output) # change the file self.create_regular_file('file1', size=1024 * 100) # should list the file as changed From b09643e14f911e0f14a9109560a0177a8eaa7444 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Antoine=20Beaupr=C3=A9?= Date: Tue, 24 Nov 2015 12:11:43 -0500 Subject: [PATCH 07/11] change file status test and cleanup last ref to --verbose this ports the changes here to #445 --- borg/testsuite/archiver.py | 4 ++-- docs/usage.rst | 5 +++-- 2 files changed, 5 insertions(+), 4 deletions(-) diff --git a/borg/testsuite/archiver.py b/borg/testsuite/archiver.py index fcabb35d8..8542c338a 100644 --- a/borg/testsuite/archiver.py +++ b/borg/testsuite/archiver.py @@ -713,11 +713,11 @@ class ArchiverTestCase(ArchiverTestCaseBase): os.utime('input/file1', (now - 5, now - 5)) # 5 seconds ago self.create_regular_file('file2', size=1024 * 80) self.cmd('init', self.repository_location) - output = self.cmd('create', '--verbose', self.repository_location + '::test', 'input') + output = self.cmd('create', '--changed', '--unchanged', self.repository_location + '::test', 'input') self.assert_in("A input/file1", output) self.assert_in("A input/file2", output) # should find first file as unmodified - output = self.cmd('create', '--verbose', self.repository_location + '::test1', 'input') + output = self.cmd('create', '--changed', '--unchanged', self.repository_location + '::test1', 'input') self.assert_in("U input/file1", output) # this is expected, although surprising, for why, see: # http://borgbackup.readthedocs.org/en/latest/faq.html#i-am-seeing-a-added-status-for-a-unchanged-file diff --git a/docs/usage.rst b/docs/usage.rst index 57702452a..67e6a039f 100644 --- a/docs/usage.rst +++ b/docs/usage.rst @@ -430,7 +430,8 @@ Item flags ~~~~~~~~~~ `borg create --changed` outputs a verbose list of all files, directories and other -file system items it considered. For each item, it prefixes a single-letter +file system items it considered, with the exception of unchanged files +(for this, also add `--unchanged`). For each item, it prefixes a single-letter flag that indicates type and/or status of the item. A uppercase character represents the status of a regular file relative to the @@ -440,7 +441,7 @@ chunks are stored. For 'U' all data chunks refer to already existing chunks. - 'A' = regular file, added (see also :ref:`a_status_oddity` in the FAQ) - 'M' = regular file, modified -- 'U' = regular file, unchanged +- 'U' = regular file, unchanged (only if `--unchanged` is specified) - 'E' = regular file, an error happened while accessing/reading *this* file A lowercase character means a file type other than a regular file, From 21bd01ef1677ad52e73b1b4d98ba1364d4c64506 Mon Sep 17 00:00:00 2001 From: Thomas Waldmann Date: Wed, 2 Dec 2015 02:55:59 +0100 Subject: [PATCH 08/11] add a --filter option replacing --changed/--unchanged the problem here was that we do not just have changed and unchanged items, but also a lot of items besides regular files which we just back up "as is" without determining whether they are changed or not. thus, we can't support changed/unchanged in a way users would expect them to work. the A/M/U status only applies to the data content of regular files (compared to the index). for all items, we ALWAYS save the metadata, there is no changed / not changed detection there. thus, I replaced this with a --filter option where you can just specify which status chars you want to see listed in the output. E.g. --filter AM will only show regular files with A(dded) or M(odified) state, but nothing else. Not giving --filter defaults to showing all items no matter what status they have. Output is emitted via logger at info level, so it won't show up except if the logger is at that level. --- borg/archiver.py | 17 +++++------------ borg/testsuite/archiver.py | 10 +++++----- docs/usage.rst | 14 +++++++++----- 3 files changed, 19 insertions(+), 22 deletions(-) diff --git a/borg/archiver.py b/borg/archiver.py index eefe81369..47c000aed 100644 --- a/borg/archiver.py +++ b/borg/archiver.py @@ -74,12 +74,8 @@ class Archiver: logger.warning(msg) def print_file_status(self, status, path): - if status == 'U': - if self.unchanged: - print("%1s %s" % (status, remove_surrogates(path)), file=sys.stderr) - else: - if self.changed: - print("%1s %s" % (status, remove_surrogates(path)), file=sys.stderr) + if self.output_filter is None or status in self.output_filter: + logger.info("%1s %s", status, remove_surrogates(path)) def do_serve(self, args): """Start in server mode. This command is usually not used manually. @@ -128,6 +124,7 @@ class Archiver: def do_create(self, args): """Create new archive""" + self.output_filter = args.output_filter dry_run = args.dry_run t0 = datetime.now() if not dry_run: @@ -806,10 +803,8 @@ class Archiver: help="""toggle progress display while creating the archive, showing Original, Compressed and Deduplicated sizes, followed by the Number of files seen and the path being processed, default: %(default)s""") - subparser.add_argument('--changed', action='store_true', dest='changed', default=False, - help="""display which files were added to the archive""") - subparser.add_argument('--unchanged', action='store_true', dest='unchanged', default=False, - help="""display which files were *not* added to the archive""") + subparser.add_argument('--filter', dest='output_filter', metavar='STATUSCHARS', + help='only display items with the given status characters') subparser.add_argument('-e', '--exclude', dest='excludes', type=ExcludePattern, action='append', metavar="PATTERN", help='exclude paths matching PATTERN') @@ -1186,8 +1181,6 @@ class Archiver: def run(self, args): os.umask(args.umask) # early, before opening files self.lock_wait = args.lock_wait - self.changed = getattr(args, 'changed', False) - self.unchanged = getattr(args, 'unchanged', False) RemoteRepository.remote_path = args.remote_path RemoteRepository.umask = args.umask setup_logging(level=args.log_level) # do not use loggers before this! diff --git a/borg/testsuite/archiver.py b/borg/testsuite/archiver.py index 8542c338a..9472cc7c9 100644 --- a/borg/testsuite/archiver.py +++ b/borg/testsuite/archiver.py @@ -713,11 +713,11 @@ class ArchiverTestCase(ArchiverTestCaseBase): os.utime('input/file1', (now - 5, now - 5)) # 5 seconds ago self.create_regular_file('file2', size=1024 * 80) self.cmd('init', self.repository_location) - output = self.cmd('create', '--changed', '--unchanged', self.repository_location + '::test', 'input') + output = self.cmd('create', '-v', self.repository_location + '::test', 'input') self.assert_in("A input/file1", output) self.assert_in("A input/file2", output) # should find first file as unmodified - output = self.cmd('create', '--changed', '--unchanged', self.repository_location + '::test1', 'input') + output = self.cmd('create', '-v', self.repository_location + '::test1', 'input') self.assert_in("U input/file1", output) # this is expected, although surprising, for why, see: # http://borgbackup.readthedocs.org/en/latest/faq.html#i-am-seeing-a-added-status-for-a-unchanged-file @@ -736,15 +736,15 @@ class ArchiverTestCase(ArchiverTestCaseBase): output = self.cmd('create', self.repository_location + '::test0', 'input') self.assert_not_in('file1', output) # should list the file as unchanged - output = self.cmd('create', '--unchanged', self.repository_location + '::test1', 'input') + output = self.cmd('create', '-v', '--filter=U', self.repository_location + '::test1', 'input') self.assert_in('file1', output) # should *not* list the file as changed - output = self.cmd('create', '--changed', self.repository_location + '::test2', 'input') + output = self.cmd('create', '-v', '--filter=AM', self.repository_location + '::test2', 'input') self.assert_not_in('file1', output) # change the file self.create_regular_file('file1', size=1024 * 100) # should list the file as changed - output = self.cmd('create', '--changed', self.repository_location + '::test3', 'input') + output = self.cmd('create', '-v', '--filter=AM', self.repository_location + '::test3', 'input') self.assert_in('file1', output) def test_cmdline_compatibility(self): diff --git a/docs/usage.rst b/docs/usage.rst index 67e6a039f..9367791c4 100644 --- a/docs/usage.rst +++ b/docs/usage.rst @@ -429,10 +429,14 @@ Here are misc. notes about topics that are maybe not covered in enough detail in Item flags ~~~~~~~~~~ -`borg create --changed` outputs a verbose list of all files, directories and other -file system items it considered, with the exception of unchanged files -(for this, also add `--unchanged`). For each item, it prefixes a single-letter -flag that indicates type and/or status of the item. +`borg create -v` outputs a verbose list of all files, directories and other +file system items it considered (no matter whether they had content changes +or not). For each item, it prefixes a single-letter flag that indicates type +and/or status of the item. + +If you are interested only in a subset of that output, you can give e.g. +`--filter=AME` and it will only show regular files with A, M or E status (see +below). A uppercase character represents the status of a regular file relative to the "files" cache (not relative to the repo - this is an issue if the files cache @@ -441,7 +445,7 @@ chunks are stored. For 'U' all data chunks refer to already existing chunks. - 'A' = regular file, added (see also :ref:`a_status_oddity` in the FAQ) - 'M' = regular file, modified -- 'U' = regular file, unchanged (only if `--unchanged` is specified) +- 'U' = regular file, unchanged - 'E' = regular file, an error happened while accessing/reading *this* file A lowercase character means a file type other than a regular file, From 68225af4497ae53afdde7a25cc68ea28dc812c51 Mon Sep 17 00:00:00 2001 From: Thomas Waldmann Date: Tue, 8 Dec 2015 00:21:46 +0100 Subject: [PATCH 09/11] archive checker: remove report_progress, fix log levels --- borg/archive.py | 34 ++++++++++++++++++---------------- borg/archiver.py | 1 + borg/testsuite/archiver.py | 2 +- 3 files changed, 20 insertions(+), 17 deletions(-) diff --git a/borg/archive.py b/borg/archive.py index d5b46792c..f4d98a3a7 100644 --- a/borg/archive.py +++ b/borg/archive.py @@ -3,7 +3,6 @@ from datetime import datetime from getpass import getuser from itertools import groupby import errno -import logging from .logger import create_logger logger = create_logger() @@ -663,20 +662,24 @@ class ArchiveChecker: self.possibly_superseded = set() def check(self, repository, repair=False, archive=None, last=None): - self.report_progress('Starting archive consistency check...') + logger.info('Starting archive consistency check...') self.check_all = archive is None and last is None self.repair = repair self.repository = repository self.init_chunks() self.key = self.identify_key(repository) if Manifest.MANIFEST_ID not in self.chunks: + logger.error("Repository manifest not found!") + self.error_found = True self.manifest = self.rebuild_manifest() else: self.manifest, _ = Manifest.load(repository, key=self.key) self.rebuild_refcounts(archive=archive, last=last) self.orphan_chunks_check() self.finish() - if not self.error_found: + if self.error_found: + logger.error('Archive consistency check complete, problems found.') + else: logger.info('Archive consistency check complete, no problems found.') return self.repair or not self.error_found @@ -696,11 +699,6 @@ class ArchiveChecker: for id_ in result: self.chunks[id_] = (0, 0, 0) - def report_progress(self, msg, error=False): - if error: - self.error_found = True - logger.log(logging.ERROR if error else logging.WARNING, msg) - def identify_key(self, repository): cdata = repository.get(next(self.chunks.iteritems())[0]) return key_factory(repository, cdata) @@ -710,7 +708,7 @@ class ArchiveChecker: Iterates through all objects in the repository looking for archive metadata blocks. """ - self.report_progress('Rebuilding missing manifest, this might take some time...', error=True) + logger.info('Rebuilding missing manifest, this might take some time...') manifest = Manifest(self.key, self.repository) for chunk_id, _ in self.chunks.iteritems(): cdata = self.repository.get(chunk_id) @@ -727,9 +725,9 @@ class ArchiveChecker: except (TypeError, ValueError, StopIteration): continue if isinstance(archive, dict) and b'items' in archive and b'cmdline' in archive: - self.report_progress('Found archive ' + archive[b'name'].decode('utf-8'), error=True) + logger.info('Found archive %s', archive[b'name'].decode('utf-8')) manifest.archives[archive[b'name'].decode('utf-8')] = {b'id': chunk_id, b'time': archive[b'time']} - self.report_progress('Manifest rebuild complete', error=True) + logger.info('Manifest rebuild complete.') return manifest def rebuild_refcounts(self, archive=None, last=None): @@ -771,7 +769,8 @@ class ArchiveChecker: for chunk_id, size, csize in item[b'chunks']: if chunk_id not in self.chunks: # If a file chunk is missing, create an all empty replacement chunk - self.report_progress('{}: Missing file chunk detected (Byte {}-{})'.format(item[b'path'].decode('utf-8', 'surrogateescape'), offset, offset + size), error=True) + logger.error('{}: Missing file chunk detected (Byte {}-{})'.format(item[b'path'].decode('utf-8', 'surrogateescape'), offset, offset + size)) + self.error_found = True data = bytes(size) chunk_id = self.key.id_hash(data) cdata = self.key.encrypt(data) @@ -800,7 +799,8 @@ class ArchiveChecker: def report(msg, chunk_id, chunk_no): cid = hexlify(chunk_id).decode('ascii') msg += ' [chunk: %06d_%s]' % (chunk_no, cid) # see debug-dump-archive-items - self.report_progress(msg, error=True) + self.error_found = True + logger.error(msg) i = 0 for state, items in groupby(archive[b'items'], missing_chunk_detector): @@ -841,7 +841,8 @@ class ArchiveChecker: logger.info('Analyzing archive {} ({}/{})'.format(name, num_archives - i, num_archives)) archive_id = info[b'id'] if archive_id not in self.chunks: - self.report_progress('Archive metadata block is missing', error=True) + logger.error('Archive metadata block is missing!') + self.error_found = True del self.manifest.archives[name] continue mark_as_possibly_superseded(archive_id) @@ -876,12 +877,13 @@ class ArchiveChecker: unused.add(id_) orphaned = unused - self.possibly_superseded if orphaned: - self.report_progress('{} orphaned objects found'.format(len(orphaned)), error=True) + logger.error('{} orphaned objects found!'.format(len(orphaned))) + self.error_found = True if self.repair: for id_ in unused: self.repository.delete(id_) else: - self.report_progress('Orphaned objects check skipped (needs all archives checked)') + logger.warning('Orphaned objects check skipped (needs all archives checked).') def finish(self): if self.repair: diff --git a/borg/archiver.py b/borg/archiver.py index 47c000aed..fe9813d2f 100644 --- a/borg/archiver.py +++ b/borg/archiver.py @@ -109,6 +109,7 @@ class Archiver: if repository.check(repair=args.repair): logger.info('Repository check complete, no problems found.') else: + logger.error('Repository check complete, problems found.') return EXIT_WARNING if not args.repo_only and not ArchiveChecker().check( repository, repair=args.repair, archive=args.repository.archive, last=args.last): diff --git a/borg/testsuite/archiver.py b/borg/testsuite/archiver.py index 9472cc7c9..8e24671b9 100644 --- a/borg/testsuite/archiver.py +++ b/borg/testsuite/archiver.py @@ -992,7 +992,7 @@ class ArchiverCheckTestCase(ArchiverTestCaseBase): repository.delete(Manifest.MANIFEST_ID) repository.commit() self.cmd('check', self.repository_location, exit_code=1) - output = self.cmd('check', '--repair', self.repository_location, exit_code=0) + output = self.cmd('check', '-v', '--repair', self.repository_location, exit_code=0) self.assert_in('archive1', output) self.assert_in('archive2', output) self.cmd('check', self.repository_location, exit_code=0) From cb821b119b43ac940ff6960c1c8140f30de8f6c8 Mon Sep 17 00:00:00 2001 From: Thomas Waldmann Date: Tue, 8 Dec 2015 01:37:34 +0100 Subject: [PATCH 10/11] remove --log-level, add --debug and --info option, update docs removed --log-level due to overlap with how --verbose works now. for consistency, added --info as alias to --verbose (as the effect is setting INFO log level). also added --debug which sets DEBUG log level. note: there are no messages emitted at DEBUG level yet. WARNING is the default (because we want mostly silent behaviour, except if something serious happens), so we don't need --warning as an option. --- borg/archiver.py | 10 +++++----- borg/testsuite/archiver.py | 6 +++--- docs/changes.rst | 4 +++- docs/usage.rst | 16 ++++++++++++---- 4 files changed, 23 insertions(+), 13 deletions(-) diff --git a/borg/archiver.py b/borg/archiver.py index fe9813d2f..39ecaaa24 100644 --- a/borg/archiver.py +++ b/borg/archiver.py @@ -664,12 +664,12 @@ class Archiver: def build_parser(self, args=None, prog=None): common_parser = argparse.ArgumentParser(add_help=False, prog=prog) - common_parser.add_argument('-v', '--verbose', dest='log_level', + common_parser.add_argument('-v', '--verbose', '--info', dest='log_level', action='store_const', const='info', default='warning', - help='verbose output, same as --log-level=info') - common_parser.add_argument('--log-level', dest='log_level', default='warning', metavar='LEVEL', - choices=('debug', 'info', 'warning', 'error', 'critical'), - help='set the log level to LEVEL, default: %(default)s)') + help='enable informative (verbose) output, work on log level INFO') + common_parser.add_argument('--debug', dest='log_level', + action='store_const', const='debug', default='warning', + help='enable debug output, work on log level DEBUG') common_parser.add_argument('--lock-wait', dest='lock_wait', type=int, metavar='N', default=1, help='wait for the lock, but max. N seconds (default: %(default)d).') common_parser.add_argument('--show-rc', dest='show_rc', action='store_true', default=False, diff --git a/borg/testsuite/archiver.py b/borg/testsuite/archiver.py index 8e24671b9..0698befc5 100644 --- a/borg/testsuite/archiver.py +++ b/borg/testsuite/archiver.py @@ -950,13 +950,13 @@ class ArchiverCheckTestCase(ArchiverTestCaseBase): return archive, repository def test_check_usage(self): - output = self.cmd('check', '--log-level=info', self.repository_location, exit_code=0) + output = self.cmd('check', '-v', self.repository_location, exit_code=0) self.assert_in('Starting repository check', output) self.assert_in('Starting archive consistency check', output) - output = self.cmd('check', '--log-level=info', '--repository-only', self.repository_location, exit_code=0) + output = self.cmd('check', '-v', '--repository-only', self.repository_location, exit_code=0) self.assert_in('Starting repository check', output) self.assert_not_in('Starting archive consistency check', output) - output = self.cmd('check', '--log-level=info', '--archives-only', self.repository_location, exit_code=0) + output = self.cmd('check', '-v', '--archives-only', self.repository_location, exit_code=0) self.assert_not_in('Starting repository check', output) self.assert_in('Starting archive consistency check', output) diff --git a/docs/changes.rst b/docs/changes.rst index d87dba7dd..712e89989 100644 --- a/docs/changes.rst +++ b/docs/changes.rst @@ -25,7 +25,9 @@ New features: - implement borg break-lock command, fixes #157 - include system info below traceback, fixes #324 - use ISO-8601 date and time format, fixes #375 -- add --log-level to set the level of the builtin logging configuration, fixes #426 +- add --debug and --info (same as --verbose) to set the log level of the + builtin logging configuration (which otherwise defaults to warning), + fixes #426 - configure logging via env var BORG_LOGGING_CONF - add a --no-progress flag to forcibly disable progress info diff --git a/docs/usage.rst b/docs/usage.rst index 9367791c4..1d31d6e5f 100644 --- a/docs/usage.rst +++ b/docs/usage.rst @@ -14,12 +14,20 @@ General Type of log output ~~~~~~~~~~~~~~~~~~ -You can set the log level of the builtin logging configuration using the ---log-level option. +The log level of the builtin logging configuration defaults to WARNING. +This is because we want |project_name| to be mostly silent and only output +warnings (plus errors and critical messages). -Supported levels: ``debug``, ``info``, ``warning``, ``error``, ``critical``. +Use --verbose or --info to set INFO (you will get informative output then +additionally to warnings, errors, critical messages). +Use --debug to set DEBUG to get output made for debugging. -All log messages created with at least the given level will be output. +All log messages created with at least the set level will be output. + +Log levels: DEBUG < INFO < WARNING < ERROR < CRITICAL + +While you can set misc. log levels, do not expect that every command will +give different output on different log levels - it's just a possibility. Return codes ~~~~~~~~~~~~ From 74ee8154f22e608c3972e638cba50dd05a626cae Mon Sep 17 00:00:00 2001 From: Thomas Waldmann Date: Tue, 8 Dec 2015 01:45:22 +0100 Subject: [PATCH 11/11] add developer docs about output and logging --- docs/development.rst | 12 ++++++++++++ 1 file changed, 12 insertions(+) diff --git a/docs/development.rst b/docs/development.rst index 753f3d554..0d75dfe4a 100644 --- a/docs/development.rst +++ b/docs/development.rst @@ -19,6 +19,18 @@ separate sections either. The `flake8 `_ commandline tool should be used to check for style errors before sending pull requests. +Output and Logging +------------------ +When writing logger calls, always use correct log level (debug only for +debugging, info for informative messages, warning for warnings, error for +errors, critical for critical errors/states). + +When directly talking to the user (e.g. Y/N questions), do not use logging, +but directly output to stderr (not: stdout, it could be connected to a pipe). + +To control the amount and kinds of messages output to stderr or emitted at +info level, use flags like --stats. + Building a development environment ----------------------------------