Merge branch 'master' into move-to-src

.gitignore

@@ -11,6 +11,7 @@ crypto.c
 platform_darwin.c
 platform_freebsd.c
 platform_linux.c
+platform_posix.c
 *.egg-info
 *.pyc
 *.pyo

Vagrantfile

@@ -202,8 +202,8 @@ def install_borg(boxname)
     rm -f borg/{chunker,crypto,compress,hashindex,platform_linux}.c
     rm -rf borg/__pycache__ borg/support/__pycache__ borg/testsuite/__pycache__
     pip install -r requirements.d/development.txt
-    pip install -r requirements.d/fuse.txt
-    pip install -e .
+    # by using [fuse], setup.py can handle different fuse requirements:
+    pip install -e .[fuse]
   EOF
 end
 

conftest.py

@@ -0,0 +1,39 @@
+import sys
+
+# This is a hack to fix path problems because "borg" (the package) is in the source root.
+# When importing the conftest an "import borg" can incorrectly import the borg from the
+# source root instead of the one installed in the environment.
+# The workaround is to remove entries pointing there from the path and check whether "borg"
+# is still importable. If it is not, then it has not been installed in the environment
+# and the entries are put back.
+#
+# TODO: After moving the package to src/: remove this.
+
+original_path = list(sys.path)
+for entry in original_path:
+    if entry == '' or entry.endswith('/borg'):
+        sys.path.remove(entry)
+
+try:
+    import borg
+except ImportError:
+    sys.path = original_path
+
+from borg.logger import setup_logging
+
+# Ensure that the loggers exist for all tests
+setup_logging()
+
+from borg.testsuite import has_lchflags, no_lchlfags_because, has_llfuse
+from borg.testsuite.platform import fakeroot_detected
+from borg import xattr
+
+
+def pytest_report_header(config, startdir):
+    yesno = ['no', 'yes']
+    flags = 'Testing BSD-style flags: %s %s' % (yesno[has_lchflags], no_lchlfags_because)
+    fakeroot = 'fakeroot: %s (>=1.20.2: %s)' % (
+        yesno[fakeroot_detected()],
+        yesno[xattr.XATTR_FAKEROOT])
+    llfuse = 'Testing fuse: %s' % yesno[has_llfuse]
+    return '\n'.join((flags, llfuse, fakeroot))

docs/api.rst

@@ -2,55 +2,55 @@
 API Documentation
 =================
 
-.. automodule:: borg.platform
+.. automodule:: borg.archiver
     :members:
     :undoc-members:
 
-.. automodule:: borg.shellpattern
+.. automodule:: borg.upgrader
     :members:
     :undoc-members:
 
-.. automodule:: borg.locking
+.. automodule:: borg.archive
     :members:
     :undoc-members:
 
-.. automodule:: borg.hash_sizes
+.. automodule:: borg.fuse
     :members:
     :undoc-members:
 
-.. automodule:: borg.logger
+.. automodule:: borg.platform
     :members:
     :undoc-members:
 
-.. automodule:: borg.remote
+.. automodule:: borg.locking
     :members:
     :undoc-members:
 
-.. automodule:: borg.fuse
+.. automodule:: borg.shellpattern
     :members:
     :undoc-members:
 
-.. automodule:: borg.archive
+.. automodule:: borg.repository
     :members:
     :undoc-members:
 
-.. automodule:: borg.helpers
+.. automodule:: borg.lrucache
     :members:
     :undoc-members:
 
-.. automodule:: borg.lrucache
+.. automodule:: borg.remote
     :members:
     :undoc-members:
 
-.. automodule:: borg.xattr
+.. automodule:: borg.hash_sizes
     :members:
     :undoc-members:
 
-.. automodule:: borg.archiver
+.. automodule:: borg.xattr
     :members:
     :undoc-members:
 
-.. automodule:: borg.repository
+.. automodule:: borg.helpers
     :members:
     :undoc-members:
 
@@ -62,7 +62,7 @@ API Documentation
     :members:
     :undoc-members:
 
-.. automodule:: borg.upgrader
+.. automodule:: borg.logger
     :members:
     :undoc-members:
 
@@ -70,15 +70,15 @@ API Documentation
     :members:
     :undoc-members:
 
-.. automodule:: borg.compress
+.. automodule:: borg.platform_linux
     :members:
     :undoc-members:
 
-.. automodule:: borg.platform_linux
+.. automodule:: borg.hashindex
     :members:
     :undoc-members:
 
-.. automodule:: borg.crypto
+.. automodule:: borg.compress
     :members:
     :undoc-members:
 
@@ -86,10 +86,10 @@ API Documentation
     :members:
     :undoc-members:
 
-.. automodule:: borg.platform_freebsd
+.. automodule:: borg.crypto
     :members:
     :undoc-members:
 
-.. automodule:: borg.hashindex
+.. automodule:: borg.platform_freebsd
     :members:
     :undoc-members:

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:
@@ -70,22 +74,34 @@ Other changes:
   - ChunkBuffer: add test for leaving partial chunk in buffer, fixes #945
 
 
-Version 1.0.3 (not released yet)
---------------------------------
+Version 1.0.3
+-------------
 
 Bug fixes:
 
-- prune: ignore checkpoints, #997
-- prune: fix bad validator, #942
-- fix capabilities extraction on Linux (set xattrs last, after chown())
+- prune: avoid that checkpoints are kept and completed archives are deleted in
+  a prune run), #997
+- prune: fix commandline argument validation - some valid command lines were
+  considered invalid (annoying, but harmless), #942
+- fix capabilities extraction on Linux (set xattrs last, after chown()), #1069
+- repository: fix commit tags being seen in data
+- when probing key files, do binary reads. avoids crash when non-borg binary
+  files are located in borg's key files directory.
+- handle SIGTERM and make a clean exit - avoids orphan lock files.
+- repository cache: don't cache large objects (avoid using lots of temp. disk
+  space), #1063
 
 Other changes:
 
-- update readthedocs URLs, #991
-- add missing docs for "borg break-lock", #992
-- borg create help: add some words to about the archive name
-- borg create help: document format tags, #894
 - Vagrantfile: OS X: update osxfuse / install lzma package, #933
+- setup.py: add check for platform_darwin.c
+- setup.py: on freebsd, use a llfuse release that builds ok
+- docs / help:
+
+  - update readthedocs URLs, #991
+  - add missing docs for "borg break-lock", #992
+  - borg create help: add some words to about the archive name
+  - borg create help: document format tags, #894
 
 
 Version 1.0.2

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
 ----------------------------------

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
 ------------------
@@ -105,23 +106,27 @@ server. The script also uses the :ref:`borg_prune` subcommand to maintain a
 certain number of old archives::
 
     #!/bin/sh
-    REPOSITORY=username@remoteserver.com:backup
-
-    # Backup all of /home and /var/www except a few
-    # excluded directories
-    borg create -v --stats                          \
-        $REPOSITORY::`hostname`-`date +%Y-%m-%d`    \
-        /home                                       \
-        /var/www                                    \
-        --exclude '/home/*/.cache'                  \
-        --exclude /home/Ben/Music/Justin\ Bieber    \
+
+    # setting this, so the repo does not need to be given on the commandline:
+    export BORG_REPO=username@remoteserver.com:backup
+
+    # setting this, so you won't be asked for your passphrase - make sure the
+    # script has appropriate owner/group and mode, e.g. root.root 600:
+    export BORG_PASSPHRASE=mysecret
+
+    # Backup most important stuff:
+    borg create --stats -C lz4 ::`hostname`-`date +%Y-%m-%d` \
+        /etc                                                    \
+        /home                                                   \
+        /var                                                    \
+        --exclude '/home/*/.cache'                              \
         --exclude '*.pyc'
 
     # Use the `prune` subcommand to maintain 7 daily, 4 weekly and 6 monthly
-    # archives of THIS machine. --prefix `hostname`- is very important to
+    # archives of THIS machine. Using --prefix is very important to
     # limit prune's operation to this machine's archives and not apply to
     # other machine's archives also.
-    borg prune -v $REPOSITORY --prefix `hostname`- \
+    borg prune -v --prefix `hostname`- \
         --keep-daily=7 --keep-weekly=4 --keep-monthly=6
 
 .. backup_compression:

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
 ~~~~~~~~~~~~
 
@@ -170,6 +167,22 @@ Network:
 
 In case you are interested in more details, please read the internals documentation.
 
+File systems
+~~~~~~~~~~~~
+
+We strongly recommend against using Borg (or any other database-like
+software) on non-journaling file systems like FAT, since it is not
+possible to assume any consistency in case of power failures (or a
+sudden disconnect of an external drive or similar failures).
+
+While Borg uses a data store that is resilient against these failures
+when used on journaling file systems, it is not possible to guarantee
+this with some hardware -- independent of the software used. We don't
+know a list of affected hardware.
+
+If you are suspicious whether your Borg repository is still consistent
+and readable after one of the failures mentioned above occured, run
+``borg check --verify-data`` to make sure it is consistent.
 
 Units
 ~~~~~
@@ -220,46 +233,6 @@ Examples
     # Remote repository (store the key your home dir)
     $ borg init --encryption=keyfile user@hostname:backup
 
-Important notes about encryption:
-
-It is not recommended to disable encryption. Repository encryption protects you
-e.g. against the case that an attacker has access to your backup repository.
-
-But be careful with the key / the passphrase:
-
-If you want "passphrase-only" security, use the ``repokey`` mode. The key will
-be stored inside the repository (in its "config" file). In above mentioned
-attack scenario, the attacker will have the key (but not the passphrase).
-
-If you want "passphrase and having-the-key" security, use the ``keyfile`` mode.
-The key will be stored in your home directory (in ``.config/borg/keys``). In
-the attack scenario, the attacker who has just access to your repo won't have
-the key (and also not the passphrase).
-
-Make a backup copy of the key file (``keyfile`` mode) or repo config file
-(``repokey`` mode) and keep it at a safe place, so you still have the key in
-case it gets corrupted or lost. Also keep the passphrase at a safe place.
-The backup that is encrypted with that key won't help you with that, of course.
-
-Make sure you use a good passphrase. Not too short, not too simple. The real
-encryption / decryption key is encrypted with / locked by your passphrase.
-If an attacker gets your key, he can't unlock and use it without knowing the
-passphrase.
-
-Be careful with special or non-ascii characters in your passphrase:
-
-- |project_name| processes the passphrase as unicode (and encodes it as utf-8),
-  so it does not have problems dealing with even the strangest characters.
-- BUT: that does not necessarily apply to your OS / VM / keyboard configuration.
-
-So better use a long passphrase made from simple ascii chars than one that
-includes non-ascii stuff or characters that are hard/impossible to enter on
-a different keyboard layout.
-
-You can change your passphrase for existing repos at any time, it won't affect
-the encryption/decryption key or other secrets.
-
-
 .. include:: usage/create.rst.inc
 
 Examples
@@ -269,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 \
@@ -325,7 +298,10 @@ 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
 
     # Extract the "src" directory
     $ borg extract /path/to/repo::my-files home/USERNAME/src
@@ -501,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
@@ -676,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.

docs/usage/create.rst.inc

@@ -74,6 +74,12 @@ This command creates a backup archive containing all files found while recursive
 traversing all paths specified. The archive will consume almost no disk space for
 files or parts of files that have already been stored in other archives.
 
+The archive name needs to be unique. It must not end in '.checkpoint' or
+'.checkpoint.N' (with N being a number), because these names are used for
+checkpoints and treated in special ways.
+
+In the archive name, you may use the following format tags:
+{now}, {utcnow}, {fqdn}, {hostname}, {user}, {pid}
 
 To speed up pulling backups over sshfs and similar network file systems which do
 not provide correct inode information the --ignore-inode flag can be used. This

setup.py

@@ -26,20 +26,26 @@ install_requires = ['msgpack-python>=0.4.6', ]
 extras_require = {
     # llfuse 0.40 (tested, proven, ok), needs FUSE version >= 2.8.0
     # llfuse 0.41 (tested shortly, looks ok), needs FUSE version >= 2.8.0
+    # llfuse 0.41.1 (tested shortly, looks ok), needs FUSE version >= 2.8.0
     # llfuse 0.42 (tested shortly, looks ok), needs FUSE version >= 2.8.0
     # llfuse 1.0 (tested shortly, looks ok), needs FUSE version >= 2.8.0
     # llfuse 2.0 will break API
     'fuse': ['llfuse<2.0', ],
 }
 
+if sys.platform.startswith('freebsd'):
+    # while llfuse 1.0 is the latest llfuse release right now,
+    # llfuse 0.41.1 is the latest release that actually builds on freebsd:
+    extras_require['fuse'] = ['llfuse==0.41.1', ]
+
 from setuptools import setup, find_packages, Extension
 from setuptools.command.sdist import sdist
 
-
 compress_source = 'src/borg/compress.pyx'
 crypto_source = 'src/borg/crypto.pyx'
 chunker_source = 'src/borg/chunker.pyx'
 hashindex_source = 'src/borg/hashindex.pyx'
+platform_posix_source = 'src/borg/platform_posix.pyx'
 platform_linux_source = 'src/borg/platform_linux.pyx'
 platform_darwin_source = 'src/borg/platform_darwin.pyx'
 platform_freebsd_source = 'src/borg/platform_freebsd.pyx'
@@ -60,6 +66,7 @@ try:
                 'src/borg/crypto.c',
                 'src/borg/chunker.c', 'src/borg/_chunker.c',
                 'src/borg/hashindex.c', 'src/borg/_hashindex.c',
+                'src/borg/platform_posix.c',
                 'src/borg/platform_linux.c',
                 'src/borg/platform_freebsd.c',
                 'src/borg/platform_darwin.c',
@@ -75,13 +82,14 @@ except ImportError:
     crypto_source = crypto_source.replace('.pyx', '.c')
     chunker_source = chunker_source.replace('.pyx', '.c')
     hashindex_source = hashindex_source.replace('.pyx', '.c')
+    platform_posix_source = platform_posix_source.replace('.pyx', '.c')
     platform_linux_source = platform_linux_source.replace('.pyx', '.c')
     platform_freebsd_source = platform_freebsd_source.replace('.pyx', '.c')
     platform_darwin_source = platform_darwin_source.replace('.pyx', '.c')
     from distutils.command.build_ext import build_ext
     if not on_rtd and not all(os.path.exists(path) for path in [
         compress_source, crypto_source, chunker_source, hashindex_source,
-        platform_linux_source, platform_freebsd_source]):
+        platform_posix_source, platform_linux_source, platform_freebsd_source, platform_darwin_source]):
         raise ImportError('The GIT version of Borg needs Cython. Install Cython or use a released version.')
 
 
@@ -106,7 +114,8 @@ def detect_lz4(prefixes):
 include_dirs = []
 library_dirs = []
 
-possible_openssl_prefixes = ['/usr', '/usr/local', '/usr/local/opt/openssl', '/usr/local/ssl', '/usr/local/openssl', '/usr/local/borg', '/opt/local']
+possible_openssl_prefixes = ['/usr', '/usr/local', '/usr/local/opt/openssl', '/usr/local/ssl', '/usr/local/openssl',
+                             '/usr/local/borg', '/opt/local', '/opt/pkg', ]
 if os.environ.get('BORG_OPENSSL_PREFIX'):
     possible_openssl_prefixes.insert(0, os.environ.get('BORG_OPENSSL_PREFIX'))
 ssl_prefix = detect_openssl(possible_openssl_prefixes)
@@ -116,7 +125,8 @@ include_dirs.append(os.path.join(ssl_prefix, 'include'))
 library_dirs.append(os.path.join(ssl_prefix, 'lib'))
 
 
-possible_lz4_prefixes = ['/usr', '/usr/local', '/usr/local/opt/lz4', '/usr/local/lz4', '/usr/local/borg', '/opt/local']
+possible_lz4_prefixes = ['/usr', '/usr/local', '/usr/local/opt/lz4', '/usr/local/lz4',
+                         '/usr/local/borg', '/opt/local', '/opt/pkg', ]
 if os.environ.get('BORG_LZ4_PREFIX'):
     possible_lz4_prefixes.insert(0, os.environ.get('BORG_LZ4_PREFIX'))
 lz4_prefix = detect_lz4(possible_lz4_prefixes)
@@ -284,6 +294,9 @@ if not on_rtd:
     Extension('borg.chunker', [chunker_source]),
     Extension('borg.hashindex', [hashindex_source])
 ]
+    if sys.platform.startswith(('linux', 'freebsd', 'darwin')):
+        ext_modules.append(Extension('borg.platform_posix', [platform_posix_source]))
+
     if sys.platform == 'linux':
         ext_modules.append(Extension('borg.platform_linux', [platform_linux_source], libraries=['acl']))
     elif sys.platform.startswith('freebsd'):

src/borg/_chunker.c

@@ -184,9 +184,9 @@ chunker_fill(Chunker *c)
         length = c->bytes_read - offset;
         #if ( ( _XOPEN_SOURCE >= 600 || _POSIX_C_SOURCE >= 200112L ) && defined(POSIX_FADV_DONTNEED) )
 
-	// Only do it once per run.
-	if (pagemask == 0)
-		pagemask = getpagesize() - 1;
+        // Only do it once per run.
+        if (pagemask == 0)
+            pagemask = getpagesize() - 1;
 
         // We tell the OS that we do not need the data that we just have read any
         // more (that it maybe has in the cache). This avoids that we spoil the
@@ -207,7 +207,7 @@ chunker_fill(Chunker *c)
             // fadvise. This will cancel the final page and is not part
             // of the above workaround.
             overshoot = 0;
-	}
+        }
 
         posix_fadvise(c->fh, offset & ~pagemask, length - overshoot, POSIX_FADV_DONTNEED);
         #endif

src/borg/archive.py

@@ -9,6 +9,7 @@ from .key import key_factory
 from .remote import cache_if_remote
 
 import os
+from shutil import get_terminal_size
 import socket
 import stat
 import sys
@@ -19,24 +20,76 @@ from .compress import COMPR_BUFFER
 from .constants import *  # NOQA
 from .helpers import Chunk, Error, uid2user, user2uid, gid2group, group2gid, \
     parse_timestamp, to_localtime, format_time, format_timedelta, safe_encode, safe_decode, \
-    Manifest, Statistics, decode_dict, make_path_safe, StableDict, int_to_bigint, bigint_to_int, bin_to_hex, \
+    Manifest, decode_dict, make_path_safe, StableDict, int_to_bigint, bigint_to_int, bin_to_hex, \
     ProgressIndicatorPercent, ChunkIteratorFileWrapper, remove_surrogates, log_multi, \
     PathPrefixPattern, FnmatchPattern, open_item, file_status, format_file_size, consume, \
-    CompressionDecider1, CompressionDecider2, CompressionSpec
+    CompressionDecider1, CompressionDecider2, CompressionSpec, \
+    IntegrityError
 from .repository import Repository
-from .platform import acl_get, acl_set
+from .platform import acl_get, acl_set, set_flags, get_flags, swidth
 from .chunker import Chunker
 from .hashindex import ChunkIndex, ChunkIndexEntry
 from .cache import ChunkListEntry
 import msgpack
 
 has_lchmod = hasattr(os, 'lchmod')
-has_lchflags = hasattr(os, 'lchflags')
 
 flags_normal = os.O_RDONLY | getattr(os, 'O_BINARY', 0)
 flags_noatime = flags_normal | getattr(os, 'O_NOATIME', 0)
 
 
+class Statistics:
+
+    def __init__(self):
+        self.osize = self.csize = self.usize = self.nfiles = 0
+        self.last_progress = 0  # timestamp when last progress was shown
+
+    def update(self, size, csize, unique):
+        self.osize += size
+        self.csize += csize
+        if unique:
+            self.usize += csize
+
+    summary = """\
+                       Original size      Compressed size    Deduplicated size
+{label:15} {stats.osize_fmt:>20s} {stats.csize_fmt:>20s} {stats.usize_fmt:>20s}"""
+
+    def __str__(self):
+        return self.summary.format(stats=self, label='This archive:')
+
+    def __repr__(self):
+        return "<{cls} object at {hash:#x} ({self.osize}, {self.csize}, {self.usize})>".format(
+            cls=type(self).__name__, hash=id(self), self=self)
+
+    @property
+    def osize_fmt(self):
+        return format_file_size(self.osize)
+
+    @property
+    def usize_fmt(self):
+        return format_file_size(self.usize)
+
+    @property
+    def csize_fmt(self):
+        return format_file_size(self.csize)
+
+    def show_progress(self, item=None, final=False, stream=None, dt=None):
+        now = time.time()
+        if dt is None or now - self.last_progress > dt:
+            self.last_progress = now
+            columns, lines = get_terminal_size()
+            if not final:
+                msg = '{0.osize_fmt} O {0.csize_fmt} C {0.usize_fmt} D {0.nfiles} N '.format(self)
+                path = remove_surrogates(item[b'path']) if item else ''
+                space = columns - swidth(msg)
+                if space < swidth('...') + swidth(path):
+                    path = '%s...%s' % (path[:(space // 2) - swidth('...')], path[-space // 2:])
+                msg += "{0:<{space}}".format(path, space=space)
+            else:
+                msg = ' ' * columns
+            print(msg, file=stream or sys.stderr, end="\r", flush=True)
+
+
 class DownloadPipeline:
 
     def __init__(self, repository, key):
@@ -434,10 +487,9 @@ Number of files: {0.stats.nfiles}'''.format(
         else:
             os.utime(path, None, ns=(atime, mtime), follow_symlinks=False)
         acl_set(path, item, self.numeric_owner)
-        # Only available on OS X and FreeBSD
-        if has_lchflags and b'bsdflags' in item:
+        if b'bsdflags' in item:
             try:
-                os.lchflags(path, item[b'bsdflags'])
+                set_flags(path, item[b'bsdflags'], fd=fd)
             except OSError:
                 pass
         # chown removes Linux capabilities, so set the extended attributes at the end, after chown, since they include
@@ -505,8 +557,9 @@ Number of files: {0.stats.nfiles}'''.format(
         xattrs = xattr.get_all(path, follow_symlinks=False)
         if xattrs:
             item[b'xattrs'] = StableDict(xattrs)
-        if has_lchflags and st.st_flags:
-            item[b'bsdflags'] = st.st_flags
+        bsdflags = get_flags(path, st)
+        if bsdflags:
+            item[b'bsdflags'] = bsdflags
         acl_get(path, item, st, self.numeric_owner)
         return item
 
@@ -698,7 +751,17 @@ class ArchiveChecker:
         self.error_found = False
         self.possibly_superseded = set()
 
-    def check(self, repository, repair=False, archive=None, last=None, prefix=None, save_space=False):
+    def check(self, repository, repair=False, archive=None, last=None, prefix=None, verify_data=False,
+              save_space=False):
+        """Perform a set of checks on 'repository'
+
+        :param repair: enable repair mode, write updated or corrected data into repository
+        :param archive: only check this archive
+        :param last: only check this number of recent archives
+        :param prefix: only check archives with this prefix
+        :param verify_data: integrity verification of data referenced by archives
+        :param save_space: Repository.commit(save_space)
+        """
         logger.info('Starting archive consistency check...')
         self.check_all = archive is None and last is None and prefix is None
         self.repair = repair
@@ -712,6 +775,8 @@ class ArchiveChecker:
         else:
             self.manifest, _ = Manifest.load(repository, key=self.key)
         self.rebuild_refcounts(archive=archive, last=last, prefix=prefix)
+        if verify_data:
+            self.verify_data()
         self.orphan_chunks_check()
         self.finish(save_space=save_space)
         if self.error_found:
@@ -741,6 +806,26 @@ class ArchiveChecker:
         cdata = repository.get(next(self.chunks.iteritems())[0])
         return key_factory(repository, cdata)
 
+    def verify_data(self):
+        logger.info('Starting cryptographic data integrity verification...')
+        pi = ProgressIndicatorPercent(total=len(self.chunks), msg="Verifying data %6.2f%%", step=0.01, same_line=True)
+        count = errors = 0
+        for chunk_id, (refcount, *_) in self.chunks.iteritems():
+            pi.show()
+            if not refcount:
+                continue
+            encrypted_data = self.repository.get(chunk_id)
+            try:
+                _, data = self.key.decrypt(chunk_id, encrypted_data)
+            except IntegrityError as integrity_error:
+                self.error_found = True
+                errors += 1
+                logger.error('chunk %s, integrity error: %s', bin_to_hex(chunk_id), integrity_error)
+            count += 1
+        pi.finish()
+        log = logger.error if errors else logger.info
+        log('Finished cryptographic data integrity verification, verified %d chunks with %d integrity errors.', count, errors)
+
     def rebuild_manifest(self):
         """Rebuild the manifest object if it is missing
 
@@ -874,6 +959,8 @@ class ArchiveChecker:
         else:
             # we only want one specific archive
             archive_items = [item for item in self.manifest.archives.items() if item[0] == archive]
+            if not archive_items:
+                logger.error("Archive '%s' not found.", archive)
             num_archives = 1
             end = 1
 

src/borg/archiver.py

@@ -8,6 +8,7 @@ import functools
 import hashlib
 import inspect
 import io
+import logging
 import os
 import re
 import shlex
@@ -22,7 +23,7 @@ from . import __version__
 from .helpers import Error, location_validator, archivename_validator, format_time, format_file_size, \
     parse_pattern, PathPrefixPattern, to_localtime, timestamp, \
     get_cache_dir, prune_within, prune_split, bin_to_hex, safe_encode, \
-    Manifest, remove_surrogates, update_excludes, format_archive, check_extension_modules, Statistics, \
+    Manifest, remove_surrogates, update_excludes, format_archive, check_extension_modules, \
     dir_is_tagged, ChunkerParams, CompressionSpec, is_slow_msgpack, yes, sysinfo, \
     log_multi, PatternMatcher, ItemFormatter
 from .logger import create_logger, setup_logging
@@ -34,12 +35,11 @@ from .repository import Repository
 from .cache import Cache
 from .constants import *  # NOQA
 from .key import key_creator, RepoKey, PassphraseKey
-from .archive import Archive, ArchiveChecker, ArchiveRecreater
+from .archive import Archive, ArchiveChecker, ArchiveRecreater, Statistics
 from .remote import RepositoryServer, RemoteRepository, cache_if_remote
 from .selftest import selftest
 from .hashindex import ChunkIndexEntry
-
-has_lchflags = hasattr(os, 'lchflags')
+from .platform import get_flags
 
 
 def argument(args, str_or_bool):
@@ -112,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):
@@ -185,12 +185,16 @@ class Archiver:
             if not yes(msg, false_msg="Aborting.", truish=('YES', ),
                        env_var_override='BORG_CHECK_I_KNOW_WHAT_I_AM_DOING'):
                 return EXIT_ERROR
+        if args.repo_only and args.verify_data:
+            self.print_error("--repository-only and --verify-data contradict each other. Please select one.")
+            return EXIT_ERROR
         if not args.archives_only:
             if not repository.check(repair=args.repair, save_space=args.save_space):
                 return EXIT_WARNING
         if not args.repo_only and not ArchiveChecker().check(
                 repository, repair=args.repair, archive=args.location.archive,
-                last=args.last, prefix=args.prefix, save_space=args.save_space):
+                last=args.last, prefix=args.prefix, verify_data=args.verify_data,
+                save_space=args.save_space):
             return EXIT_WARNING
         return EXIT_SUCCESS
 
@@ -274,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
@@ -312,7 +316,7 @@ class Archiver:
             return
         status = None
         # Ignore if nodump flag is set
-        if has_lchflags and (st.st_flags & stat.UF_NODUMP):
+        if get_flags(path, st) & stat.UF_NODUMP:
             return
         if stat.S_ISREG(st.st_mode) or read_special and not stat.S_ISDIR(st.st_mode):
             if not dry_run:
@@ -413,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)
@@ -670,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 = []
@@ -789,9 +793,8 @@ class Archiver:
         is_checkpoint = re.compile(r'\.checkpoint(\.\d+)?$').search
         checkpoints = [arch for arch in archives_checkpoints if is_checkpoint(arch.name)]
         # keep the latest checkpoint, if there is no later non-checkpoint archive
-        latest_checkpoint = checkpoints[0] if checkpoints else None
-        if archives_checkpoints[0] is latest_checkpoint:
-            keep_checkpoints = [latest_checkpoint, ]
+        if archives_checkpoints and checkpoints and archives_checkpoints[0] is checkpoints[0]:
+            keep_checkpoints = checkpoints[:1]
         else:
             keep_checkpoints = []
         checkpoints = set(checkpoints)
@@ -818,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)
@@ -838,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):
@@ -1164,7 +1168,48 @@ class Archiver:
         init_epilog = textwrap.dedent("""
         This command initializes an empty repository. A repository is a filesystem
         directory containing the deduplicated data from zero or more archives.
-        Encryption can be enabled at repository init time.
+
+        Encryption can be enabled at repository init time (the default).
+
+        It is not recommended to disable encryption. Repository encryption protects you
+        e.g. against the case that an attacker has access to your backup repository.
+
+        But be careful with the key / the passphrase:
+
+        If you want "passphrase-only" security, use the repokey mode. The key will
+        be stored inside the repository (in its "config" file). In above mentioned
+        attack scenario, the attacker will have the key (but not the passphrase).
+
+        If you want "passphrase and having-the-key" security, use the keyfile mode.
+        The key will be stored in your home directory (in .config/borg/keys). In
+        the attack scenario, the attacker who has just access to your repo won't have
+        the key (and also not the passphrase).
+
+        Make a backup copy of the key file (keyfile mode) or repo config file
+        (repokey mode) and keep it at a safe place, so you still have the key in
+        case it gets corrupted or lost. Also keep the passphrase at a safe place.
+        The backup that is encrypted with that key won't help you with that, of course.
+
+        Make sure you use a good passphrase. Not too short, not too simple. The real
+        encryption / decryption key is encrypted with / locked by your passphrase.
+        If an attacker gets your key, he can't unlock and use it without knowing the
+        passphrase.
+
+        Be careful with special or non-ascii characters in your passphrase:
+
+        - Borg processes the passphrase as unicode (and encodes it as utf-8),
+          so it does not have problems dealing with even the strangest characters.
+        - BUT: that does not necessarily apply to your OS / VM / keyboard configuration.
+
+        So better use a long passphrase made from simple ascii chars than one that
+        includes non-ascii stuff or characters that are hard/impossible to enter on
+        a different keyboard layout.
+
+        You can change your passphrase for existing repos at any time, it won't affect
+        the encryption/decryption key or other secrets.
+
+        When encrypting, AES-CTR-256 is used for encryption, and HMAC-SHA256 for
+        authentication. Hardware acceleration will be used automatically.
         """)
         subparser = subparsers.add_parser('init', parents=[common_parser], add_help=False,
                                           description=self.do_init.__doc__, epilog=init_epilog,
@@ -1213,6 +1258,18 @@ class Archiver:
           required).
         - The archive checks can be time consuming, they can be skipped using the
           --repository-only option.
+
+        The --verify-data option will perform a full integrity verification (as opposed to
+        checking the CRC32 of the segment) of data, which means reading the data from the
+        repository, decrypting and decompressing it. This is a cryptographic verification,
+        which will detect (accidental) corruption. For encrypted repositories it is
+        tamper-resistant as well, unless the attacker has access to the keys.
+
+        It is also very slow.
+
+        --verify-data only verifies data used by the archives specified with --last,
+        --prefix or an explicitly named archive. If none of these are passed,
+        all data in the repository is verified.
         """)
         subparser = subparsers.add_parser('check', parents=[common_parser], add_help=False,
                                           description=self.do_check.__doc__,
@@ -1229,6 +1286,10 @@ class Archiver:
         subparser.add_argument('--archives-only', dest='archives_only', action='store_true',
                                default=False,
                                help='only perform archives checks')
+        subparser.add_argument('--verify-data', dest='verify_data', action='store_true',
+                               default=False,
+                               help='perform cryptographic archive data integrity verification '
+                                    '(conflicts with --repository-only)')
         subparser.add_argument('--repair', dest='repair', action='store_true',
                                default=False,
                                help='attempt to repair any inconsistencies found')
@@ -1240,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
@@ -1401,6 +1465,10 @@ class Archiver:
         be restricted by using the ``--exclude`` option.
 
         See the output of the "borg help patterns" command for more help on exclude patterns.
+
+        By using ``--dry-run``, you can do all extraction steps except actually writing the
+        output data: reading metadata and data chunks from the repo, checking the hash/hmac,
+        decrypting, decompressing.
         """)
         subparser = subparsers.add_parser('extract', parents=[common_parser], add_help=False,
                                           description=self.do_extract.__doc__,
@@ -2002,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.")
@@ -2037,6 +2120,14 @@ def sig_info_handler(signum, stack):  # pragma: no cover
             break
 
 
+class SIGTERMReceived(BaseException):
+    pass
+
+
+def sig_term_handler(signum, stack):
+    raise SIGTERMReceived
+
+
 def setup_signal_handlers():  # pragma: no cover
     sigs = []
     if hasattr(signal, 'SIGUSR1'):
@@ -2045,6 +2136,7 @@ def setup_signal_handlers():  # pragma: no cover
         sigs.append(signal.SIGINFO)  # kill -INFO pid (or ctrl-t)
     for sig in sigs:
         signal.signal(sig, sig_info_handler)
+    signal.signal(signal.SIGTERM, sig_term_handler)
 
 
 def main():  # pragma: no cover
@@ -2076,18 +2168,22 @@ def main():  # pragma: no cover
     except KeyboardInterrupt:
         msg = 'Keyboard interrupt.\n%s\n%s' % (traceback.format_exc(), sysinfo())
         exit_code = EXIT_ERROR
+    except SIGTERMReceived:
+        msg = 'Received SIGTERM.'
+        exit_code = EXIT_ERROR
     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)
 
 

src/borg/constants.py

@@ -12,8 +12,14 @@ UMASK_DEFAULT = 0o077
 CACHE_TAG_NAME = 'CACHEDIR.TAG'
 CACHE_TAG_CONTENTS = b'Signature: 8a477f597d28d172789f06886806bc55'
 
-DEFAULT_MAX_SEGMENT_SIZE = 5 * 1024 * 1024
-DEFAULT_SEGMENTS_PER_DIR = 10000
+# A large, but not unreasonably large segment size. Always less than 2 GiB (for legacy file systems). We choose
+# 500 MiB which means that no indirection from the inode is needed for typical Linux file systems.
+# Note that this is a soft-limit and can be exceeded (worst case) by a full maximum chunk size and some metadata
+# bytes. That's why it's 500 MiB instead of 512 MiB.
+DEFAULT_MAX_SEGMENT_SIZE = 500 * 1024 * 1024
+
+# A few hundred files per directory to go easy on filesystems which don't like too many files per dir (NTFS)
+DEFAULT_SEGMENTS_PER_DIR = 500
 
 CHUNK_MIN_EXP = 19  # 2**19 == 512kiB
 CHUNK_MAX_EXP = 23  # 2**23 == 8MiB

src/borg/crypto.pyx

@@ -1,17 +1,11 @@
-"""A thin OpenSSL wrapper
+"""A thin OpenSSL wrapper"""
 
-This could be replaced by PyCrypto maybe?
-"""
 from libc.stdlib cimport malloc, free
 from cpython.buffer cimport PyBUF_SIMPLE, PyObject_GetBuffer, PyBuffer_Release
 
 API_VERSION = 3
 
 
-cdef extern from "openssl/rand.h":
-    int  RAND_bytes(unsigned char *buf, int num)
-
-
 cdef extern from "openssl/evp.h":
     ctypedef struct EVP_MD:
         pass

src/borg/helpers.py

@@ -11,7 +11,6 @@ import stat
 import textwrap
 import pwd
 import re
-from shutil import get_terminal_size
 import sys
 from string import Formatter
 import platform
@@ -82,7 +81,7 @@ def check_extension_modules():
         raise ExtensionModuleError
     if crypto.API_VERSION != 3:
         raise ExtensionModuleError
-    if platform.API_VERSION != 2:
+    if platform.API_VERSION != 3:
         raise ExtensionModuleError
 
 
@@ -172,57 +171,6 @@ def prune_split(archives, pattern, n, skip=[]):
     return keep
 
 
-class Statistics:
-
-    def __init__(self):
-        self.osize = self.csize = self.usize = self.nfiles = 0
-        self.last_progress = 0  # timestamp when last progress was shown
-
-    def update(self, size, csize, unique):
-        self.osize += size
-        self.csize += csize
-        if unique:
-            self.usize += csize
-
-    summary = """\
-                       Original size      Compressed size    Deduplicated size
-{label:15} {stats.osize_fmt:>20s} {stats.csize_fmt:>20s} {stats.usize_fmt:>20s}"""
-
-    def __str__(self):
-        return self.summary.format(stats=self, label='This archive:')
-
-    def __repr__(self):
-        return "<{cls} object at {hash:#x} ({self.osize}, {self.csize}, {self.usize})>".format(cls=type(self).__name__, hash=id(self), self=self)
-
-    @property
-    def osize_fmt(self):
-        return format_file_size(self.osize)
-
-    @property
-    def usize_fmt(self):
-        return format_file_size(self.usize)
-
-    @property
-    def csize_fmt(self):
-        return format_file_size(self.csize)
-
-    def show_progress(self, item=None, final=False, stream=None, dt=None):
-        now = time.time()
-        if dt is None or now - self.last_progress > dt:
-            self.last_progress = now
-            columns, lines = get_terminal_size()
-            if not final:
-                msg = '{0.osize_fmt} O {0.csize_fmt} C {0.usize_fmt} D {0.nfiles} N '.format(self)
-                path = remove_surrogates(item[b'path']) if item else ''
-                space = columns - len(msg)
-                if space < len('...') + len(path):
-                    path = '%s...%s' % (path[:(space // 2) - len('...')], path[-space // 2:])
-                msg += "{0:<{space}}".format(path, space=space)
-            else:
-                msg = ' ' * columns
-            print(msg, file=stream or sys.stderr, end="\r", flush=True)
-
-
 def get_home_dir():
     """Get user's home directory while preferring a possibly set HOME
     environment variable
@@ -282,8 +230,7 @@ def load_excludes(fh):
     """Load and parse exclude patterns from file object. Lines empty or starting with '#' after stripping whitespace on
     both line ends are ignored.
     """
-    patterns = (line for line in (i.strip() for i in fh) if not line.startswith('#'))
-    return [parse_pattern(pattern) for pattern in patterns if pattern]
+    return [parse_pattern(pattern) for pattern in clean_lines(fh)]
 
 
 def update_excludes(args):
@@ -734,11 +681,15 @@ def posix_acl_use_stored_uid_gid(acl):
 
 def safe_decode(s, coding='utf-8', errors='surrogateescape'):
     """decode bytes to str, with round-tripping "invalid" bytes"""
+    if s is None:
+        return None
     return s.decode(coding, errors)
 
 
 def safe_encode(s, coding='utf-8', errors='surrogateescape'):
     """encode str to bytes, with round-tripping "invalid" bytes"""
+    if s is None:
+        return None
     return s.encode(coding, errors)
 
 
@@ -1038,7 +989,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
 
@@ -1047,17 +998,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:
@@ -1074,11 +1041,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:
@@ -1128,7 +1095,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
 
@@ -1167,7 +1134,7 @@ class ItemFormatter:
         'NUL': 'NUL character for creating print0 / xargs -0 like ouput, see bpath',
     }
     KEY_GROUPS = (
-        ('type', 'mode', 'uid', 'gid', 'user', 'group', 'path', 'bpath', 'source', 'linktarget'),
+        ('type', 'mode', 'uid', 'gid', 'user', 'group', 'path', 'bpath', 'source', 'linktarget', 'flags'),
         ('size', 'csize', 'num_chunks', 'unique_chunks'),
         ('mtime', 'ctime', 'atime', 'isomtime', 'isoctime', 'isoatime'),
         tuple(sorted(hashlib.algorithms_guaranteed)),
@@ -1260,6 +1227,7 @@ class ItemFormatter:
         item_data['source'] = source
         item_data['linktarget'] = source
         item_data['extra'] = extra
+        item_data['flags'] = item.get(b'bsdflags')
         for key in self.used_call_keys:
             item_data[key] = self.call_keys[key](item)
         return item_data

src/borg/item.py

@@ -0,0 +1,141 @@
+from .constants import ITEM_KEYS
+from .helpers import safe_encode, safe_decode, bigint_to_int, int_to_bigint, StableDict
+
+
+class PropDict:
+    """
+    Manage a dictionary via properties.
+
+    - initialization by giving a dict or kw args
+    - on initialization, normalize dict keys to be str type
+    - access dict via properties, like: x.key_name
+    - membership check via: 'key_name' in x
+    - optionally, encode when setting a value
+    - optionally, decode when getting a value
+    - be safe against typos in key names: check against VALID_KEYS
+    - when setting a value: check type of value
+    """
+    VALID_KEYS = None  # override with <set of str> in child class
+
+    __slots__ = ("_dict", )  # avoid setting attributes not supported by properties
+
+    def __init__(self, data_dict=None, **kw):
+        if data_dict is None:
+            data = kw
+        elif not isinstance(data_dict, dict):
+            raise TypeError("data_dict must be dict")
+        else:
+            data = data_dict
+        # internally, we want an dict with only str-typed keys
+        _dict = {}
+        for k, v in data.items():
+            if isinstance(k, bytes):
+                k = k.decode()
+            elif not isinstance(k, str):
+                raise TypeError("dict keys must be str or bytes, not %r" % k)
+            _dict[k] = v
+        unknown_keys = set(_dict) - self.VALID_KEYS
+        if unknown_keys:
+            raise ValueError("dict contains unknown keys %s" % ','.join(unknown_keys))
+        self._dict = _dict
+
+    def as_dict(self):
+        """return the internal dictionary"""
+        return StableDict(self._dict)
+
+    def _check_key(self, key):
+        """make sure key is of type str and known"""
+        if not isinstance(key, str):
+            raise TypeError("key must be str")
+        if key not in self.VALID_KEYS:
+            raise ValueError("key '%s' is not a valid key" % key)
+        return key
+
+    def __contains__(self, key):
+        """do we have this key?"""
+        return self._check_key(key) in self._dict
+
+    def get(self, key, default=None):
+        """get value for key, return default if key does not exist"""
+        return getattr(self, self._check_key(key), default)
+
+    @staticmethod
+    def _make_property(key, value_type, value_type_name=None, encode=None, decode=None):
+        """return a property that deals with self._dict[key]"""
+        assert isinstance(key, str)
+        if value_type_name is None:
+            value_type_name = value_type.__name__
+        doc = "%s (%s)" % (key, value_type_name)
+        type_error_msg = "%s value must be %s" % (key, value_type_name)
+        attr_error_msg = "attribute %s not found" % key
+
+        def _get(self):
+            try:
+                value = self._dict[key]
+            except KeyError:
+                raise AttributeError(attr_error_msg) from None
+            if decode is not None:
+                value = decode(value)
+            return value
+
+        def _set(self, value):
+            if not isinstance(value, value_type):
+                raise TypeError(type_error_msg)
+            if encode is not None:
+                value = encode(value)
+            self._dict[key] = value
+
+        def _del(self):
+            try:
+                del self._dict[key]
+            except KeyError:
+                raise AttributeError(attr_error_msg) from None
+
+        return property(_get, _set, _del, doc=doc)
+
+
+class Item(PropDict):
+    """
+    Item abstraction that deals with validation and the low-level details internally:
+
+    Items are created either from msgpack unpacker output, from another dict, from kwargs or
+    built step-by-step by setting attributes.
+
+    msgpack gives us a dict with bytes-typed keys, just give it to Item(d) and use item.key_name later.
+    msgpack gives us byte-typed values for stuff that should be str, we automatically decode when getting
+    such a property and encode when setting it.
+
+    If an Item shall be serialized, give as_dict() method output to msgpack packer.
+    """
+
+    VALID_KEYS = set(key.decode() for key in ITEM_KEYS)  # we want str-typed keys
+
+    __slots__ = ("_dict", )  # avoid setting attributes not supported by properties
+
+    # properties statically defined, so that IDEs can know their names:
+
+    path = PropDict._make_property('path', str, 'surrogate-escaped str', encode=safe_encode, decode=safe_decode)
+    source = PropDict._make_property('source', str, 'surrogate-escaped str', encode=safe_encode, decode=safe_decode)
+    acl_access = PropDict._make_property('acl_access', str, 'surrogate-escaped str', encode=safe_encode, decode=safe_decode)
+    acl_default = PropDict._make_property('acl_default', str, 'surrogate-escaped str', encode=safe_encode, decode=safe_decode)
+    acl_extended = PropDict._make_property('acl_extended', str, 'surrogate-escaped str', encode=safe_encode, decode=safe_decode)
+    acl_nfs4 = PropDict._make_property('acl_nfs4', str, 'surrogate-escaped str', encode=safe_encode, decode=safe_decode)
+
+    user = PropDict._make_property('user', (str, type(None)), 'surrogate-escaped str or None', encode=safe_encode, decode=safe_decode)
+    group = PropDict._make_property('group', (str, type(None)), 'surrogate-escaped str or None', encode=safe_encode, decode=safe_decode)
+
+    mode = PropDict._make_property('mode', int)
+    uid = PropDict._make_property('uid', int)
+    gid = PropDict._make_property('gid', int)
+    rdev = PropDict._make_property('rdev', int)
+    bsdflags = PropDict._make_property('bsdflags', int)
+
+    atime = PropDict._make_property('atime', int, 'bigint', encode=int_to_bigint, decode=bigint_to_int)
+    ctime = PropDict._make_property('ctime', int, 'bigint', encode=int_to_bigint, decode=bigint_to_int)
+    mtime = PropDict._make_property('mtime', int, 'bigint', encode=int_to_bigint, decode=bigint_to_int)
+
+    hardlink_master = PropDict._make_property('hardlink_master', bool)
+
+    chunks = PropDict._make_property('chunks', list)
+
+    xattrs = PropDict._make_property('xattrs', StableDict)

src/borg/key.py

@@ -1,4 +1,4 @@
-from binascii import a2b_base64, b2a_base64
+from binascii import a2b_base64, b2a_base64, hexlify
 import configparser
 import getpass
 import os
@@ -413,16 +413,19 @@ class KeyfileKey(KeyfileKeyBase):
     FILE_ID = 'BORG_KEY'
 
     def sanity_check(self, filename, id):
-        with open(filename, 'r') as fd:
-            line = fd.readline().strip()
-            if not line.startswith(self.FILE_ID):
+        file_id = self.FILE_ID.encode() + b' '
+        repo_id = hexlify(id)
+        with open(filename, 'rb') as fd:
+            # we do the magic / id check in binary mode to avoid stumbling over
+            # decoding errors if somebody has binary files in the keys dir for some reason.
+            if fd.read(len(file_id)) != file_id:
                 raise KeyfileInvalidError(self.repository._location.canonical_path(), filename)
-            if line[len(self.FILE_ID) + 1:] != id:
+            if fd.read(len(repo_id)) != repo_id:
                 raise KeyfileMismatchError(self.repository._location.canonical_path(), filename)
             return filename
 
     def find_key(self):
-        id = self.repository.id_str
+        id = self.repository.id
         keyfile = os.environ.get('BORG_KEY_FILE')
         if keyfile:
             return self.sanity_check(keyfile, id)

src/borg/logger.py

@@ -88,7 +88,7 @@ def setup_logging(stream=None, conf_fname=None, env_var='BORG_LOGGING_CONF', lev
     logger = logging.getLogger('')
     handler = logging.StreamHandler(stream)
     if is_serve:
-        fmt = '$LOG %(levelname)s Remote: %(message)s'
+        fmt = '$LOG %(levelname)s %(name)s Remote: %(message)s'
     else:
         fmt = '%(message)s'
     handler.setFormatter(logging.Formatter(fmt))

src/borg/platform.py

@@ -1,16 +1,10 @@
 import sys
 
+from .platform_base import acl_get, acl_set, SyncFile, sync_dir, set_flags, get_flags, swidth, API_VERSION
+
 if sys.platform.startswith('linux'):  # pragma: linux only
-    from .platform_linux import acl_get, acl_set, API_VERSION
+    from .platform_linux import acl_get, acl_set, SyncFile, set_flags, get_flags, swidth, API_VERSION
 elif sys.platform.startswith('freebsd'):  # pragma: freebsd only
-    from .platform_freebsd import acl_get, acl_set, API_VERSION
+    from .platform_freebsd import acl_get, acl_set, swidth, API_VERSION
 elif sys.platform == 'darwin':  # pragma: darwin only
-    from .platform_darwin import acl_get, acl_set, API_VERSION
-else:  # pragma: unknown platform only
-    API_VERSION = 2
-
-    def acl_get(path, item, st, numeric_owner=False):
-        pass
-
-    def acl_set(path, item, numeric_owner=False):
-        pass
+    from .platform_darwin import acl_get, acl_set, swidth, API_VERSION

src/borg/platform_base.py

@@ -0,0 +1,100 @@
+import os
+
+API_VERSION = 3
+
+fdatasync = getattr(os, 'fdatasync', os.fsync)
+
+
+def acl_get(path, item, st, numeric_owner=False):
+    """
+    Saves ACL Entries
+
+    If `numeric_owner` is True the user/group field is not preserved only uid/gid
+    """
+
+
+def acl_set(path, item, numeric_owner=False):
+    """
+    Restore ACL Entries
+
+    If `numeric_owner` is True the stored uid/gid is used instead
+    of the user/group names
+    """
+
+try:
+    from os import lchflags
+
+    def set_flags(path, bsd_flags, fd=None):
+        lchflags(path, bsd_flags)
+except ImportError:
+    def set_flags(path, bsd_flags, fd=None):
+        pass
+
+
+def get_flags(path, st):
+    """Return BSD-style file flags for path or stat without following symlinks."""
+    return getattr(st, 'st_flags', 0)
+
+
+def sync_dir(path):
+    fd = os.open(path, os.O_RDONLY)
+    try:
+        os.fsync(fd)
+    finally:
+        os.close(fd)
+
+
+class SyncFile:
+    """
+    A file class that is supposed to enable write ordering (one way or another) and data durability after close().
+
+    The degree to which either is possible varies with operating system, file system and hardware.
+
+    This fallback implements a naive and slow way of doing this. On some operating systems it can't actually
+    guarantee any of the above, since fsync() doesn't guarantee it. Furthermore it may not be possible at all
+    to satisfy the above guarantees on some hardware or operating systems. In these cases we hope that the thorough
+    checksumming implemented catches any corrupted data due to misordered, delayed or partial writes.
+
+    Note that POSIX doesn't specify *anything* about power failures (or similar failures). A system that
+    routinely loses files or corrupts file on power loss is POSIX compliant.
+
+    TODO: Use F_FULLSYNC on OSX.
+    TODO: A Windows implementation should use CreateFile with FILE_FLAG_WRITE_THROUGH.
+    """
+
+    def __init__(self, path):
+        self.fd = open(path, 'wb')
+        self.fileno = self.fd.fileno()
+
+    def __enter__(self):
+        return self
+
+    def __exit__(self, exc_type, exc_val, exc_tb):
+        self.close()
+
+    def write(self, data):
+        self.fd.write(data)
+
+    def sync(self):
+        """
+        Synchronize file contents. Everything written prior to sync() must become durable before anything written
+        after sync().
+        """
+        self.fd.flush()
+        fdatasync(self.fileno)
+        if hasattr(os, 'posix_fadvise'):
+            os.posix_fadvise(self.fileno, 0, 0, os.POSIX_FADV_DONTNEED)
+
+    def close(self):
+        """sync() and close."""
+        self.sync()
+        self.fd.close()
+        sync_dir(os.path.dirname(self.fd.name))
+
+
+def swidth(s):
+    """terminal output width of string <s>
+
+    For western scripts, this is just len(s), but for cjk glyphs, 2 cells are used.
+    """
+    return len(s)

src/borg/platform_darwin.pyx

@@ -1,7 +1,8 @@
 import os
 from .helpers import user2uid, group2gid, safe_decode, safe_encode
+from .platform_posix import swidth
 
-API_VERSION = 2
+API_VERSION = 3
 
 cdef extern from "sys/acl.h":
     ctypedef struct _acl_t:

src/borg/platform_freebsd.pyx

@@ -1,7 +1,8 @@
 import os
 from .helpers import posix_acl_use_stored_uid_gid, safe_encode, safe_decode
+from .platform_posix import swidth
 
-API_VERSION = 2
+API_VERSION = 3
 
 cdef extern from "errno.h":
     int errno

src/borg/platform_linux.pyx

@@ -1,13 +1,20 @@
 import os
 import re
-from stat import S_ISLNK
+import resource
+import stat
+
 from .helpers import posix_acl_use_stored_uid_gid, user2uid, group2gid, safe_decode, safe_encode
+from .platform_base import SyncFile as BaseSyncFile
+from .platform_posix import swidth
+
+from libc cimport errno
 
-API_VERSION = 2
+API_VERSION = 3
 
 cdef extern from "sys/types.h":
     int ACL_TYPE_ACCESS
     int ACL_TYPE_DEFAULT
+    ctypedef off64_t
 
 cdef extern from "sys/acl.h":
     ctypedef struct _acl_t:
@@ -23,10 +30,78 @@ cdef extern from "sys/acl.h":
 cdef extern from "acl/libacl.h":
     int acl_extended_file(const char *path)
 
+cdef extern from "fcntl.h":
+    int sync_file_range(int fd, off64_t offset, off64_t nbytes, unsigned int flags)
+    unsigned int SYNC_FILE_RANGE_WRITE
+    unsigned int SYNC_FILE_RANGE_WAIT_BEFORE
+    unsigned int SYNC_FILE_RANGE_WAIT_AFTER
+
+cdef extern from "linux/fs.h":
+    # ioctls
+    int FS_IOC_SETFLAGS
+    int FS_IOC_GETFLAGS
+
+    # inode flags
+    int FS_NODUMP_FL
+    int FS_IMMUTABLE_FL
+    int FS_APPEND_FL
+    int FS_COMPR_FL
+
+cdef extern from "stropts.h":
+    int ioctl(int fildes, int request, ...)
+
+cdef extern from "errno.h":
+    int errno
+
+cdef extern from "string.h":
+    char *strerror(int errnum)
 
 _comment_re = re.compile(' *#.*', re.M)
 
 
+BSD_TO_LINUX_FLAGS = {
+    stat.UF_NODUMP: FS_NODUMP_FL,
+    stat.UF_IMMUTABLE: FS_IMMUTABLE_FL,
+    stat.UF_APPEND: FS_APPEND_FL,
+    stat.UF_COMPRESSED: FS_COMPR_FL,
+}
+
+
+def set_flags(path, bsd_flags, fd=None):
+    if fd is None and stat.S_ISLNK(os.lstat(path).st_mode):
+        return
+    cdef int flags = 0
+    for bsd_flag, linux_flag in BSD_TO_LINUX_FLAGS.items():
+        if bsd_flags & bsd_flag:
+            flags |= linux_flag
+    open_fd = fd is None
+    if open_fd:
+        fd = os.open(path, os.O_RDONLY|os.O_NONBLOCK|os.O_NOFOLLOW)
+    try:
+        if ioctl(fd, FS_IOC_SETFLAGS, &flags) == -1:
+            raise OSError(errno, strerror(errno).decode(), path)
+    finally:
+        if open_fd:
+            os.close(fd)
+
+
+def get_flags(path, st):
+    if stat.S_ISLNK(st.st_mode):
+        return 0
+    cdef int linux_flags
+    fd = os.open(path, os.O_RDONLY|os.O_NONBLOCK|os.O_NOFOLLOW)
+    try:
+        if ioctl(fd, FS_IOC_GETFLAGS, &linux_flags) == -1:
+            return 0
+    finally:
+        os.close(fd)
+    bsd_flags = 0
+    for bsd_flag, linux_flag in BSD_TO_LINUX_FLAGS.items():
+        if linux_flags & linux_flag:
+            bsd_flags |= bsd_flag
+    return bsd_flags
+
+
 def acl_use_local_uid_gid(acl):
     """Replace the user/group field with the local uid/gid if possible
     """
@@ -77,17 +152,13 @@ cdef acl_numeric_ids(acl):
 
 
 def acl_get(path, item, st, numeric_owner=False):
-    """Saves ACL Entries
-
-    If `numeric_owner` is True the user/group field is not preserved only uid/gid
-    """
     cdef acl_t default_acl = NULL
     cdef acl_t access_acl = NULL
     cdef char *default_text = NULL
     cdef char *access_text = NULL
 
     p = <bytes>os.fsencode(path)
-    if S_ISLNK(st.st_mode) or acl_extended_file(p) <= 0:
+    if stat.S_ISLNK(st.st_mode) or acl_extended_file(p) <= 0:
         return
     if numeric_owner:
         converter = acl_numeric_ids
@@ -112,11 +183,6 @@ def acl_get(path, item, st, numeric_owner=False):
 
 
 def acl_set(path, item, numeric_owner=False):
-    """Restore ACL Entries
-
-    If `numeric_owner` is True the stored uid/gid is used instead
-    of the user/group names
-    """
     cdef acl_t access_acl = NULL
     cdef acl_t default_acl = NULL
 
@@ -141,3 +207,45 @@ def acl_set(path, item, numeric_owner=False):
                 acl_set_file(p, ACL_TYPE_DEFAULT, default_acl)
         finally:
             acl_free(default_acl)
+
+cdef _sync_file_range(fd, offset, length, flags):
+    assert offset & PAGE_MASK == 0, "offset %d not page-aligned" % offset
+    assert length & PAGE_MASK == 0, "length %d not page-aligned" % length
+    if sync_file_range(fd, offset, length, flags) != 0:
+        raise OSError(errno, os.strerror(errno))
+    os.posix_fadvise(fd, offset, length, os.POSIX_FADV_DONTNEED)
+
+cdef unsigned PAGE_MASK = resource.getpagesize() - 1
+
+
+class SyncFile(BaseSyncFile):
+    """
+    Implemented using sync_file_range for asynchronous write-out and fdatasync for actual durability.
+
+    "write-out" means that dirty pages (= data that was written) are submitted to an I/O queue and will be send to
+    disk in the immediate future.
+    """
+
+    def __init__(self, path):
+        super().__init__(path)
+        self.offset = 0
+        self.write_window = (16 * 1024 ** 2) & ~PAGE_MASK
+        self.last_sync = 0
+        self.pending_sync = None
+
+    def write(self, data):
+        self.offset += self.fd.write(data)
+        offset = self.offset & ~PAGE_MASK
+        if offset >= self.last_sync + self.write_window:
+            self.fd.flush()
+            _sync_file_range(self.fileno, self.last_sync, offset - self.last_sync, SYNC_FILE_RANGE_WRITE)
+            if self.pending_sync is not None:
+                _sync_file_range(self.fileno, self.pending_sync, self.last_sync - self.pending_sync,
+                                 SYNC_FILE_RANGE_WRITE | SYNC_FILE_RANGE_WAIT_BEFORE | SYNC_FILE_RANGE_WAIT_AFTER)
+            self.pending_sync = self.last_sync
+            self.last_sync = offset
+
+    def sync(self):
+        self.fd.flush()
+        os.fdatasync(self.fileno)
+        os.posix_fadvise(self.fileno, 0, 0, os.POSIX_FADV_DONTNEED)

src/borg/platform_posix.pyx

@@ -0,0 +1,5 @@
+cdef extern from "wchar.h":
+    cdef int wcswidth(const Py_UNICODE *str, size_t n)
+ 
+def swidth(s):
+    return wcswidth(s, len(s))

src/borg/remote.py

@@ -301,7 +301,13 @@ class RemoteRepository:
                         if line.startswith('$LOG '):
                             _, level, msg = line.split(' ', 2)
                             level = getattr(logging, level, logging.CRITICAL)  # str -> int
-                            logging.log(level, msg.rstrip())
+                            if msg.startswith('Remote:'):
+                                # server format: '$LOG <level> Remote: <msg>'
+                                logging.log(level, msg.rstrip())
+                            else:
+                                # server format '$LOG <level> <logname> Remote: <msg>'
+                                logname, msg = msg.split(' ', 1)
+                                logging.getLogger(logname).log(level, msg.rstrip())
                         else:
                             sys.stderr.write("Remote: " + line)
             if w:
@@ -418,6 +424,9 @@ class RepositoryCache(RepositoryNoCache):
 
     Caches Repository GET operations using a local temporary Repository.
     """
+    # maximum object size that will be cached, 64 kiB.
+    THRESHOLD = 2**16
+
     def __init__(self, repository):
         super().__init__(repository)
         tmppath = tempfile.mkdtemp(prefix='borg-tmp')
@@ -438,7 +447,8 @@ class RepositoryCache(RepositoryNoCache):
             except Repository.ObjectNotFound:
                 for key_, data in repository_iterator:
                     if key_ == key:
-                        self.caching_repo.put(key, data)
+                        if len(data) <= self.THRESHOLD:
+                            self.caching_repo.put(key, data)
                         yield data
                         break
         # Consume any pending requests

src/borg/repository.py

@@ -17,6 +17,7 @@ from .helpers import Error, ErrorWithTraceback, IntegrityError, Location, Progre
 from .hashindex import NSIndex
 from .locking import UpgradableLock, LockError, LockErrorT
 from .lrucache import LRUCache
+from .platform import SyncFile, sync_dir
 
 MAX_OBJECT_SIZE = 20 * 1024 * 1024
 MAGIC = b'BORG_SEG'
@@ -32,7 +33,7 @@ class Repository:
     On disk layout:
     dir/README
     dir/config
-    dir/data/<X / SEGMENTS_PER_DIR>/<X>
+    dir/data/<X // SEGMENTS_PER_DIR>/<X>
     dir/index.X
     dir/hints.X
     """
@@ -507,7 +508,7 @@ class LoggedIO:
     def __init__(self, path, limit, segments_per_dir, capacity=90):
         self.path = path
         self.fds = LRUCache(capacity,
-                            dispose=lambda fd: fd.close())
+                            dispose=self.close_fd)
         self.segment = 0
         self.limit = limit
         self.segments_per_dir = segments_per_dir
@@ -519,6 +520,11 @@ class LoggedIO:
         self.fds.clear()
         self.fds = None  # Just to make sure we're disabled
 
+    def close_fd(self, fd):
+        if hasattr(os, 'posix_fadvise'):  # only on UNIX
+            os.posix_fadvise(fd.fileno(), 0, 0, os.POSIX_FADV_DONTNEED)
+        fd.close()
+
     def segment_iterator(self, reverse=False):
         data_path = os.path.join(self.path, 'data')
         dirs = sorted((dir for dir in os.listdir(data_path) if dir.isdigit()), key=int, reverse=reverse)
@@ -535,10 +541,10 @@ class LoggedIO:
         return None
 
     def get_segments_transaction_id(self):
-        """Verify that the transaction id is consistent with the index transaction id
+        """Return the last committed segment.
         """
         for segment, filename in self.segment_iterator(reverse=True):
-            if self.is_committed_segment(filename):
+            if self.is_committed_segment(segment):
                 return segment
         return None
 
@@ -552,10 +558,14 @@ class LoggedIO:
             else:
                 break
 
-    def is_committed_segment(self, filename):
+    def is_committed_segment(self, segment):
         """Check if segment ends with a COMMIT_TAG tag
         """
-        with open(filename, 'rb') as fd:
+        try:
+            iterator = self.iter_objects(segment)
+        except IntegrityError:
+            return False
+        with open(self.segment_filename(segment), 'rb') as fd:
             try:
                 fd.seek(-self.header_fmt.size, os.SEEK_END)
             except OSError as e:
@@ -563,7 +573,22 @@ class LoggedIO:
                 if e.errno == errno.EINVAL:
                     return False
                 raise e
-            return fd.read(self.header_fmt.size) == self.COMMIT
+            if fd.read(self.header_fmt.size) != self.COMMIT:
+                return False
+        seen_commit = False
+        while True:
+            try:
+                tag, key, offset = next(iterator)
+            except IntegrityError:
+                return False
+            except StopIteration:
+                break
+            if tag == TAG_COMMIT:
+                seen_commit = True
+                continue
+            if seen_commit:
+                return False
+        return seen_commit
 
     def segment_filename(self, segment):
         return os.path.join(self.path, 'data', str(segment // self.segments_per_dir), str(segment))
@@ -578,7 +603,8 @@ class LoggedIO:
                 dirname = os.path.join(self.path, 'data', str(self.segment // self.segments_per_dir))
                 if not os.path.exists(dirname):
                     os.mkdir(dirname)
-            self._write_fd = open(self.segment_filename(self.segment), 'ab')
+                    sync_dir(os.path.join(self.path, 'data'))
+            self._write_fd = SyncFile(self.segment_filename(self.segment))
             self._write_fd.write(MAGIC)
             self.offset = MAGIC_LEN
         return self._write_fd
@@ -591,6 +617,13 @@ class LoggedIO:
             self.fds[segment] = fd
             return fd
 
+    def close_segment(self):
+        if self._write_fd:
+            self.segment += 1
+            self.offset = 0
+            self._write_fd.close()
+            self._write_fd = None
+
     def delete_segment(self, segment):
         if segment in self.fds:
             del self.fds[segment]
@@ -641,7 +674,7 @@ class LoggedIO:
 
     def read(self, segment, offset, id):
         if segment == self.segment and self._write_fd:
-            self._write_fd.flush()
+            self._write_fd.sync()
         fd = self.get_fd(segment)
         fd.seek(offset)
         header = fd.read(self.put_header_fmt.size)
@@ -703,20 +736,8 @@ class LoggedIO:
 
     def write_commit(self):
         fd = self.get_write_fd(no_new=True)
+        fd.sync()
         header = self.header_no_crc_fmt.pack(self.header_fmt.size, TAG_COMMIT)
         crc = self.crc_fmt.pack(crc32(header) & 0xffffffff)
         fd.write(b''.join((crc, header)))
         self.close_segment()
-
-    def close_segment(self):
-        if self._write_fd:
-            self.segment += 1
-            self.offset = 0
-            self._write_fd.flush()
-            os.fsync(self._write_fd.fileno())
-            if hasattr(os, 'posix_fadvise'):  # only on UNIX
-                # tell the OS that it does not need to cache what we just wrote,
-                # avoids spoiling the cache for the OS and other processes.
-                os.posix_fadvise(self._write_fd.fileno(), 0, 0, os.POSIX_FADV_DONTNEED)
-            self._write_fd.close()
-            self._write_fd = None

src/borg/testsuite/__init__.py

@@ -5,9 +5,13 @@ import posix
 import stat
 import sys
 import sysconfig
+import tempfile
 import time
 import unittest
+
 from ..xattr import get_all
+from ..platform import get_flags
+from .. import platform
 
 # Note: this is used by borg.selftest, do not use or import py.test functionality here.
 
@@ -23,8 +27,20 @@ try:
 except ImportError:
     raises = None
 
-has_lchflags = hasattr(os, 'lchflags')
+has_lchflags = hasattr(os, 'lchflags') or sys.platform.startswith('linux')
+no_lchlfags_because = '' if has_lchflags else '(not supported on this platform)'
+try:
+    with tempfile.NamedTemporaryFile() as file:
+        platform.set_flags(file.name, stat.UF_NODUMP)
+except OSError:
+    has_lchflags = False
+    no_lchlfags_because = '(the file system at %s does not support flags)' % tempfile.gettempdir()
 
+try:
+    import llfuse
+    has_llfuse = True or llfuse  # avoids "unused import"
+except ImportError:
+    has_llfuse = False
 
 # The mtime get/set precision varies on different OS and Python versions
 if 'HAVE_FUTIMENS' in getattr(posix, '_have_functions', []):
@@ -75,13 +91,13 @@ class BaseTestCase(unittest.TestCase):
             # Assume path2 is on FUSE if st_dev is different
             fuse = s1.st_dev != s2.st_dev
             attrs = ['st_mode', 'st_uid', 'st_gid', 'st_rdev']
-            if has_lchflags:
-                attrs.append('st_flags')
             if not fuse or not os.path.isdir(path1):
                 # dir nlink is always 1 on our fuse filesystem
                 attrs.append('st_nlink')
             d1 = [filename] + [getattr(s1, a) for a in attrs]
             d2 = [filename] + [getattr(s2, a) for a in attrs]
+            d1.append(get_flags(path1, s1))
+            d2.append(get_flags(path2, s2))
             # ignore st_rdev if file is not a block/char device, fixes #203
             if not stat.S_ISCHR(d1[1]) and not stat.S_ISBLK(d1[1]):
                 d1[4] = None

src/borg/testsuite/archive.py

@@ -1,14 +1,64 @@
+import os
 from datetime import datetime, timezone
+from io import StringIO
 from unittest.mock import Mock
 
+import pytest
 import msgpack
 
-from ..archive import Archive, CacheChunkBuffer, RobustUnpacker
+from ..archive import Archive, CacheChunkBuffer, RobustUnpacker, Statistics
 from ..key import PlaintextKey
 from ..helpers import Manifest
 from . import BaseTestCase
 
 
+@pytest.fixture()
+def stats():
+    stats = Statistics()
+    stats.update(20, 10, unique=True)
+    return stats
+
+
+def test_stats_basic(stats):
+    assert stats.osize == 20
+    assert stats.csize == stats.usize == 10
+    stats.update(20, 10, unique=False)
+    assert stats.osize == 40
+    assert stats.csize == 20
+    assert stats.usize == 10
+
+
+def tests_stats_progress(stats, columns=80):
+    os.environ['COLUMNS'] = str(columns)
+    out = StringIO()
+    stats.show_progress(stream=out)
+    s = '20 B O 10 B C 10 B D 0 N '
+    buf = ' ' * (columns - len(s))
+    assert out.getvalue() == s + buf + "\r"
+
+    out = StringIO()
+    stats.update(10**3, 0, unique=False)
+    stats.show_progress(item={b'path': 'foo'}, final=False, stream=out)
+    s = '1.02 kB O 10 B C 10 B D 0 N foo'
+    buf = ' ' * (columns - len(s))
+    assert out.getvalue() == s + buf + "\r"
+    out = StringIO()
+    stats.show_progress(item={b'path': 'foo'*40}, final=False, stream=out)
+    s = '1.02 kB O 10 B C 10 B D 0 N foofoofoofoofoofoofoofo...oofoofoofoofoofoofoofoofoo'
+    buf = ' ' * (columns - len(s))
+    assert out.getvalue() == s + buf + "\r"
+
+
+def test_stats_format(stats):
+    assert str(stats) == """\
+                       Original size      Compressed size    Deduplicated size
+This archive:                   20 B                 10 B                 10 B"""
+    s = "{0.osize_fmt}".format(stats)
+    assert s == "20 B"
+    # kind of redundant, but id is variable so we can't match reliably
+    assert repr(stats) == '<Statistics object at {:#x} (20, 10, 10)>'.format(id(stats))
+
+
 class MockCache:
 
     def __init__(self):

src/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
@@ -16,7 +17,7 @@ from hashlib import sha256
 
 import pytest
 
-from .. import xattr, helpers
+from .. import xattr, helpers, platform
 from ..archive import Archive, ChunkBuffer, ArchiveRecreater
 from ..archiver import Archiver
 from ..cache import Cache
@@ -26,15 +27,13 @@ from ..helpers import Chunk, Manifest, EXIT_SUCCESS, EXIT_WARNING, EXIT_ERROR, b
 from ..key import KeyfileKeyBase
 from ..remote import RemoteRepository, PathNotAllowed
 from ..repository import Repository
+from . import has_lchflags, has_llfuse
 from . import BaseTestCase, changedir, environment_variable
 
 try:
     import llfuse
-    has_llfuse = True or llfuse  # avoids "unused import"
 except ImportError:
-    has_llfuse = False
-
-has_lchflags = hasattr(os, 'lchflags')
+    pass
 
 src_dir = os.path.abspath(os.path.join(os.path.dirname(__file__), '..'))
 
@@ -280,7 +279,7 @@ class ArchiverTestCaseBase(BaseTestCase):
         # FIFO node
         os.mkfifo(os.path.join(self.input_path, 'fifo1'))
         if has_lchflags:
-            os.lchflags(os.path.join(self.input_path, 'flagfile'), stat.UF_NODUMP)
+            platform.set_flags(os.path.join(self.input_path, 'flagfile'), stat.UF_NODUMP)
         try:
             # Block device
             os.mknod('input/bdev', 0o600 | stat.S_IFBLK, os.makedev(10, 20))
@@ -299,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)
@@ -353,6 +357,14 @@ class ArchiverTestCase(ArchiverTestCaseBase):
         # the interesting parts of info_output2 and info_output should be same
         self.assert_equal(filter(info_output), filter(info_output2))
 
+    def test_symlink_extract(self):
+        self.create_test_files()
+        self.cmd('init', self.repository_location)
+        self.cmd('create', self.repository_location + '::test', 'input')
+        with changedir('output'):
+            self.cmd('extract', self.repository_location + '::test')
+            assert os.readlink('input/link1') == 'somewhere'
+
     def test_atime(self):
         self.create_test_files()
         atime, mtime = 123456780, 234567890
@@ -639,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)
@@ -851,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)
@@ -874,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")
@@ -927,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
@@ -945,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)
 
@@ -966,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):
@@ -992,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)
@@ -1026,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)
@@ -1043,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)
@@ -1395,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']):
@@ -1486,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):
@@ -1526,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)
@@ -1590,6 +1664,29 @@ class ArchiverCheckTestCase(ArchiverTestCaseBase):
         self.cmd('check', self.repository_location, exit_code=0)
         self.cmd('extract', '--dry-run', self.repository_location + '::archive1', exit_code=0)
 
+    def _test_verify_data(self, *init_args):
+        shutil.rmtree(self.repository_path)
+        self.cmd('init', self.repository_location, *init_args)
+        self.create_src_archive('archive1')
+        archive, repository = self.open_archive('archive1')
+        with repository:
+            for item in archive.iter_items():
+                if item[b'path'].endswith('testsuite/archiver.py'):
+                    chunk = item[b'chunks'][-1]
+                    data = repository.get(chunk.id) + b'1234'
+                    repository.put(chunk.id, data)
+                    break
+            repository.commit()
+        self.cmd('check', self.repository_location, exit_code=0)
+        output = self.cmd('check', '--verify-data', self.repository_location, exit_code=1)
+        assert bin_to_hex(chunk.id) + ', integrity error' in output
+
+    def test_verify_data(self):
+        self._test_verify_data('--encryption', 'repokey')
+
+    def test_verify_data_unencrypted(self):
+        self._test_verify_data('--encryption', 'none')
+
 
 class RemoteArchiverTestCase(ArchiverTestCase):
     prefix = '__testsuite__:'

src/borg/testsuite/conftest.py

@@ -1,4 +0,0 @@
-from ..logger import setup_logging
-
-# Ensure that the loggers exist for all tests
-setup_logging()

src/borg/testsuite/helpers.py

@@ -1,7 +1,8 @@
 import hashlib
+import io
+import logging
 from time import mktime, strptime
 from datetime import datetime, timezone, timedelta
-from io import StringIO
 import os
 
 import pytest
@@ -11,7 +12,7 @@ import msgpack.fallback
 import time
 
 from ..helpers import Location, format_file_size, format_timedelta, make_path_safe, clean_lines, \
-    prune_within, prune_split, get_cache_dir, get_keys_dir, Statistics, is_slow_msgpack, \
+    prune_within, prune_split, get_cache_dir, get_keys_dir, is_slow_msgpack, \
     yes, TRUISH, FALSISH, DEFAULTISH, \
     StableDict, int_to_bigint, bigint_to_int, bin_to_hex, parse_timestamp, ChunkerParams, Chunk, \
     ProgressIndicatorPercent, ProgressIndicatorEndless, load_excludes, parse_pattern, \
@@ -629,53 +630,6 @@ def test_get_keys_dir():
         os.environ['BORG_KEYS_DIR'] = old_env
 
 
-@pytest.fixture()
-def stats():
-    stats = Statistics()
-    stats.update(20, 10, unique=True)
-    return stats
-
-
-def test_stats_basic(stats):
-    assert stats.osize == 20
-    assert stats.csize == stats.usize == 10
-    stats.update(20, 10, unique=False)
-    assert stats.osize == 40
-    assert stats.csize == 20
-    assert stats.usize == 10
-
-
-def tests_stats_progress(stats, columns=80):
-    os.environ['COLUMNS'] = str(columns)
-    out = StringIO()
-    stats.show_progress(stream=out)
-    s = '20 B O 10 B C 10 B D 0 N '
-    buf = ' ' * (columns - len(s))
-    assert out.getvalue() == s + buf + "\r"
-
-    out = StringIO()
-    stats.update(10**3, 0, unique=False)
-    stats.show_progress(item={b'path': 'foo'}, final=False, stream=out)
-    s = '1.02 kB O 10 B C 10 B D 0 N foo'
-    buf = ' ' * (columns - len(s))
-    assert out.getvalue() == s + buf + "\r"
-    out = StringIO()
-    stats.show_progress(item={b'path': 'foo'*40}, final=False, stream=out)
-    s = '1.02 kB O 10 B C 10 B D 0 N foofoofoofoofoofoofoofo...oofoofoofoofoofoofoofoofoo'
-    buf = ' ' * (columns - len(s))
-    assert out.getvalue() == s + buf + "\r"
-
-
-def test_stats_format(stats):
-    assert str(stats) == """\
-                       Original size      Compressed size    Deduplicated size
-This archive:                   20 B                 10 B                 10 B"""
-    s = "{0.osize_fmt}".format(stats)
-    assert s == "20 B"
-    # kind of redundant, but id is variable so we can't match reliably
-    assert repr(stats) == '<Statistics object at {:#x} (20, 10, 10)>'.format(id(stats))
-
-
 def test_file_size():
     """test the size formatting routines"""
     si_size_map = {
@@ -826,7 +780,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 +796,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 +813,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 +825,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()

src/borg/testsuite/item.py

@@ -0,0 +1,147 @@
+import pytest
+
+from ..item import Item
+from ..helpers import StableDict
+
+
+def test_item_empty():
+    item = Item()
+
+    assert item.as_dict() == {}
+
+    assert 'path' not in item
+    with pytest.raises(ValueError):
+        'invalid-key' in item
+    with pytest.raises(TypeError):
+        b'path' in item
+    with pytest.raises(TypeError):
+        42 in item
+
+    assert item.get('mode') is None
+    assert item.get('mode', 0o666) == 0o666
+    with pytest.raises(ValueError):
+        item.get('invalid-key')
+    with pytest.raises(TypeError):
+        item.get(b'mode')
+    with pytest.raises(TypeError):
+        item.get(42)
+
+    with pytest.raises(AttributeError):
+        item.path
+
+    with pytest.raises(AttributeError):
+        del item.path
+
+
+def test_item_from_dict():
+    # does not matter whether we get str or bytes keys
+    item = Item({b'path': b'/a/b/c', b'mode': 0o666})
+    assert item.path == '/a/b/c'
+    assert item.mode == 0o666
+    assert 'path' in item
+
+    # does not matter whether we get str or bytes keys
+    item = Item({'path': b'/a/b/c', 'mode': 0o666})
+    assert item.path == '/a/b/c'
+    assert item.mode == 0o666
+    assert 'mode' in item
+
+    # invalid - no dict
+    with pytest.raises(TypeError):
+        Item(42)
+
+    # invalid - no bytes/str key
+    with pytest.raises(TypeError):
+        Item({42: 23})
+
+    # invalid - unknown key
+    with pytest.raises(ValueError):
+        Item({'foobar': 'baz'})
+
+
+def test_item_from_kw():
+    item = Item(path=b'/a/b/c', mode=0o666)
+    assert item.path == '/a/b/c'
+    assert item.mode == 0o666
+
+
+def test_item_int_property():
+    item = Item()
+    item.mode = 0o666
+    assert item.mode == 0o666
+    assert item.as_dict() == {'mode': 0o666}
+    del item.mode
+    assert item.as_dict() == {}
+    with pytest.raises(TypeError):
+        item.mode = "invalid"
+
+
+def test_item_bigint_property():
+    item = Item()
+    small, big = 42, 2 ** 65
+    item.atime = small
+    assert item.atime == small
+    assert item.as_dict() == {'atime': small}
+    item.atime = big
+    assert item.atime == big
+    assert item.as_dict() == {'atime': b'\0' * 8 + b'\x02'}
+
+
+def test_item_user_group_none():
+    item = Item()
+    item.user = None
+    assert item.user is None
+    item.group = None
+    assert item.group is None
+
+
+def test_item_se_str_property():
+    # start simple
+    item = Item()
+    item.path = '/a/b/c'
+    assert item.path == '/a/b/c'
+    assert item.as_dict() == {'path': b'/a/b/c'}
+    del item.path
+    assert item.as_dict() == {}
+    with pytest.raises(TypeError):
+        item.path = 42
+
+    # non-utf-8 path, needing surrogate-escaping for latin-1 u-umlaut
+    item = Item({'path': b'/a/\xfc/c'})
+    assert item.path == '/a/\udcfc/c'  # getting a surrogate-escaped representation
+    assert item.as_dict() == {'path': b'/a/\xfc/c'}
+    del item.path
+    assert 'path' not in item
+    item.path = '/a/\udcfc/c'  # setting using a surrogate-escaped representation
+    assert item.as_dict() == {'path': b'/a/\xfc/c'}
+
+
+def test_item_list_property():
+    item = Item()
+    item.chunks = []
+    assert item.chunks == []
+    item.chunks.append(0)
+    assert item.chunks == [0]
+    item.chunks.append(1)
+    assert item.chunks == [0, 1]
+    assert item.as_dict() == {'chunks': [0, 1]}
+
+
+def test_item_dict_property():
+    item = Item()
+    item.xattrs = StableDict()
+    assert item.xattrs == StableDict()
+    item.xattrs['foo'] = 'bar'
+    assert item.xattrs['foo'] == 'bar'
+    item.xattrs['bar'] = 'baz'
+    assert item.xattrs == StableDict({'foo': 'bar', 'bar': 'baz'})
+    assert item.as_dict() == {'xattrs': {'foo': 'bar', 'bar': 'baz'}}
+
+
+def test_unknown_property():
+    # we do not want the user to be able to set unknown attributes -
+    # they won't get into the .as_dict() result dictionary.
+    # also they might be just typos of known attributes.
+    item = Item()
+    with pytest.raises(AttributeError):
+        item.unknown_attribute = None

src/borg/testsuite/key.py

@@ -1,17 +1,24 @@
+import getpass
 import os
 import re
 import shutil
 import tempfile
 from binascii import hexlify, unhexlify
 
+import pytest
+
 from ..crypto import bytes_to_long, num_aes_blocks
-from ..key import PlaintextKey, PassphraseKey, KeyfileKey
-from ..helpers import Location, Chunk, bin_to_hex
-from . import BaseTestCase, environment_variable
+from ..key import PlaintextKey, PassphraseKey, KeyfileKey, Passphrase, PasswordRetriesExceeded, bin_to_hex
+from ..helpers import Location, Chunk, IntegrityError
+
 
+@pytest.fixture(autouse=True)
+def clean_env(monkeypatch):
+    # Workaround for some tests (testsuite/archiver) polluting the environment
+    monkeypatch.delenv('BORG_PASSPHRASE', False)
 
-class KeyTestCase(BaseTestCase):
 
+class TestKey:
     class MockArgs:
         location = Location(tempfile.mkstemp()[1])
 
@@ -31,14 +38,10 @@ class KeyTestCase(BaseTestCase):
         """))
     keyfile2_id = unhexlify('c3fbf14bc001ebcc3cd86e696c13482ed071740927cd7cbe1b01b4bfcee49314')
 
-    def setUp(self):
-        self.tmppath = tempfile.mkdtemp()
-        os.environ['BORG_KEYS_DIR'] = self.tmppath
-        self.tmppath2 = tempfile.mkdtemp()
-
-    def tearDown(self):
-        shutil.rmtree(self.tmppath)
-        shutil.rmtree(self.tmppath2)
+    @pytest.fixture
+    def keys_dir(self, request, monkeypatch, tmpdir):
+        monkeypatch.setenv('BORG_KEYS_DIR', tmpdir)
+        return tmpdir
 
     class MockRepository:
         class _Location:
@@ -51,78 +54,144 @@ class KeyTestCase(BaseTestCase):
     def test_plaintext(self):
         key = PlaintextKey.create(None, None)
         chunk = Chunk(b'foo')
-        self.assert_equal(hexlify(key.id_hash(chunk.data)), b'2c26b46b68ffc68ff99b453c1d30413413422d706483bfa0f98a5e886266e7ae')
-        self.assert_equal(chunk, key.decrypt(key.id_hash(chunk.data), key.encrypt(chunk)))
+        assert hexlify(key.id_hash(chunk.data)) == b'2c26b46b68ffc68ff99b453c1d30413413422d706483bfa0f98a5e886266e7ae'
+        assert chunk == key.decrypt(key.id_hash(chunk.data), key.encrypt(chunk))
 
-    def test_keyfile(self):
-        os.environ['BORG_PASSPHRASE'] = 'test'
+    def test_keyfile(self, monkeypatch, keys_dir):
+        monkeypatch.setenv('BORG_PASSPHRASE', 'test')
         key = KeyfileKey.create(self.MockRepository(), self.MockArgs())
-        self.assert_equal(bytes_to_long(key.enc_cipher.iv, 8), 0)
+        assert bytes_to_long(key.enc_cipher.iv, 8) == 0
         manifest = key.encrypt(Chunk(b'XXX'))
-        self.assert_equal(key.extract_nonce(manifest), 0)
+        assert key.extract_nonce(manifest) == 0
         manifest2 = key.encrypt(Chunk(b'XXX'))
-        self.assert_not_equal(manifest, manifest2)
-        self.assert_equal(key.decrypt(None, manifest), key.decrypt(None, manifest2))
-        self.assert_equal(key.extract_nonce(manifest2), 1)
+        assert manifest != manifest2
+        assert key.decrypt(None, manifest) == key.decrypt(None, manifest2)
+        assert key.extract_nonce(manifest2) == 1
         iv = key.extract_nonce(manifest)
         key2 = KeyfileKey.detect(self.MockRepository(), manifest)
-        self.assert_equal(bytes_to_long(key2.enc_cipher.iv, 8), iv + num_aes_blocks(len(manifest) - KeyfileKey.PAYLOAD_OVERHEAD))
+        assert bytes_to_long(key2.enc_cipher.iv, 8) == iv + num_aes_blocks(len(manifest) - KeyfileKey.PAYLOAD_OVERHEAD)
         # Key data sanity check
-        self.assert_equal(len(set([key2.id_key, key2.enc_key, key2.enc_hmac_key])), 3)
-        self.assert_equal(key2.chunk_seed == 0, False)
+        assert len({key2.id_key, key2.enc_key, key2.enc_hmac_key}) == 3
+        assert key2.chunk_seed != 0
         chunk = Chunk(b'foo')
-        self.assert_equal(chunk, key2.decrypt(key.id_hash(chunk.data), key.encrypt(chunk)))
-
-    def test_keyfile_kfenv(self):
-        keyfile = os.path.join(self.tmppath2, 'keyfile')
-        with environment_variable(BORG_KEY_FILE=keyfile, BORG_PASSPHRASE='testkf'):
-            assert not os.path.exists(keyfile)
-            key = KeyfileKey.create(self.MockRepository(), self.MockArgs())
-            assert os.path.exists(keyfile)
-            chunk = Chunk(b'XXX')
-            chunk_id = key.id_hash(chunk.data)
-            chunk_cdata = key.encrypt(chunk)
-            key = KeyfileKey.detect(self.MockRepository(), chunk_cdata)
-            self.assert_equal(chunk, key.decrypt(chunk_id, chunk_cdata))
-            os.unlink(keyfile)
-            self.assert_raises(FileNotFoundError, KeyfileKey.detect, self.MockRepository(), chunk_cdata)
-
-    def test_keyfile2(self):
-        with open(os.path.join(os.environ['BORG_KEYS_DIR'], 'keyfile'), 'w') as fd:
+        assert chunk == key2.decrypt(key.id_hash(chunk.data), key.encrypt(chunk))
+
+    def test_keyfile_kfenv(self, tmpdir, monkeypatch):
+        keyfile = tmpdir.join('keyfile')
+        monkeypatch.setenv('BORG_KEY_FILE', str(keyfile))
+        monkeypatch.setenv('BORG_PASSPHRASE', 'testkf')
+        assert not keyfile.exists()
+        key = KeyfileKey.create(self.MockRepository(), self.MockArgs())
+        assert keyfile.exists()
+        chunk = Chunk(b'XXX')
+        chunk_id = key.id_hash(chunk.data)
+        chunk_cdata = key.encrypt(chunk)
+        key = KeyfileKey.detect(self.MockRepository(), chunk_cdata)
+        assert chunk == key.decrypt(chunk_id, chunk_cdata)
+        keyfile.remove()
+        with pytest.raises(FileNotFoundError):
+            KeyfileKey.detect(self.MockRepository(), chunk_cdata)
+
+    def test_keyfile2(self, monkeypatch, keys_dir):
+        with keys_dir.join('keyfile').open('w') as fd:
             fd.write(self.keyfile2_key_file)
-        os.environ['BORG_PASSPHRASE'] = 'passphrase'
+        monkeypatch.setenv('BORG_PASSPHRASE', 'passphrase')
         key = KeyfileKey.detect(self.MockRepository(), self.keyfile2_cdata)
-        self.assert_equal(key.decrypt(self.keyfile2_id, self.keyfile2_cdata).data, b'payload')
+        assert key.decrypt(self.keyfile2_id, self.keyfile2_cdata).data == b'payload'
 
-    def test_keyfile2_kfenv(self):
-        keyfile = os.path.join(self.tmppath2, 'keyfile')
-        with open(keyfile, 'w') as fd:
+    def test_keyfile2_kfenv(self, tmpdir, monkeypatch):
+        keyfile = tmpdir.join('keyfile')
+        with keyfile.open('w') as fd:
             fd.write(self.keyfile2_key_file)
-        with environment_variable(BORG_KEY_FILE=keyfile, BORG_PASSPHRASE='passphrase'):
-            key = KeyfileKey.detect(self.MockRepository(), self.keyfile2_cdata)
-            self.assert_equal(key.decrypt(self.keyfile2_id, self.keyfile2_cdata).data, b'payload')
+        monkeypatch.setenv('BORG_KEY_FILE', str(keyfile))
+        monkeypatch.setenv('BORG_PASSPHRASE', 'passphrase')
+        key = KeyfileKey.detect(self.MockRepository(), self.keyfile2_cdata)
+        assert key.decrypt(self.keyfile2_id, self.keyfile2_cdata).data == b'payload'
 
-    def test_passphrase(self):
-        os.environ['BORG_PASSPHRASE'] = 'test'
+    def test_passphrase(self, keys_dir, monkeypatch):
+        monkeypatch.setenv('BORG_PASSPHRASE', 'test')
         key = PassphraseKey.create(self.MockRepository(), None)
-        self.assert_equal(bytes_to_long(key.enc_cipher.iv, 8), 0)
-        self.assert_equal(hexlify(key.id_key), b'793b0717f9d8fb01c751a487e9b827897ceea62409870600013fbc6b4d8d7ca6')
-        self.assert_equal(hexlify(key.enc_hmac_key), b'b885a05d329a086627412a6142aaeb9f6c54ab7950f996dd65587251f6bc0901')
-        self.assert_equal(hexlify(key.enc_key), b'2ff3654c6daf7381dbbe718d2b20b4f1ea1e34caa6cc65f6bb3ac376b93fed2a')
-        self.assert_equal(key.chunk_seed, -775740477)
+        assert bytes_to_long(key.enc_cipher.iv, 8) == 0
+        assert hexlify(key.id_key) == b'793b0717f9d8fb01c751a487e9b827897ceea62409870600013fbc6b4d8d7ca6'
+        assert hexlify(key.enc_hmac_key) == b'b885a05d329a086627412a6142aaeb9f6c54ab7950f996dd65587251f6bc0901'
+        assert hexlify(key.enc_key) == b'2ff3654c6daf7381dbbe718d2b20b4f1ea1e34caa6cc65f6bb3ac376b93fed2a'
+        assert key.chunk_seed == -775740477
         manifest = key.encrypt(Chunk(b'XXX'))
-        self.assert_equal(key.extract_nonce(manifest), 0)
+        assert key.extract_nonce(manifest) == 0
         manifest2 = key.encrypt(Chunk(b'XXX'))
-        self.assert_not_equal(manifest, manifest2)
-        self.assert_equal(key.decrypt(None, manifest), key.decrypt(None, manifest2))
-        self.assert_equal(key.extract_nonce(manifest2), 1)
+        assert manifest != manifest2
+        assert key.decrypt(None, manifest) == key.decrypt(None, manifest2)
+        assert key.extract_nonce(manifest2) == 1
         iv = key.extract_nonce(manifest)
         key2 = PassphraseKey.detect(self.MockRepository(), manifest)
-        self.assert_equal(bytes_to_long(key2.enc_cipher.iv, 8), iv + num_aes_blocks(len(manifest) - PassphraseKey.PAYLOAD_OVERHEAD))
-        self.assert_equal(key.id_key, key2.id_key)
-        self.assert_equal(key.enc_hmac_key, key2.enc_hmac_key)
-        self.assert_equal(key.enc_key, key2.enc_key)
-        self.assert_equal(key.chunk_seed, key2.chunk_seed)
+        assert bytes_to_long(key2.enc_cipher.iv, 8) == iv + num_aes_blocks(len(manifest) - PassphraseKey.PAYLOAD_OVERHEAD)
+        assert key.id_key == key2.id_key
+        assert key.enc_hmac_key == key2.enc_hmac_key
+        assert key.enc_key == key2.enc_key
+        assert key.chunk_seed == key2.chunk_seed
         chunk = Chunk(b'foo')
-        self.assert_equal(hexlify(key.id_hash(chunk.data)), b'818217cf07d37efad3860766dcdf1d21e401650fed2d76ed1d797d3aae925990')
-        self.assert_equal(chunk, key2.decrypt(key2.id_hash(chunk.data), key.encrypt(chunk)))
+        assert hexlify(key.id_hash(chunk.data)) == b'818217cf07d37efad3860766dcdf1d21e401650fed2d76ed1d797d3aae925990'
+        assert chunk == key2.decrypt(key2.id_hash(chunk.data), key.encrypt(chunk))
+
+    def _corrupt_byte(self, key, data, offset):
+        data = bytearray(data)
+        data[offset] += 1
+        with pytest.raises(IntegrityError):
+            key.decrypt("", data)
+
+    def test_decrypt_integrity(self, monkeypatch, keys_dir):
+        with keys_dir.join('keyfile').open('w') as fd:
+            fd.write(self.keyfile2_key_file)
+        monkeypatch.setenv('BORG_PASSPHRASE', 'passphrase')
+        key = KeyfileKey.detect(self.MockRepository(), self.keyfile2_cdata)
+
+        data = self.keyfile2_cdata
+        for i in range(len(data)):
+            self._corrupt_byte(key, data, i)
+
+        with pytest.raises(IntegrityError):
+            data = bytearray(self.keyfile2_cdata)
+            id = bytearray(key.id_hash(data))  # corrupt chunk id
+            id[12] = 0
+            key.decrypt(id, data)
+
+
+class TestPassphrase:
+    def test_passphrase_new_verification(self, capsys, monkeypatch):
+        monkeypatch.setattr(getpass, 'getpass', lambda prompt: "12aöäü")
+        monkeypatch.setenv('BORG_DISPLAY_PASSPHRASE', 'no')
+        Passphrase.new()
+        out, err = capsys.readouterr()
+        assert "12" not in out
+        assert "12" not in err
+
+        monkeypatch.setenv('BORG_DISPLAY_PASSPHRASE', 'yes')
+        passphrase = Passphrase.new()
+        out, err = capsys.readouterr()
+        assert "313261c3b6c3a4c3bc" not in out
+        assert "313261c3b6c3a4c3bc" in err
+        assert passphrase == "12aöäü"
+
+        monkeypatch.setattr(getpass, 'getpass', lambda prompt: "1234/@=")
+        Passphrase.new()
+        out, err = capsys.readouterr()
+        assert "1234/@=" not in out
+        assert "1234/@=" in err
+
+    def test_passphrase_new_empty(self, capsys, monkeypatch):
+        monkeypatch.delenv('BORG_PASSPHRASE', False)
+        monkeypatch.setattr(getpass, 'getpass', lambda prompt: "")
+        with pytest.raises(PasswordRetriesExceeded):
+            Passphrase.new(allow_empty=False)
+        out, err = capsys.readouterr()
+        assert "must not be blank" in err
+
+    def test_passphrase_new_retries(self, monkeypatch):
+        monkeypatch.delenv('BORG_PASSPHRASE', False)
+        ascending_numbers = iter(range(20))
+        monkeypatch.setattr(getpass, 'getpass', lambda prompt: str(next(ascending_numbers)))
+        with pytest.raises(PasswordRetriesExceeded):
+            Passphrase.new()
+
+    def test_passphrase_repr(self):
+        assert "secret" not in repr(Passphrase("secret"))

src/borg/testsuite/platform.py

@@ -4,7 +4,7 @@ import sys
 import tempfile
 import unittest
 
-from ..platform import acl_get, acl_set
+from ..platform import acl_get, acl_set, swidth
 from . import BaseTestCase
 
 
@@ -138,3 +138,16 @@ class PlatformDarwinTestCase(BaseTestCase):
         self.set_acl(file2.name, b'!#acl 1\ngroup:ABCDEFAB-CDEF-ABCD-EFAB-CDEF00000000:staff:0:allow:read\nuser:FFFFEEEE-DDDD-CCCC-BBBB-AAAA00000000:root:0:allow:read\n', numeric_owner=True)
         self.assert_in(b'group:ABCDEFAB-CDEF-ABCD-EFAB-CDEF00000000:wheel:0:allow:read', self.get_acl(file2.name)[b'acl_extended'])
         self.assert_in(b'group:ABCDEFAB-CDEF-ABCD-EFAB-CDEF00000000::0:allow:read', self.get_acl(file2.name, numeric_owner=True)[b'acl_extended'])
+
+
+@unittest.skipUnless(sys.platform.startswith(('linux', 'freebsd', 'darwin')), 'POSIX only tests')
+class PlatformPosixTestCase(BaseTestCase):
+
+    def test_swidth_ascii(self):
+        self.assert_equal(swidth("borg"), 4)
+
+    def test_swidth_cjk(self):
+        self.assert_equal(swidth("バックアップ"), 6 * 2)
+
+    def test_swidth_mixed(self):
+        self.assert_equal(swidth("borgバックアップ"), 4 + 6 * 2)

src/borg/testsuite/repository.py

@@ -1,3 +1,5 @@
+import io
+import logging
 import os
 import shutil
 import sys
@@ -7,8 +9,8 @@ from unittest.mock import patch
 from ..hashindex import NSIndex
 from ..helpers import Location, IntegrityError
 from ..locking import UpgradableLock, LockFailed
-from ..remote import RemoteRepository, InvalidRPCMethod
-from ..repository import Repository
+from ..remote import RemoteRepository, InvalidRPCMethod, ConnectionClosedWithHint
+from ..repository import Repository, LoggedIO
 from . import BaseTestCase
 
 
@@ -192,6 +194,13 @@ class RepositoryCommitTestCase(RepositoryTestCaseBase):
             self.assert_equal(self.repository.check(), True)
             self.assert_equal(len(self.repository), 3)
 
+    def test_ignores_commit_tag_in_data(self):
+        self.repository.put(b'0' * 32, LoggedIO.COMMIT)
+        self.reopen()
+        with self.repository:
+            io = self.repository.io
+            assert not io.is_committed_segment(io.get_latest_segment())
+
 
 class RepositoryAppendOnlyTestCase(RepositoryTestCaseBase):
     def test_destroy_append_only(self):
@@ -268,7 +277,7 @@ class RepositoryCheckTestCase(RepositoryTestCaseBase):
         return set(int(key) for key in self.repository.list())
 
     def test_repair_corrupted_segment(self):
-        self.add_objects([[1, 2, 3], [4, 5, 6]])
+        self.add_objects([[1, 2, 3], [4, 5], [6]])
         self.assert_equal(set([1, 2, 3, 4, 5, 6]), self.list_objects())
         self.check(status=True)
         self.corrupt_object(5)
@@ -389,3 +398,83 @@ class RemoteRepositoryCheckTestCase(RepositoryCheckTestCase):
     def test_crash_before_compact(self):
         # skip this test, we can't mock-patch a Repository class in another process!
         pass
+
+
+class RemoteRepositoryLoggingStub(RemoteRepository):
+    """ run a remote command that just prints a logging-formatted message to
+    stderr, and stub out enough of RemoteRepository to avoid the resulting
+    exceptions """
+    def __init__(self, *args, **kw):
+        self.msg = kw.pop('msg')
+        super().__init__(*args, **kw)
+
+    def borg_cmd(self, cmd, testing):
+        return [sys.executable, '-c', 'import sys; print("{}", file=sys.stderr)'.format(self.msg), ]
+
+    def __del__(self):
+        # clean up from exception without triggering assert
+        if self.p:
+            self.close()
+
+
+class RemoteRepositoryLoggerTestCase(RepositoryTestCaseBase):
+    def setUp(self):
+        self.location = Location('__testsuite__:/doesntexist/repo')
+        self.stream = io.StringIO()
+        self.handler = logging.StreamHandler(self.stream)
+        logging.getLogger().handlers[:] = [self.handler]
+        logging.getLogger('borg.repository').handlers[:] = []
+        logging.getLogger('borg.repository.foo').handlers[:] = []
+
+    def tearDown(self):
+        pass
+
+    def create_repository(self, msg):
+        try:
+            RemoteRepositoryLoggingStub(self.location, msg=msg)
+        except ConnectionClosedWithHint:
+            # stub is dumb, so this exception expected
+            pass
+
+    def test_old_format_messages(self):
+        self.handler.setLevel(logging.DEBUG)
+        logging.getLogger().setLevel(logging.DEBUG)
+
+        self.create_repository("$LOG INFO Remote: old format message")
+        self.assert_equal(self.stream.getvalue(), 'Remote: old format message\n')
+
+    def test_new_format_messages(self):
+        self.handler.setLevel(logging.DEBUG)
+        logging.getLogger().setLevel(logging.DEBUG)
+
+        self.create_repository("$LOG INFO borg.repository Remote: new format message")
+        self.assert_equal(self.stream.getvalue(), 'Remote: new format message\n')
+
+    def test_remote_messages_screened(self):
+        # default borg config for root logger
+        self.handler.setLevel(logging.WARNING)
+        logging.getLogger().setLevel(logging.WARNING)
+
+        self.create_repository("$LOG INFO borg.repository Remote: new format info message")
+        self.assert_equal(self.stream.getvalue(), '')
+
+    def test_info_to_correct_local_child(self):
+        logging.getLogger('borg.repository').setLevel(logging.INFO)
+        logging.getLogger('borg.repository.foo').setLevel(logging.INFO)
+        # default borg config for root logger
+        self.handler.setLevel(logging.WARNING)
+        logging.getLogger().setLevel(logging.WARNING)
+
+        child_stream = io.StringIO()
+        child_handler = logging.StreamHandler(child_stream)
+        child_handler.setLevel(logging.INFO)
+        logging.getLogger('borg.repository').handlers[:] = [child_handler]
+        foo_stream = io.StringIO()
+        foo_handler = logging.StreamHandler(foo_stream)
+        foo_handler.setLevel(logging.INFO)
+        logging.getLogger('borg.repository.foo').handlers[:] = [foo_handler]
+
+        self.create_repository("$LOG INFO borg.repository Remote: new format child message")
+        self.assert_equal(foo_stream.getvalue(), '')
+        self.assert_equal(child_stream.getvalue(), 'Remote: new format child message\n')
+        self.assert_equal(self.stream.getvalue(), '')