Skip to content

Commit

Permalink
remote repos: remove support for borg < 1.1.0 ($LOG)
Browse files Browse the repository at this point in the history
log output:

always expect json, remove $LOG format support.

we keep limited support for unstructured format also,
just not to lose anything from remote stderr.
  • Loading branch information
ThomasWaldmann committed May 23, 2023
1 parent 31e7795 commit 2d978ab
Show file tree
Hide file tree
Showing 4 changed files with 41 additions and 52 deletions.
2 changes: 1 addition & 1 deletion src/borg/archiver/__init__.py
Original file line number Diff line number Diff line change
Expand Up @@ -482,7 +482,7 @@ def run(self, args):
func = get_func(args)
# 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=is_serve, json=args.log_json or is_serve)
self.log_json = args.log_json
args.progress |= is_serve
self._setup_implied_logging(vars(args))
Expand Down
6 changes: 2 additions & 4 deletions src/borg/logger.py
Original file line number Diff line number Diff line change
Expand Up @@ -90,10 +90,8 @@ 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:
fmt = "$LOG %(levelname)s %(name)s Remote: %(message)s"
else:
fmt = "%(message)s"
assert not (is_serve and not json)
fmt = "%(message)s"
formatter = JsonFormatter(fmt) if json else logging.Formatter(fmt)
handler.setFormatter(formatter)
borg_logger = logging.getLogger("borg")
Expand Down
30 changes: 2 additions & 28 deletions src/borg/remote.py
Original file line number Diff line number Diff line change
Expand Up @@ -27,7 +27,7 @@
from .helpers import format_file_size
from .helpers import safe_unlink
from .helpers import prepare_subprocess_env, ignore_sigint
from .logger import create_logger, setup_logging
from .logger import create_logger
from .helpers import msgpack
from .repository import Repository
from .version import parse_version, format_version
Expand Down Expand Up @@ -244,9 +244,6 @@ def serve(self):
def negotiate(self, client_data):
if isinstance(client_data, dict):
self.client_version = client_data["client_version"]
level = logging.getLevelName(logging.getLogger("").level)
setup_logging(is_serve=True, json=True, level=level)
logger.debug("Initialized logging system for JSON-based protocol")
else:
self.client_version = BORG_VERSION # seems to be newer than current version (no known old format)

Expand Down Expand Up @@ -897,8 +894,6 @@ def handle_remote_line(line):
"""
assert line.endswith(("\r", "\n"))
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"):
Expand Down Expand Up @@ -937,30 +932,9 @@ def handle_remote_line(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 serve 0.xx, 1.0.x and 1.1.0b1..b5.
# 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.
_, 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:
# 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)
logging.getLogger("").warning("Unexpected non-json log output from Remote: " + line.strip())


class RepositoryNoCache:
Expand Down
55 changes: 36 additions & 19 deletions src/borg/testsuite/repository.py
Original file line number Diff line number Diff line change
Expand Up @@ -1083,29 +1083,26 @@ def tearDown(self):

def test_stderr_messages(self):
handle_remote_line("unstructured stderr message\n")
self.assert_equal(self.stream.getvalue(), "")
# stderr messages don't get an implicit newline
self.assert_equal(self.stderr.getvalue(), "Remote: unstructured stderr message\n")

def test_stderr_progress_messages(self):
handle_remote_line("unstructured stderr progress message\r")
self.assert_equal(self.stream.getvalue(), "")
# stderr messages don't get an implicit newline
self.assert_equal(self.stderr.getvalue(), "Remote: unstructured stderr progress message\r")

def test_pre11_format_messages(self):
self.handler.setLevel(logging.DEBUG)
logging.getLogger().setLevel(logging.DEBUG)

handle_remote_line("$LOG INFO Remote: borg < 1.1 format message\n")
self.assert_equal(self.stream.getvalue(), "Remote: borg < 1.1 format message\n")
self.assert_equal(
self.stream.getvalue(), "Unexpected non-json log output from Remote: unstructured stderr message\n"
)
self.assert_equal(self.stderr.getvalue(), "")

def test_post11_format_messages(self):
self.handler.setLevel(logging.DEBUG)
logging.getLogger().setLevel(logging.DEBUG)

handle_remote_line("$LOG INFO borg.repository Remote: borg >= 1.1 format message\n")
msg = """{
"type": "log_message",
"levelname": "INFO",
"name": "borg.repository",
"message": "borg >= 1.1 format message",
"msgid": 42
}
""".rstrip(
" "
)
handle_remote_line(msg)
self.assert_equal(self.stream.getvalue(), "Remote: borg >= 1.1 format message\n")
self.assert_equal(self.stderr.getvalue(), "")

Expand All @@ -1114,7 +1111,17 @@ def test_remote_messages_screened(self):
self.handler.setLevel(logging.WARNING)
logging.getLogger().setLevel(logging.WARNING)

handle_remote_line("$LOG INFO borg.repository Remote: new format info message\n")
msg = """{
"type": "log_message",
"levelname": "INFO",
"name": "borg.repository",
"message": "new format info message",
"msgid": 42
}
""".rstrip(
" "
)
handle_remote_line(msg)
self.assert_equal(self.stream.getvalue(), "")
self.assert_equal(self.stderr.getvalue(), "")

Expand All @@ -1134,7 +1141,17 @@ def test_info_to_correct_local_child(self):
foo_handler.setLevel(logging.INFO)
logging.getLogger("borg.repository.foo").handlers[:] = [foo_handler]

handle_remote_line("$LOG INFO borg.repository Remote: new format child message\n")
msg = """{
"type": "log_message",
"levelname": "INFO",
"name": "borg.repository",
"message": "new format child message",
"msgid": 42
}
""".rstrip(
" "
)
handle_remote_line(msg)
self.assert_equal(foo_stream.getvalue(), "")
self.assert_equal(child_stream.getvalue(), "Remote: new format child message\n")
self.assert_equal(self.stream.getvalue(), "")
Expand Down

0 comments on commit 2d978ab

Please sign in to comment.