Update logging parser to allow remotes to pass logger name

Parser now understands both old format messages (to keep talking to
old server) and new format messages that pass a logger name.  If
logger name is passed, the message is directed to the same logger
locally.

This could be cherry-picked to 1.x-maint (and 0.x-maint?) to allow
point releases to understand borg 1.1 server messages changed in the
next commit.  Worst case, currently existing 0.x and 1.0.x clients
talking to a 1.1.x server will see messages like:
	borg.repository Remote: hi
	borg.archiver Remote: foo
instead of
	Remote: hi
	Remote: foo

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

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:

borg/testsuite/repository.py

@@ -1,3 +1,5 @@
+import io
+import logging
 import os
 import shutil
 import sys
@@ -7,7 +9,7 @@ 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 ..remote import RemoteRepository, InvalidRPCMethod, ConnectionClosedWithHint
 from ..repository import Repository
 from . import BaseTestCase
 
@@ -389,3 +391,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(), '')