Merge ~blake-rouse/maas:fix-1801389 into maas:master

[Blake Rouse]

Fixes LP: #1801389 - Queue messages to syslog until the logging handler can actually connect.

I spent too much time trying to unit test this handler. Upstream python tests it against a running syslog if available, but this would dirty the system running the unit tests so I didn't like that approach.

I could setup a syslog just to test this one test, but that just seems way overkill for something as simple as queue messages.

I have tested this running and it works correctly, no more stack trace and the messages get queued and wrote to the socket.

[Mike Pontillo (mpontillo)]

Code looks good; good comments. Just a few grammar nits below.

review: Approve

4e15fb6... by Blake Rouse on 2018-11-16

Fix comments.

[Blake Rouse (blake-rouse)]

Fixed the comments, thanks for the review.

diff --git a/src/provisioningserver/logger/__init__.py b/src/provisioningserver/logger/__init__.py
index ceeaf19..2c109e2 100644
--- a/src/provisioningserver/logger/__init__.py
+++ b/src/provisioningserver/logger/__init__.py
@@ -54,6 +54,7 @@ __all__ = [
     "get_maas_logger",
     "LegacyLogger",
     "LoggingMode",
+    "MAASSysLogHandler",
     "set_verbosity",
     "VerbosityOptions",
 ]
@@ -68,7 +69,10 @@ from provisioningserver.logger._logging import (
     configure_standard_logging,
     set_standard_verbosity,
 )
-from provisioningserver.logger._maaslog import get_maas_logger
+from provisioningserver.logger._maaslog import (
+    get_maas_logger,
+    MAASSysLogHandler,
+)
 from provisioningserver.logger._tftp import configure_tftp_logging
 from provisioningserver.logger._twisted import (
     configure_twisted_logging,
diff --git a/src/provisioningserver/logger/_logging.py b/src/provisioningserver/logger/_logging.py
index 96bca1e..b134650 100644
--- a/src/provisioningserver/logger/_logging.py
+++ b/src/provisioningserver/logger/_logging.py
@@ -110,7 +110,7 @@ def get_logging_config(verbosity: int):
                 'formatter': 'stdout',
             },
             'syslog': {
-                'class': 'logging.handlers.SysLogHandler',
+                'class': 'provisioningserver.logger.MAASSysLogHandler',
                 'facility': logging.handlers.SysLogHandler.LOG_DAEMON,
                 'address': get_syslog_address_path(),
                 'formatter': 'syslog',
diff --git a/src/provisioningserver/logger/_maaslog.py b/src/provisioningserver/logger/_maaslog.py
index 5630ae5..89dd064 100644
--- a/src/provisioningserver/logger/_maaslog.py
+++ b/src/provisioningserver/logger/_maaslog.py
@@ -7,7 +7,10 @@ __all__ = [
     "get_maas_logger",
     ]
 
+from collections import deque
 import logging
+import logging.handlers
+import socket
 
 
 class MAASLogger(logging.getLoggerClass()):
@@ -19,6 +22,76 @@ class MAASLogger(logging.getLoggerClass()):
             "Django logger instead")
 
 
+class MAASSysLogHandler(logging.handlers.SysLogHandler):
+    """A syslog handler that queuess messages when connection to the socket
+    cannot be performed.
+
+    Once the connection is made the queue is flushed to the socket.
+    """
+
+    def __init__(self, *args, **kwargs):
+        # `queue` must be set before `super().__init__`, because
+        # `_connect_unixsocket` is called inside.
+        self.queue = deque()
+        super().__init__(*args, **kwargs)
+
+    def _connect_unixsocket(self, address):
+        super()._connect_unixsocket(address)
+        # Successfully connected to the socket. Write any queued messages.
+        while len(self.queue) > 0:
+            msg = self.queue.popleft()
+            try:
+                self.socket.send(msg)
+            except OSError:
+                self.queue.appendleft(msg)
+                raise
+
+    def emit(self, record):
+        """
+        Emit a record.
+
+        The record is formatted, and then sent to the syslog server. If
+        exception information is present, it is NOT sent to the server.
+
+        Note: This is copied directly from the python3 source code, only the
+        modification of appending to the queue was added.
+        """
+        try:
+            msg = self.format(record)
+            if self.ident:
+                msg = self.ident + msg
+            if self.append_nul:
+                msg += '\000'
+
+            # We need to convert record level to lowercase, maybe this will
+            # change in the future.
+            prio = '<%d>' % self.encodePriority(
+                self.facility, self.mapPriority(record.levelname))
+            prio = prio.encode('utf-8')
+            # Message is a string. Convert to bytes as required by RFC 5424
+            msg = msg.encode('utf-8')
+            msg = prio + msg
+            if self.unixsocket:
+                try:
+                    self.socket.send(msg)
+                except OSError:
+                    self.socket.close()
+                    try:
+                        self._connect_unixsocket(self.address)
+                    except OSError:
+                        # Queue the message to send when the connection
+                        # is finally made to the socket.
+                        self.queue.append(msg)
+                        return
+                    self.socket.send(msg)
+            elif self.socktype == socket.SOCK_DGRAM:
+                self.socket.sendto(msg, self.address)
+            else:
+                self.socket.sendall(msg)
+        except Exception:
+            self.handleError(record)
+
+
 def get_maas_logger(syslog_tag=None):
     """Return a MAAS logger that will log to syslog.