backup: Improve logging configurability for socket server

Add two optional arguments to `backup-cli server`:

- `--log-mode`: either `plain` (simply print the log message) or `systemd`
  (prefix log message with systemd log level, useful for running as a
  a service)

- `--log-level`: minimum level for messages to be logged, from `DEBUG`
  to `CRITICAL`

Also, move some noisy messages to the debug level.

backup/backup-cli

@@ -1,7 +1,7 @@
 #!/usr/bin/env python3
 from backends import get_backend
 from backend import Change
-from server import SocketServer
+from server import SocketServer, setup_server_logging
 
 import os
 import click
@@ -74,10 +74,15 @@ def restore(backend_url, restore_destination):
 @click.command()
 @click.argument("backend-url")
 @click.argument("addr")
-def server(backend_url, addr):
+@click.option('--log-mode', type=click.Choice(['plain', 'systemd'], case_sensitive=False), default='plain', help='Debug log mode, defaults to plain')
+@click.option('--log-level', type=click.Choice(['debug', 'info', 'notice', 'warning', 'error', 'critical'], case_sensitive=False), default='info', help='Debug log level, defaults to info')
+def server(backend_url, addr, log_mode, log_level):
     backend = get_backend(backend_url)
     addr, port = addr.split(':')
     port = int(port)
+
+    setup_server_logging(log_mode, log_level)
+
     server = SocketServer((addr, port), backend)
     server.run()
 

backup/server.py

@@ -1,10 +1,47 @@
 import logging, socket, struct
 import json
+import sys
 from typing import Tuple
 
 from backend import Backend
 from protocol import PacketType, recvall, PKT_CHANGE_TYPES, change_from_packet, packet_from_change, send_packet, recv_packet
 
+class SystemdHandler(logging.Handler):
+    PREFIX = {
+        # EMERG <0>
+        # ALERT <1>
+        logging.CRITICAL: "<2>",
+        logging.ERROR: "<3>",
+        logging.WARNING: "<4>",
+        # NOTICE <5>
+        logging.INFO: "<6>",
+        logging.DEBUG: "<7>",
+        logging.NOTSET: "<7>"
+    }
+
+    def __init__(self, stream=sys.stdout):
+        self.stream = stream
+        logging.Handler.__init__(self)
+
+    def emit(self, record):
+        try:
+            msg = self.PREFIX[record.levelno] + self.format(record) + "\n"
+            self.stream.write(msg)
+            self.stream.flush()
+        except Exception:
+            self.handleError(record)
+
+def setup_server_logging(mode, level):
+    root_logger = logging.getLogger()
+    root_logger.setLevel(level.upper())
+    mode = mode.lower()
+    if mode == 'systemd':
+        # replace handler with systemd one
+        root_logger.handlers = []
+        root_logger.addHandler(SystemdHandler())
+    else:
+        assert(mode == 'plain')
+
 class SocketServer:
     def __init__(self, addr: Tuple[str, int], backend: Backend) -> None:
         self.backend = backend
@@ -32,7 +69,7 @@ def _handle_conn(self, conn) -> None:
             if typ in PKT_CHANGE_TYPES:
                 change = change_from_packet(typ, payload)
                 if typ == PacketType.CHANGE:
-                    logging.info('Received CHANGE {}'.format(change.version))
+                    logging.debug('Received CHANGE {}'.format(change.version))
                 else:
                     logging.info('Received SNAPSHOT {}'.format(change.version))
                 self.backend.add_change(change)
@@ -47,7 +84,7 @@ def _handle_conn(self, conn) -> None:
                     self.backend.rewind()
                     self._send_packet(PacketType.ACK, struct.pack("!I", self.backend.version))
             elif typ == PacketType.REQ_METADATA:
-                logging.info('Received REQ_METADATA')
+                logging.debug('Received REQ_METADATA')
                 blob = struct.pack("!IIIQ", 0x01, self.backend.version,
                            self.backend.prev_version,
                            self.backend.version_count)
@@ -63,13 +100,13 @@ def _handle_conn(self, conn) -> None:
                 stats = self.backend.compact()
                 self._send_packet(PacketType.COMPACT_RES, json.dumps(stats).encode())
             elif typ == PacketType.ACK:
-                logging.info('Received ACK')
+                logging.debug('Received ACK')
             elif typ == PacketType.NACK:
-                logging.info('Received NACK')
+                logging.debug('Received NACK')
             elif typ == PacketType.METADATA:
-                logging.info('Received METADATA')
+                logging.debug('Received METADATA')
             elif typ == PacketType.COMPACT_RES:
-                logging.info('Received COMPACT_RES')
+                logging.debug('Received COMPACT_RES')
             else:
                 raise Exception('Unknown or unexpected packet type {}'.format(typ))
         self.conn = None