From d42f1e691ae20307eb2dfc4383bce8efcba81bf4 Mon Sep 17 00:00:00 2001
From: Ed Blackman <ed@edgewood.to>
Date: Fri, 27 May 2016 17:16:31 -0400
Subject: [PATCH] Break out remote log and stderr handling code to simplify
testing
May fix issue 1081, but that issue is hard to reproduce.
---
borg/remote.py | 28 +++++++++++---------
borg/testsuite/repository.py | 51 ++++++++++++++----------------------
2 files changed, 36 insertions(+), 43 deletions(-)
diff --git a/borg/remote.py b/borg/remote.py
index 099026628..c3f439639 100644
--- a/borg/remote.py
+++ b/borg/remote.py
@@ -298,18 +298,7 @@ class RemoteRepository:
raise ConnectionClosed()
data = data.decode('utf-8')
for line in data.splitlines(keepends=True):
- if line.startswith('$LOG '):
- _, level, msg = line.split(' ', 2)
- level = getattr(logging, level, logging.CRITICAL) # str -> int
- 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)
+ handle_remote_line(line)
if w:
while not self.to_send and (calls or self.preload_ids) and len(waiting_for) < 100:
if calls:
@@ -394,6 +383,21 @@ class RemoteRepository:
self.preload_ids += ids
+def handle_remote_line(line):
+ if line.startswith('$LOG '):
+ _, level, msg = line.split(' ', 2)
+ level = getattr(logging, level, logging.CRITICAL) # str -> int
+ 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)
+
+
class RepositoryNoCache:
"""A not caching Repository wrapper, passes through to repository.
diff --git a/borg/testsuite/repository.py b/borg/testsuite/repository.py
index 85f4af457..df6f1372e 100644
--- a/borg/testsuite/repository.py
+++ b/borg/testsuite/repository.py
@@ -9,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, ConnectionClosedWithHint
+from ..remote import RemoteRepository, InvalidRPCMethod, ConnectionClosedWithHint, handle_remote_line
from ..repository import Repository, LoggedIO, MAGIC
from . import BaseTestCase
@@ -440,63 +440,51 @@ class RemoteRepositoryCheckTestCase(RepositoryCheckTestCase):
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):
+class RemoteLoggerTestCase(BaseTestCase):
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[:] = []
+ # capture stderr
+ sys.stderr.flush()
+ self.old_stderr = sys.stderr
+ self.stderr = sys.stderr = io.StringIO()
def tearDown(self):
- pass
+ sys.stderr = self.old_stderr
- def create_repository(self, msg):
- try:
- RemoteRepositoryLoggingStub(self.location, msg=msg)
- except ConnectionClosedWithHint:
- # stub is dumb, so this exception expected
- pass
+ def test_stderr_messages(self):
+ handle_remote_line("unstructured stderr message")
+ self.assert_equal(self.stream.getvalue(), '')
+ # stderr messages don't get an implicit newline
+ self.assert_equal(self.stderr.getvalue(), 'Remote: unstructured stderr message')
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")
+ handle_remote_line("$LOG INFO Remote: old format message")
self.assert_equal(self.stream.getvalue(), 'Remote: old format message\n')
+ self.assert_equal(self.stderr.getvalue(), '')
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")
+ handle_remote_line("$LOG INFO borg.repository Remote: new format message")
self.assert_equal(self.stream.getvalue(), 'Remote: new format message\n')
+ self.assert_equal(self.stderr.getvalue(), '')
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")
+ handle_remote_line("$LOG INFO borg.repository Remote: new format info message")
self.assert_equal(self.stream.getvalue(), '')
+ self.assert_equal(self.stderr.getvalue(), '')
def test_info_to_correct_local_child(self):
logging.getLogger('borg.repository').setLevel(logging.INFO)
@@ -514,7 +502,8 @@ class RemoteRepositoryLoggerTestCase(RepositoryTestCaseBase):
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")
+ handle_remote_line("$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(), '')
+ self.assert_equal(self.stderr.getvalue(), '')