Repository: borgbackup/borg

Issue:
Decouple SecurityManager and Cache and always check with SecurityManager
Currently SecurityManager is only queried if the Cache is used, which elides checks for various commands, e.g. list, key management, extract, mount, ...

The debug commands may be excluded.

Discussion:
codecov-io: # [Codecov](https://codecov.io/gh/borgbackup/borg/pull/2500?src=pr&el=h1) Report
> Merging [#2500](https://codecov.io/gh/borgbackup/borg/pull/2500?src=pr&el=desc) into [master](https://codecov.io/gh/borgbackup/borg/commit/6cd7d415ca501284a12bbb1462b562f453b3205d?src=pr&el=desc) will **increase** coverage by `0.08%`.
> The diff coverage is `91.04%`.

[![Impacted file tree graph](https://codecov.io/gh/borgbackup/borg/pull/2500/graphs/tree.svg?token=LssEpmW3o4&src=pr&height=150&width=650)](https://codecov.io/gh/borgbackup/borg/pull/2500?src=pr&el=tree)

```diff
@@            Coverage Diff             @@
##           master    #2500      +/-   ##
==========================================
+ Coverage   83.24%   83.32%   +0.08%     
==========================================
  Files          21       21              
  Lines        7573     7628      +55     
  Branches     1288     1297       +9     
==========================================
+ Hits         6304     6356      +52     
- Misses        914      915       +1     
- Partials      355      357       +2
```


| [Impacted Files](https://codecov.io/gh/borgbackup/borg/pull/2500?src=pr&el=tree) | Coverage Δ | |
|---|---|---|
| [src/borg/archiver.py](https://codecov.io/gh/borgbackup/borg/pull/2500?src=pr&el=tree#diff-c3JjL2JvcmcvYXJjaGl2ZXIucHk=) | `82.32% <75%> (-0.05%)` | :arrow_down: |
| [src/borg/cache.py](https://codecov.io/gh/borgbackup/borg/pull/2500?src=pr&el=tree#diff-c3JjL2JvcmcvY2FjaGUucHk=) | `86.69% <91.53%> (+0.46%)` | :arrow_up: |
| [src/borg/archive.py](https://codecov.io/gh/borgbackup/borg/pull/2500?src=pr&el=tree#diff-c3JjL2JvcmcvYXJjaGl2ZS5weQ==) | `81.58% <0%> (-0.16%)` | :arrow_down: |
| [src/borg/helpers.py](https://codecov.io/gh/borgbackup/borg/pull/2500?src=pr&el=tree#diff-c3JjL2JvcmcvaGVscGVycy5weQ==) | `87.44% <0%> (+0.08%)` | :arrow_up: |
| [src/borg/remote.py](https://codecov.io/gh/borgbackup/borg/pull/2500?src=pr&el=tree#diff-c3JjL2JvcmcvcmVtb3RlLnB5) | `77.34% <0%> (+0.2%)` | :arrow_up: |
| [src/borg/locking.py](https://codecov.io/gh/borgbackup/borg/pull/2500?src=pr&el=tree#diff-c3JjL2JvcmcvbG9ja2luZy5weQ==) | `88.46% <0%> (+1.28%)` | :arrow_up: |

------

[Continue to review full report at Codecov](https://codecov.io/gh/borgbackup/borg/pull/2500?src=pr&el=continue).
> **Legend** - [Click here to learn more](https://docs.codecov.io/docs/codecov-delta)
> `Δ = absolute <relative> (impact)`, `ø = not affected`, `? = missing data`
> Powered by [Codecov](https://codecov.io/gh/borgbackup/borg/pull/2500?src=pr&el=footer). Last update [6cd7d41...6c93c41](https://codecov.io/gh/borgbackup/borg/pull/2500?src=pr&el=lastupdated). Read the [comment docs](https://docs.codecov.io/docs/pull-request-comments).


Patch:
diff --git a/src/borg/archiver.py b/src/borg/archiver.py
index 9946dd47..601c9848 100644
--- a/src/borg/archiver.py
+++ b/src/borg/archiver.py
@@ -36,7 +36,7 @@
 from .algorithms.crc32 import crc32
 from .archive import Archive, ArchiveChecker, ArchiveRecreater, Statistics, is_special
 from .archive import BackupOSError, backup_io
-from .cache import Cache
+from .cache import Cache, assert_secure
 from .constants import *  # NOQA
 from .compress import CompressionSpec
 from .crypto.key import key_creator, tam_required_file, tam_required, RepoKey, PassphraseKey
@@ -86,7 +86,8 @@ def argument(args, str_or_bool):
     return str_or_bool
 
 
-def with_repository(fake=False, invert_fake=False, create=False, lock=True, exclusive=False, manifest=True, cache=False):
+def with_repository(fake=False, invert_fake=False, create=False, lock=True, exclusive=False, manifest=True, cache=False,
+                    secure=True):
     """
     Method decorator for subcommand-handling methods: do_XYZ(self, args, repository, …)
 
@@ -97,6 +98,7 @@ def with_repository(fake=False, invert_fake=False, create=False, lock=True, excl
     :param exclusive: (str or bool) lock repository exclusively (for writing)
     :param manifest: load manifest and key, pass them as keyword arguments
     :param cache: open cache, pass it as keyword argument (implies manifest)
+    :param secure: do assert_secure after loading manifest
     """
     def decorator(method):
         @functools.wraps(method)
@@ -117,6 +119,8 @@ def wrapper(self, args, **kwargs):
                     kwargs['manifest'], kwargs['key'] = Manifest.load(repository)
                     if 'compression' in args:
                         kwargs['key'].compressor = args.compression.compressor
+                    if secure:
+                        assert_secure(repository, kwargs['manifest'])
                 if cache:
                     with Cache(repository, kwargs['key'], kwargs['manifest'],
                                do_files=getattr(args, 'cache_files', False),
@@ -3815,15 +3819,15 @@ 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',
-        }
+                '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():
-            option_set = args.get(option, False)
-            logging.getLogger(logger_name).setLevel('INFO' if option_set else 'WARN')
+            if args.get(option, False):
+                logging.getLogger(logger_name).setLevel('INFO')
 
     def _setup_topic_debugging(self, args):
         """Turn on DEBUG level logging for specified --debug-topics."""
@@ -3839,10 +3843,8 @@ def run(self, args):
         # This works around http://bugs.python.org/issue9351
         func = getattr(args, 'func', None) or getattr(args, 'fallback_func')
         # do not use loggers before this!
-        is_serve = func == self.do_serve
-        setup_logging(level=args.log_level, is_serve=is_serve, json=args.log_json)
+        setup_logging(level=args.log_level, is_serve=func == self.do_serve, json=args.log_json)
         self.log_json = args.log_json
-        args.progress |= is_serve
         self._setup_implied_logging(vars(args))
         self._setup_topic_debugging(args)
         if args.show_version:
diff --git a/src/borg/cache.py b/src/borg/cache.py
index 40ed925a..882d9863 100644
--- a/src/borg/cache.py
+++ b/src/borg/cache.py
@@ -32,9 +32,29 @@
 
 
 class SecurityManager:
+    """
+    Tracks repositories. Ensures that nothing bad happens (repository swaps,
+    replay attacks, unknown repositories etc.).
+
+    This is complicated by the Cache being initially used for this, while
+    only some commands actually use the Cache, which meant that other commands
+    did not perform these checks.
+
+    Further complications were created by the Cache being a cache, so it
+    could be legitimately deleted, which is annoying because Borg didn't
+    recognize repositories after that.
+
+    Therefore a second location, the security database (see get_security_dir),
+    was introduced which stores this information. However, this means that
+    the code has to deal with a cache existing but no security DB entry,
+    or inconsistencies between the security DB and the cache which have to
+    be reconciled, and also with no cache existing but a security DB entry.
+    """
+
     def __init__(self, repository):
         self.repository = repository
         self.dir = get_security_dir(repository.id_str)
+        self.cache_dir = cache_dir(repository)
         self.key_type_file = os.path.join(self.dir, 'key-type')
         self.location_file = os.path.join(self.dir, 'location')
         self.manifest_ts_file = os.path.join(self.dir, 'manifest-timestamp')
@@ -52,9 +72,9 @@ def key_matches(self, key):
         except OSError as exc:
             logger.warning('Could not read/parse key type file: %s', exc)
 
-    def save(self, manifest, key, cache):
+    def save(self, manifest, key):
         logger.debug('security: saving state for %s to %s', self.repository.id_str, self.dir)
-        current_location = cache.repository._location.canonical_path()
+        current_location = self.repository._location.canonical_path()
         logger.debug('security: current location   %s', current_location)
         logger.debug('security: key type           %s', str(key.TYPE))
         logger.debug('security: manifest timestamp %s', manifest.timestamp)
@@ -65,25 +85,27 @@ def save(self, manifest, key, cache):
         with open(self.manifest_ts_file, 'w') as fd:
             fd.write(manifest.timestamp)
 
-    def assert_location_matches(self, cache):
+    def assert_location_matches(self, cache_config=None):
         # Warn user before sending data to a relocated repository
         try:
             with open(self.location_file) as fd:
                 previous_location = fd.read()
-            logger.debug('security: read previous_location %r', previous_location)
+            logger.debug('security: read previous location %r', previous_location)
         except FileNotFoundError:
-            logger.debug('security: previous_location file %s not found', self.location_file)
+            logger.debug('security: previous location file %s not found', self.location_file)
             previous_location = None
         except OSError as exc:
             logger.warning('Could not read previous location file: %s', exc)
             previous_location = None
-        if cache.previous_location and previous_location != cache.previous_location:
+        if cache_config and cache_config.previous_location and previous_location != cache_config.previous_location:
             # Reconcile cache and security dir; we take the cache location.
-            previous_location = cache.previous_location
+            previous_location = cache_config.previous_location
             logger.debug('security: using previous_location of cache: %r', previous_location)
-        if previous_location and previous_location != self.repository._location.canonical_path():
+
+        repository_location = self.repository._location.canonical_path()
+        if previous_location and previous_location != repository_location:
             msg = ("Warning: The repository at location {} was previously located at {}\n".format(
-                self.repository._location.canonical_path(), previous_location) +
+                repository_location, previous_location) +
                 "Do you want to continue? [yN] ")
             if not yes(msg, false_msg="Aborting.", invalid_msg="Invalid answer, aborting.",
                        retry=False, env_var_override='BORG_RELOCATED_REPO_ACCESS_IS_OK'):
@@ -91,11 +113,11 @@ def assert_location_matches(self, cache):
             # adapt on-disk config immediately if the new location was accepted
             logger.debug('security: updating location stored in cache and security dir')
             with open(self.location_file, 'w') as fd:
-                fd.write(cache.repository._location.canonical_path())
-            cache.begin_txn()
-            cache.commit()
+                fd.write(repository_location)
+            if cache_config:
+                cache_config.save()
 
-    def assert_no_manifest_replay(self, manifest, key, cache):
+    def assert_no_manifest_replay(self, manifest, key, cache_config=None):
         try:
             with open(self.manifest_ts_file) as fd:
                 timestamp = fd.read()
@@ -106,7 +128,8 @@ def assert_no_manifest_replay(self, manifest, key, cache):
         except OSError as exc:
             logger.warning('Could not read previous location file: %s', exc)
             timestamp = ''
-        timestamp = max(timestamp, cache.timestamp or '')
+        if cache_config:
+            timestamp = max(timestamp, cache_config.timestamp or '')
         logger.debug('security: determined newest manifest timestamp as %s', timestamp)
         # If repository is older than the cache or security dir something fishy is going on
         if timestamp and timestamp > manifest.timestamp:
@@ -115,29 +138,155 @@ def assert_no_manifest_replay(self, manifest, key, cache):
             else:
                 raise Cache.RepositoryReplay()
 
-    def assert_key_type(self, key, cache):
+    def assert_key_type(self, key, cache_config=None):
         # Make sure an encrypted repository has not been swapped for an unencrypted repository
-        if cache.key_type is not None and cache.key_type != str(key.TYPE):
+        if cache_config and cache_config.key_type is not None and cache_config.key_type != str(key.TYPE):
             raise Cache.EncryptionMethodMismatch()
         if self.known() and not self.key_matches(key):
             raise Cache.EncryptionMethodMismatch()
 
-    def assert_secure(self, manifest, key, cache):
-        self.assert_location_matches(cache)
-        self.assert_key_type(key, cache)
-        self.assert_no_manifest_replay(manifest, key, cache)
+    def assert_secure(self, manifest, key, *, cache_config=None, warn_if_unencrypted=True):
+        # warn_if_unencrypted=False is only used for initializing a new repository.
+        # Thus, avoiding asking about a repository that's currently initializing.
+        self.assert_access_unknown(warn_if_unencrypted, manifest, key)
+        if cache_config:
+            self._assert_secure(manifest, key, cache_config)
+        else:
+            cache_config = CacheConfig(self.repository)
+            if cache_config.exists():
+                with cache_config:
+                    self._assert_secure(manifest, key, cache_config)
+            else:
+                self._assert_secure(manifest, key)
+        logger.debug('security: repository checks ok, allowing access')
+
+    def _assert_secure(self, manifest, key, cache_config=None):
+        self.assert_location_matches(cache_config)
+        self.assert_key_type(key, cache_config)
+        self.assert_no_manifest_replay(manifest, key, cache_config)
         if not self.known():
-            self.save(manifest, key, cache)
+            logger.debug('security: remembering previously unknown repository')
+            self.save(manifest, key)
 
-    def assert_access_unknown(self, warn_if_unencrypted, key):
-        if warn_if_unencrypted and not key.logically_encrypted and not self.known():
+    def assert_access_unknown(self, warn_if_unencrypted, manifest, key):
+        # warn_if_unencrypted=False is only used for initializing a new repository.
+        # Thus, avoiding asking about a repository that's currently initializing.
+        if not key.logically_encrypted and not self.known():
             msg = ("Warning: Attempting to access a previously unknown unencrypted repository!\n" +
                    "Do you want to continue? [yN] ")
-            if not yes(msg, false_msg="Aborting.", invalid_msg="Invalid answer, aborting.",
-                       retry=False, env_var_override='BORG_UNKNOWN_UNENCRYPTED_REPO_ACCESS_IS_OK'):
+            allow_access = not warn_if_unencrypted or yes(msg, false_msg="Aborting.",
+                invalid_msg="Invalid answer, aborting.",
+                retry=False, env_var_override='BORG_UNKNOWN_UNENCRYPTED_REPO_ACCESS_IS_OK')
+            if allow_access:
+                if warn_if_unencrypted:
+                    logger.debug('security: remembering unknown unencrypted repository (explicitly allowed)')
+                else:
+                    logger.debug('security: initializing unencrypted repository')
+                self.save(manifest, key)
+            else:
                 raise Cache.CacheInitAbortedError()
 
 
+def assert_secure(repository, manifest):
+    sm = SecurityManager(repository)
+    sm.assert_secure(manifest, manifest.key)
+
+
+def recanonicalize_relative_location(cache_location, repository):
+    # borg < 1.0.8rc1 had different canonicalization for the repo location (see #1655 and #1741).
+    repo_location = repository._location.canonical_path()
+    rl = Location(repo_location)
+    cl = Location(cache_location)
+    if cl.proto == rl.proto and cl.user == rl.user and cl.host == rl.host and cl.port == rl.port \
+            and \
+            cl.path and rl.path and \
+            cl.path.startswith('/~/') and rl.path.startswith('/./') and cl.path[3:] == rl.path[3:]:
+        # everything is same except the expected change in relative path canonicalization,
+        # update previous_location to avoid warning / user query about changed location:
+        return repo_location
+    else:
+        return cache_location
+
+
+def cache_dir(repository, path=None):
+    return path or os.path.join(get_cache_dir(), repository.id_str)
+
+
+class CacheConfig:
+    def __init__(self, repository, path=None, lock_wait=None):
+        self.repository = repository
+        self.path = cache_dir(repository, path)
+        self.config_path = os.path.join(self.path, 'config')
+        self.lock = None
+        self.lock_wait = lock_wait
+
+    def __enter__(self):
+        self.open()
+        return self
+
+    def __exit__(self, exc_type, exc_val, exc_tb):
+        self.close()
+
+    def exists(self):
+        return os.path.exists(self.config_path)
+
+    def create(self):
+        assert not self.exists()
+        config = configparser.ConfigParser(interpolation=None)
+        config.add_section('cache')
+        config.set('cache', 'version', '1')
+        config.set('cache', 'repository', self.repository.id_str)
+        config.set('cache', 'manifest', '')
+        with SaveFile(self.config_path) as fd:
+            config.write(fd)
+
+    def open(self):
+        self.lock = Lock(os.path.join(self.path, 'lock'), exclusive=True, timeout=self.lock_wait,
+                         kill_stale_locks=hostname_is_unique()).acquire()
+        self.load()
+
+    def load(self):
+        self._config = configparser.ConfigParser(interpolation=None)
+        self._config.read(self.config_path)
+        self._check_upgrade(self.config_path)
+        self.id = self._config.get('cache', 'repository')
+        self.manifest_id = unhexlify(self._config.get('cache', 'manifest'))
+        self.timestamp = self._config.get('cache', 'timestamp', fallback=None)
+        self.key_type = self._config.get('cache', 'key_type', fallback=None)
+        previous_location = self._config.get('cache', 'previous_location', fallback=None)
+        if previous_location:
+            self.previous_location = recanonicalize_relative_location(previous_location, self.repository)
+        else:
+            self.previous_location = None
+
+    def save(self, manifest=None, key=None):
+        if manifest:
+            self._config.set('cache', 'manifest', manifest.id_str)
+            self._config.set('cache', 'timestamp', manifest.timestamp)
+        if key:
+            self._config.set('cache', 'key_type', str(key.TYPE))
+        self._config.set('cache', 'previous_location', self.repository._location.canonical_path())
+        with SaveFile(self.config_path) as fd:
+            self._config.write(fd)
+
+    def close(self):
+        if self.lock is not None:
+            self.lock.release()
+            self.lock = None
+
+    def _check_upgrade(self, config_path):
+        try:
+            cache_version = self._config.getint('cache', 'version')
+            wanted_version = 1
+            if cache_version != wanted_version:
+                self.close()
+                raise Exception('%s has unexpected cache version %d (wanted: %d).' %
+                                (config_path, cache_version, wanted_version))
+        except configparser.NoSectionError:
+            self.close()
+            raise Exception('%s does not look like a Borg cache.' % config_path) from None
+
+
 class Cache:
     """Client Side cache
     """
@@ -158,7 +307,7 @@ class EncryptionMethodMismatch(Error):
 
     @staticmethod
     def break_lock(repository, path=None):
-        path = path or os.path.join(get_cache_dir(), repository.id_str)
+        path = cache_dir(repository, path)
         Lock(os.path.join(path, 'lock'), exclusive=True).break_lock()
 
     @staticmethod
@@ -178,25 +327,27 @@ def __init__(self, repository, key, manifest, path=None, sync=True, do_files=Fal
         :param lock_wait: timeout for lock acquisition (None: return immediately if lock unavailable)
         :param sync: do :meth:`.sync`
         """
-        self.lock = None
-        self.timestamp = None
-        self.lock = None
-        self.txn_active = False
         self.repository = repository
         self.key = key
         self.manifest = manifest
         self.progress = progress
-        self.path = path or os.path.join(get_cache_dir(), repository.id_str)
-        self.security_manager = SecurityManager(repository)
         self.do_files = do_files
+        self.timestamp = None
+        self.txn_active = False
+
+        self.path = cache_dir(repository, path)
+        self.security_manager = SecurityManager(repository)
+        self.cache_config = CacheConfig(self.repository, self.path, lock_wait)
+
         # Warn user before sending data to a never seen before unencrypted repository
         if not os.path.exists(self.path):
-            self.security_manager.assert_access_unknown(warn_if_unencrypted, key)
+            self.security_manager.assert_access_unknown(warn_if_unencrypted, manifest, key)
             self.create()
-        self.open(lock_wait=lock_wait)
+
+        self.open()
         try:
-            self.security_manager.assert_secure(manifest, key, self)
-            if sync and self.manifest.id != self.manifest_id:
+            self.security_manager.assert_secure(manifest, key, cache_config=self.cache_config)
+            if sync and self.manifest.id != self.cache_config.manifest_id:
                 self.sync()
                 self.commit()
         except:
@@ -240,66 +391,27 @@ def create(self):
         os.makedirs(self.path)
         with open(os.path.join(self.path, 'README'), 'w') as fd:
             fd.write(CACHE_README)
-        config = configparser.ConfigParser(interpolation=None)
-        config.add_section('cache')
-        config.set('cache', 'version', '1')
-        config.set('cache', 'repository', self.repository.id_str)
-        config.set('cache', 'manifest', '')
-        with SaveFile(os.path.join(self.path, 'config')) as fd:
-            config.write(fd)
+        self.cache_config.create()
         ChunkIndex().write(os.path.join(self.path, 'chunks').encode('utf-8'))
         os.makedirs(os.path.join(self.path, 'chunks.archive.d'))
         with SaveFile(os.path.join(self.path, 'files'), binary=True) as fd:
             pass  # empty file
 
-    def _check_upgrade(self, config_path):
-        try:
-            cache_version = self.config.getint('cache', 'version')
-            wanted_version = 1
-            if cache_version != wanted_version:
-                self.close()
-                raise Exception('%s has unexpected cache version %d (wanted: %d).' % (
-                    config_path, cache_version, wanted_version))
-        except configparser.NoSectionError:
-            self.close()
-            raise Exception('%s does not look like a Borg cache.' % config_path) from None
-        # borg < 1.0.8rc1 had different canonicalization for the repo location (see #1655 and #1741).
-        cache_loc = self.config.get('cache', 'previous_location', fallback=None)
-        if cache_loc:
-            repo_loc = self.repository._location.canonical_path()
-            rl = Location(repo_loc)
-            cl = Location(cache_loc)
-            if cl.proto == rl.proto and cl.user == rl.user and cl.host == rl.host and cl.port == rl.port \
-                    and \
-                    cl.path and rl.path and \
-                    cl.path.startswith('/~/') and rl.path.startswith('/./') and cl.path[3:] == rl.path[3:]:
-                # everything is same except the expected change in relative path canonicalization,
-                # update previous_location to avoid warning / user query about changed location:
-                self.config.set('cache', 'previous_location', repo_loc)
-
     def _do_open(self):
-        self.config = configparser.ConfigParser(interpolation=None)
-        config_path = os.path.join(self.path, 'config')
-        self.config.read(config_path)
-        self._check_upgrade(config_path)
-        self.id = self.config.get('cache', 'repository')
-        self.manifest_id = unhexlify(self.config.get('cache', 'manifest'))
-        self.timestamp = self.config.get('cache', 'timestamp', fallback=None)
-        self.key_type = self.config.get('cache', 'key_type', fallback=None)
-        self.previous_location = self.config.get('cache', 'previous_location', fallback=None)
+        self.cache_config.load()
         self.chunks = ChunkIndex.read(os.path.join(self.path, 'chunks').encode('utf-8'))
         self.files = None
 
-    def open(self, lock_wait=None):
+    def open(self):
         if not os.path.isdir(self.path):
             raise Exception('%s Does not look like a Borg cache' % self.path)
-        self.lock = Lock(os.path.join(self.path, 'lock'), exclusive=True, timeout=lock_wait, kill_stale_locks=hostname_is_unique()).acquire()
+        self.cache_config.open()
         self.rollback()
 
     def close(self):
-        if self.lock is not None:
-            self.lock.release()
-            self.lock = None
+        if self.cache_config is not None:
+            self.cache_config.close()
+            self.cache_config = None
 
     def _read_files(self):
         self.files = {}
@@ -338,7 +450,7 @@ def commit(self):
         """
         if not self.txn_active:
             return
-        self.security_manager.save(self.manifest, self.key, self)
+        self.security_manager.save(self.manifest, self.key)
         pi = ProgressIndicatorMessage(msgid='cache.commit')
         if self.files is not None:
             if self._newest_mtime is None:
@@ -356,12 +468,7 @@ def commit(self):
                        entry.age > 0 and entry.age < ttl:
                         msgpack.pack((path_hash, entry), fd)
         pi.output('Saving cache config')
-        self.config.set('cache', 'manifest', self.manifest.id_str)
-        self.config.set('cache', 'timestamp', self.manifest.timestamp)
-        self.config.set('cache', 'key_type', str(self.key.TYPE))
-        self.config.set('cache', 'previous_location', self.repository._location.canonical_path())
-        with SaveFile(os.path.join(self.path, 'config')) as fd:
-            self.config.write(fd)
+        self.cache_config.save(self.manifest, self.key)
         pi.output('Saving chunks cache')
         self.chunks.write(os.path.join(self.path, 'chunks').encode('utf-8'))
         os.rename(os.path.join(self.path, 'txn.active'),
diff --git a/src/borg/helpers.py b/src/borg/helpers.py
index a93ba710..ec06946e 100644
--- a/src/borg/helpers.py
+++ b/src/borg/helpers.py
@@ -1226,14 +1226,6 @@ def __init__(self, msgid=None):
             if self.logger.level == logging.NOTSET:
                 self.logger.setLevel(logging.WARN)
             self.logger.propagate = False
-
-        # If --progress is not set then the progress logger level will be WARN
-        # due to setup_implied_logging (it may be NOTSET with a logging config file,
-        # but the interactions there are generally unclear), so self.emit becomes
-        # False, which is correct.
-        # If --progress is set then the level will be INFO as per setup_implied_logging;
-        # note that this is always the case for serve processes due to a "args.progress |= is_serve".
-        # In this case self.emit is True.
         self.emit = self.logger.getEffectiveLevel() == logging.INFO
 
     def __del__(self):
diff --git a/src/borg/logger.py b/src/borg/logger.py
index 69cb86f1..6300776d 100644
--- a/src/borg/logger.py
+++ b/src/borg/logger.py
@@ -88,21 +88,15 @@ def setup_logging(stream=None, conf_fname=None, env_var='BORG_LOGGING_CONF', lev
     # if we did not / not successfully load a logging configuration, fallback to this:
     logger = logging.getLogger('')
     handler = logging.StreamHandler(stream)
-    if is_serve and not json:
+    if is_serve:
         fmt = '$LOG %(levelname)s %(name)s Remote: %(message)s'
     else:
         fmt = '%(message)s'
-    formatter = JsonFormatter(fmt) if json else logging.Formatter(fmt)
+    formatter = JsonFormatter(fmt) if json and not is_serve else logging.Formatter(fmt)
     handler.setFormatter(formatter)
     borg_logger = logging.getLogger('borg')
     borg_logger.formatter = formatter
     borg_logger.json = json
-    if configured and logger.handlers:
-        # The RepositoryServer can call setup_logging a second time to adjust the output
-        # mode from text-ish is_serve to json is_serve.
-        # Thus, remove the previously installed handler, if any.
-        logger.handlers[0].close()
-        logger.handlers.clear()
     logger.addHandler(handler)
     logger.setLevel(level.upper())
     configured = True
@@ -230,8 +224,6 @@ def format(self, record):
         data = {
             'type': 'log_message',
             'time': record.created,
-            'message': '',
-            'levelname': 'CRITICAL',
         }
         for attr in self.RECORD_ATTRIBUTES:
             value = getattr(record, attr, None)
diff --git a/src/borg/remote.py b/src/borg/remote.py
index 1a67930e..c32ba9e6 100644
--- a/src/borg/remote.py
+++ b/src/borg/remote.py
@@ -2,30 +2,29 @@
 import fcntl
 import functools
 import inspect
-import json
 import logging
 import os
 import select
 import shlex
 import sys
 import tempfile
+import traceback
 import textwrap
 import time
-import traceback
 from subprocess import Popen, PIPE
 
 import msgpack
 
 from . import __version__
 from .helpers import Error, IntegrityError
-from .helpers import bin_to_hex
 from .helpers import get_home_dir
-from .helpers import hostname_is_unique
-from .helpers import replace_placeholders
 from .helpers import sysinfo
-from .logger import create_logger, setup_logging
+from .helpers import bin_to_hex
+from .helpers import replace_placeholders
+from .helpers import hostname_is_unique
 from .repository import Repository, MAX_OBJECT_SIZE, LIST_SCAN_LIMIT
 from .version import parse_version, format_version
+from .logger import create_logger
 
 logger = create_logger(__name__)
 
@@ -313,10 +312,6 @@ def negotiate(self, client_data):
         # clients since 1.1.0b3 use a dict as client_data
         if isinstance(client_data, dict):
             self.client_version = client_data[b'client_version']
-            if client_data.get(b'client_supports_log_v3', False):
-                level = logging.getLevelName(logging.getLogger('').level)
-                setup_logging(is_serve=True, json=True, level=level)
-                logger.debug('Initialized logging system for new (v3) protocol')
         else:
             self.client_version = BORG_VERSION  # seems to be newer than current version (no known old format)
 
@@ -560,10 +555,7 @@ def __init__(self, location, create=False, exclusive=False, lock_wait=None, lock
 
         try:
             try:
-                version = self.call('negotiate', {'client_data': {
-                    b'client_version': BORG_VERSION,
-                    b'client_supports_log_v3': True,
-                }})
+                version = self.call('negotiate', {'client_data': {b'client_version': BORG_VERSION}})
             except ConnectionClosed:
                 raise ConnectionClosedWithHint('Is borg working on the server?') from None
             if version == RPC_PROTOCOL_VERSION:
@@ -654,23 +646,12 @@ def borg_cmd(self, args, testing):
                 opts.append('--critical')
             else:
                 raise ValueError('log level missing, fix this code')
-
-            # Tell the remote server about debug topics it may need to consider.
-            # Note that debug topics are usable for "spew" or "trace" logs which would
-            # be too plentiful to transfer for normal use, so the server doesn't send
-            # them unless explicitly enabled.
-            #
-            # Needless to say, if you do --debug-topic=repository.compaction, for example,
-            # with a 1.0.x server it won't work, because the server does not recognize the
-            # option.
-            #
-            # This is not considered a problem, since this is a debugging feature that
-            # should not be used for regular use.
-            for topic in args.debug_topics:
-                if '.' not in topic:
-                    topic = 'borg.debug.' + topic
-                if 'repository' in topic:
-                    opts.append('--debug-topic=%s' % topic)
+            try:
+                borg_logger = logging.getLogger('borg')
+                if borg_logger.json:
+                    opts.append('--log-json')
+            except AttributeError:
+                pass
         env_vars = []
         if not hostname_is_unique():
             env_vars.append('BORG_HOSTNAME_IS_UNIQUE=no')
@@ -949,63 +930,7 @@ def preload(self, ids):
 
 
 def handle_remote_line(line):
-    """
-    Handle a remote log line.
-
-    This function is remarkably complex because it handles multiple wire formats.
-    """
-    if line.startswith('{'):
-        # This format is used by Borg since 1.1.0b6 for new-protocol clients.
-        # It is the same format that is exposed by --log-json.
-        msg = json.loads(line)
-
-        if msg['type'] not in ('progress_message', 'progress_percent', 'log_message'):
-            logger.warning('Dropped remote log message with unknown type %r: %s', msg['type'], line)
-            return
-
-        if msg['type'] == 'log_message':
-            # Re-emit log messages on the same level as the remote to get correct log suppression and verbosity.
-            level = getattr(logging, msg['levelname'], logging.CRITICAL)
-            assert isinstance(level, int)
-            target_logger = logging.getLogger(msg['name'])
-            msg['message'] = 'Remote: ' + msg['message']
-            # In JSON mode, we manually check whether the log message should be propagated.
-            if logging.getLogger('borg').json and level >= target_logger.getEffectiveLevel():
-                sys.stderr.write(json.dumps(msg) + '\n')
-            else:
-                target_logger.log(level, '%s', msg['message'])
-        elif msg['type'].startswith('progress_'):
-            # Progress messages are a bit more complex.
-            # First of all, we check whether progress output is enabled. This is signalled
-            # through the effective level of the borg.output.progress logger
-            # (also see ProgressIndicatorBase in borg.helpers).
-            progress_logger = logging.getLogger('borg.output.progress')
-            if progress_logger.getEffectiveLevel() == logging.INFO:
-                # When progress output is enabled, we check whether the client is in
-                # --log-json mode, as signalled by the "json" attribute on the "borg" logger.
-                if logging.getLogger('borg').json:
-                    # In --log-json mode we re-emit the progress JSON line as sent by the server,
-                    # with the message, if any, prefixed with "Remote: ".
-                    if 'message' in msg:
-                        msg['message'] = 'Remote: ' + msg['message']
-                    sys.stderr.write(json.dumps(msg) + '\n')
-                elif 'message' in msg:
-                    # In text log mode we write only the message to stderr and terminate with \r
-                    # (carriage return, i.e. move the write cursor back to the beginning of the line)
-                    # so that the next message, progress or not, overwrites it. This mirrors the behaviour
-                    # of local progress displays.
-                    sys.stderr.write('Remote: ' + msg['message'] + '\r')
-    elif line.startswith('$LOG '):
-        # This format is used by Borg since 1.1.0b1.
-        # It prefixed log lines with $LOG as a marker, followed by the log level
-        # and optionally a logger name, then "Remote:" as a separator followed by the original
-        # message.
-        #
-        # It is the oldest format supported by these servers, so it was important to make
-        # it readable with older (1.0.x) clients.
-        #
-        # TODO: Remove this block (so it'll be handled by the "else:" below) with a Borg 1.1 RC.
-        #       Also check whether client_supports_log_v3 should be removed.
+    if line.startswith('$LOG '):
         _, level, msg = line.split(' ', 2)
         level = getattr(logging, level, logging.CRITICAL)  # str -> int
         if msg.startswith('Remote:'):
@@ -1016,15 +941,7 @@ def handle_remote_line(line):
             logname, msg = msg.split(' ', 1)
             logging.getLogger(logname).log(level, msg.rstrip())
     else:
-        # Plain 1.0.x and older format - re-emit to stderr (mirroring what the 1.0.x
-        # client did) or as a generic log message.
-        # We don't know what priority the line had.
-        if logging.getLogger('borg').json:
-            logging.getLogger('').warning('Remote: ' + line.strip())
-        else:
-            # In non-JSON mode we circumvent logging to preserve carriage returns (\r)
-            # which are generated by remote progress displays.
-            sys.stderr.write('Remote: ' + line)
+        sys.stderr.write('Remote: ' + line)
 
 
 class RepositoryNoCache:


Test patch:
diff --git a/src/borg/testsuite/archiver.py b/src/borg/testsuite/archiver.py
index 29460189..8f47b0b9 100644
--- a/src/borg/testsuite/archiver.py
+++ b/src/borg/testsuite/archiver.py
@@ -1709,7 +1709,7 @@ def test_common_options(self):
         self.create_test_files()
         self.cmd('init', '--encryption=repokey', self.repository_location)
         log = self.cmd('--debug', 'create', self.repository_location + '::test', 'input')
-        assert 'security: read previous_location' in log
+        assert 'security: read previous location' in log
 
     def _get_sizes(self, compression, compressible, size=10000):
         if compressible:
diff --git a/src/borg/testsuite/repository.py b/src/borg/testsuite/repository.py
index 16f47b91..2819c64c 100644
--- a/src/borg/testsuite/repository.py
+++ b/src/borg/testsuite/repository.py
@@ -714,7 +714,6 @@ def test_borg_cmd(self):
         class MockArgs:
             remote_path = 'borg'
             umask = 0o077
-            debug_topics = []
 
         assert self.repository.borg_cmd(None, testing=True) == [sys.executable, '-m', 'borg.archiver', 'serve']
         args = MockArgs()
@@ -724,9 +723,6 @@ class MockArgs:
         assert self.repository.borg_cmd(args, testing=False) == ['borg', 'serve', '--umask=077', '--info']
         args.remote_path = 'borg-0.28.2'
         assert self.repository.borg_cmd(args, testing=False) == ['borg-0.28.2', 'serve', '--umask=077', '--info']
-        args.debug_topics = ['something_client_side', 'repository_compaction']
-        assert self.repository.borg_cmd(args, testing=False) == ['borg-0.28.2', 'serve', '--umask=077', '--info',
-                                                                 '--debug-topic=borg.debug.repository_compaction']
 
 
 class RemoteLegacyFree(RepositoryTestCaseBase):