[trac800] Provide logging for the sockcreator parser

src/bin/bind10/bind10_messages.mes

@@ -155,3 +155,37 @@ the message channel.
 An unknown child process has exited. The PID is printed, but no further
 action will be taken by the boss process.
 
+% BIND10_SOCKCREATOR_INIT initializing socket creator parser
+The boss module initializes routines for parsing the socket creator
+protocol.
+
+% BIND10_SOCKCREATOR_TERMINATE terminating socket creator
+The boss module sends a request to terminate to the socket creator.
+
+% BIND10_SOCKET_GET requesting socket [%1]:%2 of type %3 from the creator
+The boss forwards a request for a socket to the socket creator.
+
+% BIND10_SOCKCREATOR_EOF eof while expecting data from socket creator
+There should be more data from the socket creator, but it closed the socket.
+It probably crashed.
+
+% BIND10_SOCKCREATOR_BAD_RESPONSE unknown response for socket request: %1
+The boss requested a socket from the creator, but the answer is unknown. This
+looks like programmer error.
+
+% BIND10_SOCKET_ERROR error on %1 call in the creator: %2/%3
+The socket creator failed to create the requested socket. It failed on the
+indicated OS API function with given error.
+
+% BIND10_SOCKCREATOR_BAD_CAUSE unknown error cause from socket creator: %1
+The socket creator reported an error when creating a socket. But the function
+which failed is unknown (not one of 'S' for socket or 'B' for bind).
+
+% BIND10_SOCKET_CREATED successfully created socket %1
+The socket creator successfully created and sent a requested socket, it has
+the given file number.
+
+% BIND10_SOCKCREATOR_TRANSPORT_ERROR transport error when talking to the socket creator: %1
+Either sending or receiving data from the socket creator failed with the given
+error. The creator probably crashed or some serious OS-level problem happened,
+as the communication happens only on local host.

src/bin/bind10/sockcreator.py

@@ -15,6 +15,10 @@
 
 import socket
 import struct
+import os
+from bind10_messages import *
+
+logger = isc.log.Logger("boss")
 
 """
 Module that comunicates with the priviledget socket creator (b10-sockcreator).
@@ -59,6 +63,7 @@ class Parser:
         unusual modification of socket object is used to easy up testing.
         """
         self.__socket = creator_socket
+        logger.info(BIND10_SOCKCREATOR_INIT)
 
     def terminate(self):
         """
@@ -67,6 +72,7 @@ class Parser:
         """
         if self.__socket is None:
             raise CreatorError('Terminated already', True)
+        logger.info(BIND10_SOCKCREATOR_TERMINATE)
         try:
             self.__socket.sendall(b'T')
             # Wait for an EOF - it will return empty data
@@ -93,6 +99,7 @@ class Parser:
         if self.__socket is None:
             raise CreatorError('Socket requested on terminated creator', True)
         # First, assemble the request from parts
+        logger.info(BIND10_SOCKET_GET, address, port, socktype)
         data = b'S'
         if socktype == 'UDP' or socktype == socket.SOCK_DGRAM:
             data += b'U'
@@ -114,7 +121,9 @@ class Parser:
             answer = self.__socket.recv(1)
             if answer == b'S':
                 # Success!
-                return self.__socket.read_fd()
+                result = self.__socket.read_fd()
+                logger.info(BIND10_SOCKET_CREATED, result)
+                return result
             elif answer == b'E':
                 # There was an error, read the error as well
                 error = self.__socket.recv(1)
@@ -127,14 +136,19 @@ class Parser:
                     cause = 'bind'
                 else:
                     self.__socket = None
+                    logger.fatal(BIND10_SOCKCREATOR_BAD_CAUSE, error)
                     raise CreatorError('Unknown error cause' + str(answer), True)
+                logger.error(BIND10_SOCKET_ERROR, cause, errno[0],
+                             os.strerror(errno[0]))
                 raise CreatorError('Error creating socket on ' + cause, False,
                                    errno[0])
             else:
                 self.__socket = None
+                logger.fatal(BIND10_SOCKCREATOR_BAD_RESPONSE, answer)
                 raise CreatorError('Unknown response ' + str(answer), True)
         except socket.error as se:
             self.__socket = None
+            logger.fatal(BIND10_SOCKCREATOR_TRANSPORT_ERROR, str(se))
             raise CreatorError(str(se), True)
 
     def __read_all(self, length):
@@ -148,6 +162,7 @@ class Parser:
             data = self.__socket.recv(length - len(result))
             if len(data) == 0:
                 self.__socket = None
+                logger.fatal(BIND10_SOCKCREATOR_EOF)
                 raise CreatorError('Unexpected EOF', True)
             result += data
         return result

src/bin/bind10/tests/sockcreator_test.py

@@ -22,6 +22,7 @@ import struct
 import socket
 from bind10.sockcreator import Parser, CreatorError
 from isc.net.addr import IPAddr
+import isc.log
 
 class FakeCreator:
     """
@@ -262,10 +263,16 @@ class ParserTests(unittest.TestCase):
         """
         Test it rejects invalid address family.
         """
+        # Note: this produces a bad logger output, since this address
+        # can not be converted to string, so the original message with
+        # placeholders is output. This should not happen in practice, so
+        # it is harmless.
         addr = IPAddr('0.0.0.0')
-        addr.family = 'Nonsense'
+        addr.family = 42
         self.assertRaises(ValueError, Parser(FakeCreator([])).get_socket,
                           addr, 42, socket.SOCK_DGRAM)
 
 if __name__ == '__main__':
+    isc.log.init("bind10") # FIXME Should this be needed?
+    isc.log.resetUnitTestRootLogger()
     unittest.main()