From 226e5519f33bfd5b14082808c6af72b24f0ee3a8 Mon Sep 17 00:00:00 2001 From: Ed Blackman Date: Tue, 17 May 2016 22:59:58 -0400 Subject: [PATCH] Print implied output without --info/-v There are persistent questions why output from options like --list and --stats doesn't show up. Also, borg currently isn't able to show *just* the output for a given option (--list, --stats, --show-rc, --show-version, or --progress), without other INFO level messages. The solution is to use more granular loggers, so that messages specific to a given option goes to a logger designated for that option. That option-specific logger can then be configured separately from the regular loggers. Those option-specific loggers can also be used as a hook in a BORG_LOGGING_CONF config file to log the --list output to a separate file, or send --stats output to a network socket where some daemon could analyze it. Steps: - create an option-specific logger for each of the implied output options - modify the messages specific to each option to go to the correct logger - if an implied output option is passed, change the option-specific logger (only) to log at INFO level - test that root logger messages don't come through option-specific loggers They shouldn't, per https://docs.python.org/3/howto/logging.html#logging-flow but test just the same. Particularly test a message that can come from remote repositories. Fixes #526, #573, #665, #824 --- borg/archiver.py | 47 ++++++++++++----- borg/helpers.py | 32 +++++++++--- borg/testsuite/archiver.py | 102 ++++++++++++++++++++++++++++++------- borg/testsuite/helpers.py | 26 ++++++++-- docs/changes.rst | 6 ++- docs/development.rst | 6 ++- docs/quickstart.rst | 11 ++-- docs/usage.rst | 17 +++---- 8 files changed, 187 insertions(+), 60 deletions(-) diff --git a/borg/archiver.py b/borg/archiver.py index bd45da2ba..59d7e3336 100644 --- a/borg/archiver.py +++ b/borg/archiver.py @@ -8,6 +8,7 @@ import functools import hashlib import inspect import io +import logging import os import re import shlex @@ -111,7 +112,7 @@ class Archiver: def print_file_status(self, status, path): if self.output_list and (self.output_filter is None or status in self.output_filter): - logger.info("%1s %s", status, remove_surrogates(path)) + logging.getLogger('borg.output.list').info("%1s %s", status, remove_surrogates(path)) @staticmethod def compare_chunk_contents(chunks1, chunks2): @@ -277,7 +278,7 @@ class Archiver: DASHES, str(archive.stats), str(cache), - DASHES) + DASHES, logger=logging.getLogger('borg.output.stats')) self.output_filter = args.output_filter self.output_list = args.output_list @@ -416,7 +417,7 @@ class Archiver: while dirs and not item[b'path'].startswith(dirs[-1][b'path']): archive.extract_item(dirs.pop(-1), stdout=stdout) if output_list: - logger.info(remove_surrogates(orig_path)) + logging.getLogger('borg.output.list').info(remove_surrogates(orig_path)) try: if dry_run: archive.extract_item(item, dry_run=True) @@ -673,7 +674,7 @@ class Archiver: log_multi(DASHES, stats.summary.format(label='Deleted data:', stats=stats), str(cache), - DASHES) + DASHES, logger=logging.getLogger('borg.output.stats')) else: if not args.cache_only: msg = [] @@ -820,18 +821,19 @@ class Archiver: to_delete = (set(archives) | checkpoints) - (set(keep) | set(keep_checkpoints)) stats = Statistics() with Cache(repository, key, manifest, do_files=args.cache_files, lock_wait=self.lock_wait) as cache: + list_logger = logging.getLogger('borg.output.list') for archive in archives_checkpoints: if archive in to_delete: if args.dry_run: if args.output_list: - logger.info('Would prune: %s' % format_archive(archive)) + list_logger.info('Would prune: %s' % format_archive(archive)) else: if args.output_list: - logger.info('Pruning archive: %s' % format_archive(archive)) + list_logger.info('Pruning archive: %s' % format_archive(archive)) Archive(repository, key, manifest, archive.name, cache).delete(stats) else: if args.output_list: - logger.info('Keeping archive: %s' % format_archive(archive)) + list_logger.info('Keeping archive: %s' % format_archive(archive)) if to_delete and not args.dry_run: manifest.write() repository.commit(save_space=args.save_space) @@ -840,7 +842,7 @@ class Archiver: log_multi(DASHES, stats.summary.format(label='Deleted data:', stats=stats), str(cache), - DASHES) + DASHES, logger=logging.getLogger('borg.output.stats')) return self.exit_code def do_upgrade(self, args): @@ -1299,6 +1301,9 @@ class Archiver: help='only check last N archives (Default: all)') subparser.add_argument('-P', '--prefix', dest='prefix', type=str, help='only consider archive names starting with this prefix') + subparser.add_argument('-p', '--progress', dest='progress', + action='store_true', default=False, + help="""show progress display while checking""") change_passphrase_epilog = textwrap.dedent(""" The key files used for repository encryption are optionally passphrase @@ -2065,12 +2070,27 @@ class Archiver: check_extension_modules() selftest(logger) + def _setup_implied_logging(self, args): + """ turn on INFO level logging for args that imply that they will produce output """ + # map of option name to name of logger for that option + option_logger = { + 'output_list': 'borg.output.list', + 'show_version': 'borg.output.show-version', + 'show_rc': 'borg.output.show-rc', + 'stats': 'borg.output.stats', + 'progress': 'borg.output.progress', + } + for option, logger_name in option_logger.items(): + if args.get(option, False): + logging.getLogger(logger_name).setLevel('INFO') + def run(self, args): os.umask(args.umask) # early, before opening files self.lock_wait = args.lock_wait setup_logging(level=args.log_level, is_serve=args.func == self.do_serve) # do not use loggers before this! + self._setup_implied_logging(vars(args)) if args.show_version: - logger.info('borgbackup version %s' % __version__) + logging.getLogger('borg.output.show-version').info('borgbackup version %s' % __version__) self.prerun_checks(logger) if is_slow_msgpack(): logger.warning("Using a pure-python msgpack! This will result in lower performance.") @@ -2142,15 +2162,16 @@ def main(): # pragma: no cover if msg: logger.error(msg) if args.show_rc: + rc_logger = logging.getLogger('borg.output.show-rc') exit_msg = 'terminating with %s status, rc %d' if exit_code == EXIT_SUCCESS: - logger.info(exit_msg % ('success', exit_code)) + rc_logger.info(exit_msg % ('success', exit_code)) elif exit_code == EXIT_WARNING: - logger.warning(exit_msg % ('warning', exit_code)) + rc_logger.warning(exit_msg % ('warning', exit_code)) elif exit_code == EXIT_ERROR: - logger.error(exit_msg % ('error', exit_code)) + rc_logger.error(exit_msg % ('error', exit_code)) else: - logger.error(exit_msg % ('abnormal', exit_code or 666)) + rc_logger.error(exit_msg % ('abnormal', exit_code or 666)) sys.exit(exit_code) diff --git a/borg/helpers.py b/borg/helpers.py index 7e783f3eb..d6fa4aba3 100644 --- a/borg/helpers.py +++ b/borg/helpers.py @@ -1037,7 +1037,7 @@ def yes(msg=None, false_msg=None, true_msg=None, default_msg=None, class ProgressIndicatorPercent: - def __init__(self, total, step=5, start=0, same_line=False, msg="%3.0f%%", file=None): + def __init__(self, total, step=5, start=0, same_line=False, msg="%3.0f%%"): """ Percentage-based progress indicator @@ -1046,17 +1046,33 @@ class ProgressIndicatorPercent: :param start: at which percent value to start :param same_line: if True, emit output always on same line :param msg: output message, must contain one %f placeholder for the percentage - :param file: output file, default: sys.stderr """ self.counter = 0 # 0 .. (total-1) self.total = total self.trigger_at = start # output next percentage value when reaching (at least) this self.step = step - if file is None: - file = sys.stderr - self.file = file self.msg = msg self.same_line = same_line + self.handler = None + self.logger = logging.getLogger('borg.output.progress') + + # If there are no handlers, set one up explicitly because the + # terminator and propagation needs to be set. If there are, + # they must have been set up by BORG_LOGGING_CONF: skip setup. + if not self.logger.handlers: + self.handler = logging.StreamHandler(stream=sys.stderr) + self.handler.setLevel(logging.INFO) + self.handler.terminator = '\r' if self.same_line else '\n' + + self.logger.addHandler(self.handler) + if self.logger.level == logging.NOTSET: + self.logger.setLevel(logging.WARN) + self.logger.propagate = False + + def __del__(self): + if self.handler is not None: + self.logger.removeHandler(self.handler) + self.handler.close() def progress(self, current=None): if current is not None: @@ -1073,11 +1089,11 @@ class ProgressIndicatorPercent: return self.output(pct) def output(self, percent): - print(self.msg % percent, file=self.file, end='\r' if self.same_line else '\n', flush=True) + self.logger.info(self.msg % percent) def finish(self): if self.same_line: - print(" " * len(self.msg % 100.0), file=self.file, end='\r') + self.logger.info(" " * len(self.msg % 100.0)) class ProgressIndicatorEndless: @@ -1127,7 +1143,7 @@ def sysinfo(): return '\n'.join(info) -def log_multi(*msgs, level=logging.INFO): +def log_multi(*msgs, level=logging.INFO, logger=logger): """ log multiple lines of text, each line by a separate logging call for cosmetic reasons diff --git a/borg/testsuite/archiver.py b/borg/testsuite/archiver.py index 75ee0c04f..5b8cf95af 100644 --- a/borg/testsuite/archiver.py +++ b/borg/testsuite/archiver.py @@ -3,6 +3,7 @@ import errno import os import inspect from io import StringIO +import logging import random import stat import subprocess @@ -297,9 +298,14 @@ class ArchiverTestCaseBase(BaseTestCase): class ArchiverTestCase(ArchiverTestCaseBase): def test_basic_functionality(self): have_root = self.create_test_files() - self.cmd('init', self.repository_location) + # fork required to test show-rc output + output = self.cmd('init', '--show-version', '--show-rc', self.repository_location, fork=True) + self.assert_in('borgbackup version', output) + self.assert_in('terminating with success status, rc 0', output) self.cmd('create', self.repository_location + '::test', 'input') - self.cmd('create', '--stats', self.repository_location + '::test.2', 'input') + output = self.cmd('create', '--stats', self.repository_location + '::test.2', 'input') + self.assert_in('Archive name: test.2', output) + self.assert_in('This archive: ', output) with changedir('output'): self.cmd('extract', self.repository_location + '::test') list_output = self.cmd('list', '--short', self.repository_location) @@ -645,6 +651,31 @@ class ArchiverTestCase(ArchiverTestCaseBase): self.cmd("extract", self.repository_location + "::test", "fm:input/file1", "fm:*file33*", "input/file2") self.assert_equal(sorted(os.listdir("output/input")), ["file1", "file2", "file333"]) + def test_extract_list_output(self): + self.cmd('init', self.repository_location) + self.create_regular_file('file', size=1024 * 80) + + self.cmd('create', self.repository_location + '::test', 'input') + + with changedir('output'): + output = self.cmd('extract', self.repository_location + '::test') + self.assert_not_in("input/file", output) + shutil.rmtree('output/input') + + with changedir('output'): + output = self.cmd('extract', '--info', self.repository_location + '::test') + self.assert_not_in("input/file", output) + shutil.rmtree('output/input') + + with changedir('output'): + output = self.cmd('extract', '--list', self.repository_location + '::test') + self.assert_in("input/file", output) + shutil.rmtree('output/input') + + with changedir('output'): + output = self.cmd('extract', '--list', '--info', self.repository_location + '::test') + self.assert_in("input/file", output) + def _create_test_caches(self): self.cmd('init', self.repository_location) self.create_regular_file('file1', size=1024 * 80) @@ -857,7 +888,8 @@ class ArchiverTestCase(ArchiverTestCaseBase): self.cmd('extract', '--dry-run', self.repository_location + '::test.2') self.cmd('delete', self.repository_location + '::test') self.cmd('extract', '--dry-run', self.repository_location + '::test.2') - self.cmd('delete', '--stats', self.repository_location + '::test.2') + output = self.cmd('delete', '--stats', self.repository_location + '::test.2') + self.assert_in('Deleted data:', output) # Make sure all data except the manifest has been deleted with Repository(self.repository_path) as repository: self.assert_equal(len(repository), 1) @@ -880,12 +912,16 @@ class ArchiverTestCase(ArchiverTestCaseBase): self.cmd('init', self.repository_location) self.create_src_archive('test') self.cmd('extract', '--dry-run', self.repository_location + '::test') - self.cmd('check', self.repository_location) + output = self.cmd('check', '--show-version', self.repository_location) + self.assert_in('borgbackup version', output) # implied output even without --info given + self.assert_not_in('Starting repository check', output) # --info not given for root logger + name = sorted(os.listdir(os.path.join(self.tmpdir, 'repository', 'data', '0')), reverse=True)[0] with open(os.path.join(self.tmpdir, 'repository', 'data', '0', name), 'r+b') as fd: fd.seek(100) fd.write(b'XXXX') - self.cmd('check', self.repository_location, exit_code=1) + output = self.cmd('check', '--info', self.repository_location, exit_code=1) + self.assert_in('Starting repository check', output) # --info given for root logger # we currently need to be able to create a lock directory inside the repo: @pytest.mark.xfail(reason="we need to be able to create the lock directory inside the repo") @@ -933,11 +969,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', '-v', '--list', self.repository_location + '::test', 'input') + output = self.cmd('create', '--list', 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', '-v', '--list', self.repository_location + '::test1', 'input') + output = self.cmd('create', '--list', self.repository_location + '::test1', 'input') self.assert_in("U input/file1", output) # this is expected, although surprising, for why, see: # https://borgbackup.readthedocs.org/en/latest/faq.html#i-am-seeing-a-added-status-for-a-unchanged-file @@ -951,11 +987,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', '-v', '--list', self.repository_location + '::test', 'input') + output = self.cmd('create', '--list', self.repository_location + '::test', 'input') self.assert_in("A input/file1", output) self.assert_in("A input/file2", output) # should find second file as excluded - output = self.cmd('create', '-v', '--list', self.repository_location + '::test1', 'input', '--exclude', '*/file2') + output = self.cmd('create', '--list', self.repository_location + '::test1', 'input', '--exclude', '*/file2') self.assert_in("U input/file1", output) self.assert_in("x input/file2", output) @@ -972,15 +1008,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', '-v', '--list', '--filter=U', self.repository_location + '::test1', 'input') + output = self.cmd('create', '--list', '--filter=U', self.repository_location + '::test1', 'input') self.assert_in('file1', output) # should *not* list the file as changed - output = self.cmd('create', '-v', '--filter=AM', self.repository_location + '::test2', 'input') + output = self.cmd('create', '--list', '--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', '-v', '--list', '--filter=AM', self.repository_location + '::test3', 'input') + output = self.cmd('create', '--list', '--filter=AM', self.repository_location + '::test3', 'input') self.assert_in('file1', output) # def test_cmdline_compatibility(self): @@ -998,7 +1034,8 @@ class ArchiverTestCase(ArchiverTestCaseBase): self.cmd('create', self.repository_location + '::test3.checkpoint', src_dir) self.cmd('create', self.repository_location + '::test3.checkpoint.1', src_dir) self.cmd('create', self.repository_location + '::test4.checkpoint', src_dir) - output = self.cmd('prune', '-v', '--list', '--dry-run', self.repository_location, '--keep-daily=2') + output = self.cmd('prune', '--list', '--dry-run', self.repository_location, '--keep-daily=2') + self.assert_in('Keeping archive: test2', output) self.assert_in('Would prune: test1', output) # must keep the latest non-checkpoint archive: self.assert_in('Keeping archive: test2', output) @@ -1032,9 +1069,10 @@ class ArchiverTestCase(ArchiverTestCaseBase): self.cmd('init', self.repository_location) self.cmd('create', self.repository_location + '::test1', src_dir) self.cmd('create', self.repository_location + '::test2', src_dir) - output = self.cmd('prune', '-v', '--list', '--dry-run', self.repository_location, '--keep-daily=2') + output = self.cmd('prune', '--list', '--stats', '--dry-run', self.repository_location, '--keep-daily=2') self.assert_in('Keeping archive: test2', output) self.assert_in('Would prune: test1', output) + self.assert_in('Deleted data:', output) output = self.cmd('list', self.repository_location) self.assert_in('test1', output) self.assert_in('test2', output) @@ -1049,7 +1087,7 @@ class ArchiverTestCase(ArchiverTestCaseBase): self.cmd('create', self.repository_location + '::foo-2015-08-12-20:00', src_dir) self.cmd('create', self.repository_location + '::bar-2015-08-12-10:00', src_dir) self.cmd('create', self.repository_location + '::bar-2015-08-12-20:00', src_dir) - output = self.cmd('prune', '-v', '--list', '--dry-run', self.repository_location, '--keep-daily=2', '--prefix=foo-') + output = self.cmd('prune', '--list', '--dry-run', self.repository_location, '--keep-daily=2', '--prefix=foo-') self.assert_in('Keeping archive: foo-2015-08-12-20:00', output) self.assert_in('Would prune: foo-2015-08-12-10:00', output) output = self.cmd('list', self.repository_location) @@ -1401,7 +1439,7 @@ class ArchiverTestCase(ArchiverTestCaseBase): if interrupt_early: process_files = 0 with patch.object(ArchiveRecreater, 'process_item', self._recreate_interrupt_patch(process_files)): - self.cmd('recreate', '-sv', '--list', self.repository_location, 'input/dir2') + self.cmd('recreate', self.repository_location, 'input/dir2') assert 'test.recreate' in self.cmd('list', self.repository_location) if change_args: with patch.object(sys, 'argv', sys.argv + ['non-forking tests don\'t use sys.argv']): @@ -1492,6 +1530,32 @@ class ArchiverTestCase(ArchiverTestCaseBase): cmd = 'python3', '-c', 'import os, sys; sys.exit(42 if os.path.exists("%s") else 23)' % lock_path self.cmd('with-lock', self.repository_location, *cmd, fork=True, exit_code=42) + def test_recreate_list_output(self): + self.cmd('init', self.repository_location) + self.create_regular_file('file1', size=0) + self.create_regular_file('file2', size=0) + self.create_regular_file('file3', size=0) + self.create_regular_file('file4', size=0) + self.create_regular_file('file5', size=0) + + self.cmd('create', self.repository_location + '::test', 'input') + + output = self.cmd('recreate', '--list', '--info', self.repository_location + '::test', '-e', 'input/file2') + self.assert_in("input/file1", output) + self.assert_in("x input/file2", output) + + output = self.cmd('recreate', '--list', self.repository_location + '::test', '-e', 'input/file3') + self.assert_in("input/file1", output) + self.assert_in("x input/file3", output) + + output = self.cmd('recreate', self.repository_location + '::test', '-e', 'input/file4') + self.assert_not_in("input/file1", output) + self.assert_not_in("x input/file4", output) + + output = self.cmd('recreate', '--info', self.repository_location + '::test', '-e', 'input/file5') + self.assert_not_in("input/file1", output) + self.assert_not_in("x input/file5", output) + @unittest.skipUnless('binary' in BORG_EXES, 'no borg.exe available') class ArchiverTestCaseBinary(ArchiverTestCase): @@ -1532,12 +1596,16 @@ class ArchiverCheckTestCase(ArchiverTestCaseBase): return archive, repository def test_check_usage(self): - output = self.cmd('check', '-v', self.repository_location, exit_code=0) + output = self.cmd('check', '-v', '--progress', self.repository_location, exit_code=0) self.assert_in('Starting repository check', output) self.assert_in('Starting archive consistency check', output) + self.assert_in('Checking segments', output) + # reset logging to new process default to avoid need for fork=True on next check + logging.getLogger('borg.output.progress').setLevel(logging.NOTSET) 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) + self.assert_not_in('Checking segments', output) 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/borg/testsuite/helpers.py b/borg/testsuite/helpers.py index c86a0b3b2..beb67fc23 100644 --- a/borg/testsuite/helpers.py +++ b/borg/testsuite/helpers.py @@ -1,4 +1,6 @@ import hashlib +import io +import logging from time import mktime, strptime from datetime import datetime, timezone, timedelta from io import StringIO @@ -826,7 +828,7 @@ def test_yes_output(capfd): def test_progress_percentage_multiline(capfd): - pi = ProgressIndicatorPercent(1000, step=5, start=0, same_line=False, msg="%3.0f%%", file=sys.stderr) + pi = ProgressIndicatorPercent(1000, step=5, start=0, same_line=False, msg="%3.0f%%") pi.show(0) out, err = capfd.readouterr() assert err == ' 0%\n' @@ -842,13 +844,14 @@ def test_progress_percentage_multiline(capfd): def test_progress_percentage_sameline(capfd): - pi = ProgressIndicatorPercent(1000, step=5, start=0, same_line=True, msg="%3.0f%%", file=sys.stderr) + pi = ProgressIndicatorPercent(1000, step=5, start=0, same_line=True, msg="%3.0f%%") pi.show(0) out, err = capfd.readouterr() assert err == ' 0%\r' pi.show(420) + pi.show(680) out, err = capfd.readouterr() - assert err == ' 42%\r' + assert err == ' 42%\r 68%\r' pi.show(1000) out, err = capfd.readouterr() assert err == '100%\r' @@ -858,7 +861,7 @@ def test_progress_percentage_sameline(capfd): def test_progress_percentage_step(capfd): - pi = ProgressIndicatorPercent(100, step=2, start=0, same_line=False, msg="%3.0f%%", file=sys.stderr) + pi = ProgressIndicatorPercent(100, step=2, start=0, same_line=False, msg="%3.0f%%") pi.show() out, err = capfd.readouterr() assert err == ' 0%\n' @@ -870,6 +873,21 @@ def test_progress_percentage_step(capfd): assert err == ' 2%\n' +def test_progress_percentage_quiet(capfd): + logging.getLogger('borg.output.progress').setLevel(logging.WARN) + + pi = ProgressIndicatorPercent(1000, step=5, start=0, same_line=False, msg="%3.0f%%") + pi.show(0) + out, err = capfd.readouterr() + assert err == '' + pi.show(1000) + out, err = capfd.readouterr() + assert err == '' + pi.finish() + out, err = capfd.readouterr() + assert err == '' + + def test_progress_endless(capfd): pi = ProgressIndicatorEndless(step=1, file=sys.stderr) pi.show() diff --git a/docs/changes.rst b/docs/changes.rst index 1e6d1a6f1..90c9f1eb8 100644 --- a/docs/changes.rst +++ b/docs/changes.rst @@ -6,6 +6,10 @@ Version 1.1.0 (not released yet) New features: +- borg check: will not produce the "Checking segments" output unless + new --progress option is passed, #824. +- options that imply output (--show-rc, --show-version, --list, --stats, + --progress) don't need -v/--info to have that output displayed, #865 - borg recreate: re-create existing archives, #787 #686 #630 #70, also see #757, #770. @@ -34,7 +38,7 @@ New features: - borg comment: add archive comments, #842 - provide "borgfs" wrapper for borg mount, enables usage via fstab, #743 - create: add 'x' status for excluded paths, #814 -- --show-version: shows/logs the borg version (use -v), #725 +- --show-version: shows/logs the borg version, #725 - borg list/prune/delete: also output archive id, #731 Bug fixes: diff --git a/docs/development.rst b/docs/development.rst index 7d6323dce..b94554462 100644 --- a/docs/development.rst +++ b/docs/development.rst @@ -27,8 +27,10 @@ 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`` or ``--list``. +To control the amount and kinds of messages output emitted at info level, use +flags like ``--stats`` or ``--list``, then create a topic logger for messages +controlled by that flag. See ``_setup_implied_logging()`` in +``borg/archiver.py`` for the entry point to topic logging. Building a development environment ---------------------------------- diff --git a/docs/quickstart.rst b/docs/quickstart.rst index c8456b85d..f61656a3b 100644 --- a/docs/quickstart.rst +++ b/docs/quickstart.rst @@ -46,7 +46,7 @@ A step by step example 3. The next day create a new archive called *Tuesday*:: - $ borg create -v --stats /path/to/repo::Tuesday ~/src ~/Documents + $ borg create --stats /path/to/repo::Tuesday ~/src ~/Documents This backup will be a lot quicker and a lot smaller since only new never before seen data is stored. The ``--stats`` option causes |project_name| to @@ -93,9 +93,10 @@ A step by step example .. Note:: Borg is quiet by default (it works on WARNING log level). - Add the ``-v`` (or ``--verbose`` or ``--info``) option to adjust the log - level to INFO and also use options like ``--progress`` or ``--list`` to - get progress reporting during command execution. + You can use options like ``--progress`` or ``--list`` to get specific + reports during command execution. You can also add the ``-v`` (or + ``--verbose`` or ``--info``) option to adjust the log level to INFO to + get other informational messages. Automating backups ------------------ @@ -114,7 +115,7 @@ certain number of old archives:: export BORG_PASSPHRASE=mysecret # Backup most important stuff: - borg create -v --stats -C lz4 ::`hostname`-`date +%Y-%m-%d` \ + borg create --stats -C lz4 ::`hostname`-`date +%Y-%m-%d` \ /etc \ /home \ /var \ diff --git a/docs/usage.rst b/docs/usage.rst index d559c0bb0..b19234c6d 100644 --- a/docs/usage.rst +++ b/docs/usage.rst @@ -16,7 +16,8 @@ Type of log output 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, errors and critical messages. +warnings, errors and critical messages, unless output has been requested +by supplying an option that implies output (eg, --list or --progress). Log levels: DEBUG < INFO < WARNING < ERROR < CRITICAL @@ -41,10 +42,6 @@ give different output on different log levels - it's just a possibility. .. warning:: Options --critical and --error are provided for completeness, their usage is not recommended as you might miss important information. -.. warning:: While some options (like ``--stats`` or ``--list``) will emit more - informational messages, you have to use INFO (or lower) log level to make - them show up in log output. Use ``-v`` or a logging configuration. - Return codes ~~~~~~~~~~~~ @@ -245,8 +242,8 @@ Examples # Backup ~/Documents into an archive named "my-documents" $ borg create /path/to/repo::my-documents ~/Documents - # same, but verbosely list all files as we process them - $ borg create -v --list /path/to/repo::my-documents ~/Documents + # same, but list all files as we process them + $ borg create --list /path/to/repo::my-documents ~/Documents # Backup ~/Documents and ~/src but exclude pyc files $ borg create /path/to/repo::my-files \ @@ -301,7 +298,7 @@ Examples $ borg extract /path/to/repo::my-files # Extract entire archive and list files while processing - $ borg extract -v --list /path/to/repo::my-files + $ borg extract --list /path/to/repo::my-files # Verify whether an archive could be successfully extracted, but do not write files to disk $ borg extract --dry-run /path/to/repo::my-files @@ -480,7 +477,7 @@ Examples Username: root Time (start): Mon, 2016-02-15 19:36:29 Time (end): Mon, 2016-02-15 19:39:26 - Command line: /usr/local/bin/borg create -v --list -C zlib,6 /path/to/repo::root-2016-02-15 / --one-file-system + Command line: /usr/local/bin/borg create --list -C zlib,6 /path/to/repo::root-2016-02-15 / --one-file-system Number of files: 38100 Original size Compressed size Deduplicated size @@ -655,7 +652,7 @@ Here are misc. notes about topics that are maybe not covered in enough detail in Item flags ~~~~~~~~~~ -``borg create -v --list`` outputs a verbose list of all files, directories and other +``borg create --list`` outputs a 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.