[master] Merge branch 'trac2003' with fixing conflicts.

Also updated server_common/auth_command.py so it uses the package level
logger module (as originally planned in #1978).

src/bin/ddns/ddns.py.in

@@ -30,6 +30,7 @@ import isc.util.process
 import isc.util.cio.socketsession
 from isc.notify.notify_out import ZONE_NEW_DATA_READY_CMD
 import isc.server_common.tsig_keyring
+from isc.server_common.dns_tcp import DNSTCPContext
 from isc.datasrc import DataSourceClient
 from isc.server_common.auth_command import auth_loadzone_command
 import select
@@ -153,6 +154,10 @@ def get_datasrc_client(cc_session):
         return HARDCODED_DATASRC_CLASS, DummyDataSourceClient(ex)
 
 class DDNSServer:
+    # The number of TCP clients that can be handled by the server at the same
+    # time (this should be configurable parameter).
+    TCP_CLIENTS = 10
+
     def __init__(self, cc_session=None):
         '''
         Initialize the DDNS Server.
@@ -192,12 +197,14 @@ class DDNSServer:
         self.__request_msg = Message(Message.PARSE)
         self.__response_renderer = MessageRenderer()
 
-        # The following attribute(s) are essentially private and constant,
-        # but defined as "protected" so that test code can customize them.
-        # They should not be overridden for any other purposes.
+        # The following attribute(s) are essentially private, but defined as
+        # "protected" so that test code can customize/inspect them.
+        # They should not be overridden/referenced for any other purposes.
         #
         # DDNS Protocol handling class.
         self._UpdateSessionClass = isc.ddns.session.UpdateSession
+        # Outstanding TCP context: fileno=>(context_obj, dst)
+        self._tcp_ctxs = {}
 
     class InternalError(Exception):
         '''Exception for internal errors in an update session.
@@ -344,8 +351,6 @@ class DDNSServer:
         # or dropped by the sender, so if such error is detected we treat it
         # as an internal error and don't bother to respond.
         try:
-            if sock.proto == socket.IPPROTO_TCP:
-                raise self.InternalError('TCP requests are not yet supported')
             self.__request_msg.clear(Message.PARSE)
             # specify PRESERVE_ORDER as we need to handle each RR separately.
             self.__request_msg.from_wire(req_data, Message.PRESERVE_ORDER)
@@ -405,9 +410,19 @@ class DDNSServer:
 
         '''
         try:
-            sock.sendto(data, dest)
+            if sock.proto == socket.IPPROTO_UDP:
+                sock.sendto(data, dest)
+            else:
+                tcp_ctx = DNSTCPContext(sock)
+                send_result = tcp_ctx.send(data)
+                if send_result == DNSTCPContext.SENDING:
+                    self._tcp_ctxs[sock.fileno()] = (tcp_ctx, dest)
+                elif send_result == DNSTCPContext.CLOSED:
+                    raise socket.error("socket error in TCP send")
+                else:
+                    tcp_ctx.close()
         except socket.error as ex:
-            logger.error(DDNS_RESPONSE_SOCKET_ERROR, ClientFormatter(dest), ex)
+            logger.warn(DDNS_RESPONSE_SOCKET_ERROR, ClientFormatter(dest), ex)
             return False
 
         return True
@@ -458,19 +473,35 @@ class DDNSServer:
                          ZoneFormatter(zname, zclass), error_msg)
 
     def handle_session(self, fileno):
-        """
-        Handle incoming session on the socket with given fileno.
+        """Handle incoming session on the socket with given fileno.
+
+        Return True if a response (whether positive or negative) has been
+        sent; otherwise False.  The return value isn't expected to be used
+        for other purposes than testing.
+
         """
         logger.debug(TRACE_BASIC, DDNS_SESSION, fileno)
-        (socket, receiver) = self._socksession_receivers[fileno]
+        (session_socket, receiver) = self._socksession_receivers[fileno]
         try:
-            self.handle_request(receiver.pop())
+            req_session = receiver.pop()
+            (sock, remote_addr) = (req_session[0], req_session[2])
+
+            # If this is a TCP client, check the quota, and immediately reject
+            # it if we cannot accept more.
+            if sock.proto == socket.IPPROTO_TCP and \
+                    len(self._tcp_ctxs) >= self.TCP_CLIENTS:
+                logger.warn(DDNS_REQUEST_TCP_QUOTA,
+                            ClientFormatter(remote_addr), len(self._tcp_ctxs))
+                sock.close()
+                return False
+            return self.handle_request(req_session)
         except isc.util.cio.socketsession.SocketSessionError as se:
             # No matter why this failed, the connection is in unknown, possibly
             # broken state. So, we close the socket and remove the receiver.
             del self._socksession_receivers[fileno]
-            socket.close()
+            session_socket.close()
             logger.warn(DDNS_DROP_CONN, fileno, se)
+            return False
 
     def run(self):
         '''
@@ -491,8 +522,8 @@ class DDNSServer:
             try:
                 (reads, writes, exceptions) = \
                     select.select([cc_fileno, listen_fileno] +
-                                  list(self._socksession_receivers.keys()), [],
-                                  [])
+                                  list(self._socksession_receivers.keys()),
+                                  list(self._tcp_ctxs.keys()), [])
             except select.error as se:
                 # In case it is just interrupted, we continue like nothing
                 # happened
@@ -507,6 +538,15 @@ class DDNSServer:
                     self.accept()
                 else:
                     self.handle_session(fileno)
+            for fileno in writes:
+                ctx = self._tcp_ctxs[fileno]
+                result = ctx[0].send_ready()
+                if result != DNSTCPContext.SENDING:
+                    if result == DNSTCPContext.CLOSED:
+                        logger.warn(DDNS_RESPONSE_TCP_SOCKET_ERROR,
+                                    ClientFormatter(ctx[1]))
+                    ctx[0].close()
+                    del self._tcp_ctxs[fileno]
         self.shutdown_cleanup()
         logger.info(DDNS_STOPPED)
 

src/bin/ddns/ddns_messages.mes

@@ -81,11 +81,38 @@ this stage and should rather be considered an internal bug.  This
 event is therefore logged at the error level, and the request is
 simply dropped.  Additional information of the error is also logged.
 
+% DDNS_REQUEST_TCP_QUOTA reject TCP update client %1 (%2 running)
+b10-ddns received a new update request from a client over TCP, but
+the number of TCP clients being handled by the server already reached
+the configured quota, so the latest client was rejected by closing
+the connection.  The administrator may want to check the status of
+b10-ddns, and if this happens even if the server is not very busy,
+the quota may have to be increased.  Or, if it's more likely to be
+malicious or simply bogus clients that somehow keep the TCP connection
+open for a long period, maybe they should be rejected with an
+appropriate ACL configuration or some lower layer filtering.  The
+number of existing TCP clients are shown in the log, which should be
+identical to the current quota.
+
 % DDNS_RESPONSE_SOCKET_ERROR failed to send update response to %1: %2
-Network I/O error happens in sending an update request.  The
+Network I/O error happens in sending an update response.  The
 client's address that caused the error and error details are also
 logged.
 
+% DDNS_RESPONSE_TCP_SOCKET_ERROR failed to complete sending update response to %1 over TCP
+b10-ddns had tried to send an update response over TCP, and it hadn't
+been completed at that time, and a followup attempt to complete the
+send operation failed due to some network I/O error.  While a network
+error can happen any time, this event is quite unexpected for two
+reasons.  First, since the size of a response to an update request
+should be generally small, it's unlikely that the initial attempt
+didn't fail but wasn't completed.  Second, since the first attempt
+succeeded and the TCP connection had been established in the first
+place, it's more likely for the subsequent attempt to succeed.  In any
+case, there may not be able to do anything to fix it at the server
+side, but the administrator may want to check the general reachability
+with the client address.
+
 % DDNS_RUNNING ddns server is running and listening for updates
 The ddns process has successfully started and is now ready to receive commands
 and updates.

src/bin/ddns/tests/ddns_test.py

@@ -22,6 +22,7 @@ import isc.util.cio.socketsession
 from isc.cc.session import SessionTimeout, SessionError, ProtocolError
 from isc.datasrc import DataSourceClient
 from isc.config.ccsession import create_answer
+from isc.server_common.dns_tcp import DNSTCPContext
 import ddns
 import errno
 import os
@@ -59,17 +60,23 @@ class FakeSocket:
     """
     A fake socket. It only provides a file number, peer name and accept method.
     """
-    def __init__(self, fileno):
-        self.proto = socket.IPPROTO_UDP
+    def __init__(self, fileno, proto=socket.IPPROTO_UDP):
+        self.proto = proto
         self.__fileno = fileno
         self._sent_data = None
         self._sent_addr = None
+        self._close_called = 0  # number of calls to close()
+        self.__send_cc = 0      # waterline of the send buffer (can be reset)
         # customizable by tests; if set to True, sendto() will throw after
         # recording the parameters.
         self._raise_on_send = False
+        self._send_buflen = None # imaginary send buffer for partial send
     def fileno(self):
         return self.__fileno
     def getpeername(self):
+        if self.proto == socket.IPPROTO_UDP or \
+                self.proto == socket.IPPROTO_TCP:
+            return TEST_CLIENT4
         return "fake_unix_socket"
     def accept(self):
         return FakeSocket(self.__fileno + 1), '/dummy/path'
@@ -78,10 +85,39 @@ class FakeSocket:
         self._sent_addr = addr
         if self._raise_on_send:
             raise socket.error('test socket failure')
+    def send(self, data):
+        if self._raise_on_send:
+            raise socket.error(errno.EPIPE, 'faked connection disruption')
+        elif self._send_buflen is None:
+            available_space = len(data)
+        else:
+            available_space = self._send_buflen - self.__send_cc
+        if available_space == 0:
+            # if there's no space, (assuming it's nonblocking mode) raise
+            # EAGAIN.
+            raise socket.error(errno.EAGAIN,
+                               "Resource temporarily unavailable")
+        # determine the sendable part of the data, record it, update "buffer".
+        cc = min(available_space, len(data))
+        if self._sent_data is None:
+            self._sent_data = data[:cc]
+        else:
+            self._sent_data += data[:cc]
+        self.__send_cc += cc
+        return cc
+    def setblocking(self, on):
+        # We only need a faked NO-OP implementation.
+        pass
+    def close(self):
+        self._close_called += 1
     def clear(self):
         '''Clear internal instrumental data.'''
         self._sent_data = None
         self._sent_addr = None
+    def make_send_ready(self):
+        # pretend that the accrued data has been cleared, making room in
+        # the send buffer.
+        self.__send_cc = 0
 
 class FakeSessionReceiver:
     """
@@ -266,6 +302,11 @@ class TestDDNSServer(unittest.TestCase):
         self.ddns_server._listen_socket = FakeSocket(2)
         ddns.select.select = self.__select
 
+        # common private attributes for TCP response tests
+        self.__tcp_sock = FakeSocket(10, socket.IPPROTO_TCP)
+        self.__tcp_ctx = DNSTCPContext(self.__tcp_sock)
+        self.__tcp_data = b'A' * 12 # dummy, just the same size as DNS header
+
     def tearDown(self):
         ddns.select.select = select.select
         ddns.isc.util.cio.socketsession.SocketSessionReceiver = \
@@ -594,6 +635,100 @@ class TestDDNSServer(unittest.TestCase):
         self.__select_expected = ([1, 2], [], [], None)
         self.assertRaises(select.error, self.ddns_server.run)
 
+    def __send_select_tcp(self, buflen, raise_after_select=False):
+        '''Common subroutine for some TCP related tests below.'''
+        fileno = self.__tcp_sock.fileno()
+        self.ddns_server._tcp_ctxs = {fileno: (self.__tcp_ctx, TEST_CLIENT6)}
+
+        # make an initial, incomplete send via the test context
+        self.__tcp_sock._send_buflen = buflen
+        self.assertEqual(DNSTCPContext.SENDING,
+                         self.__tcp_ctx.send(self.__tcp_data))
+        self.assertEqual(buflen, len(self.__tcp_sock._sent_data))
+        # clear the socket "send buffer"
+        self.__tcp_sock.make_send_ready()
+        # if requested, set up exception
+        self.__tcp_sock._raise_on_send = raise_after_select
+
+        # Run select
+        self.__select_expected = ([1, 2], [fileno], [], None)
+        self.__select_answer = ([], [fileno], [])
+        self.ddns_server.run()
+
+    def test_select_send_continued(self):
+        '''Test continuation of sending a TCP response.'''
+        # Common setup, with the bufsize that would make it complete after a
+        # single select call.
+        self.__send_select_tcp(7)
+
+        # Now the send should be completed.  socket should be closed,
+        # and the context should be removed from the server.
+        self.assertEqual(14, len(self.__tcp_sock._sent_data))
+        self.assertEqual(1, self.__tcp_sock._close_called)
+        self.assertEqual(0, len(self.ddns_server._tcp_ctxs))
+
+    def test_select_send_continued_twice(self):
+        '''Test continuation of sending a TCP response, still continuing.'''
+        # This is similar to the send_continued test, but the continued
+        # operation still won't complete the send.
+        self.__send_select_tcp(5)
+
+        # Only 10 bytes should have been transmitted, socket is still open,
+        # and the context is still in the server (that would require select
+        # watch it again).
+        self.assertEqual(10, len(self.__tcp_sock._sent_data))
+        self.assertEqual(0, self.__tcp_sock._close_called)
+        fileno = self.__tcp_sock.fileno()
+        self.assertEqual(self.__tcp_ctx,
+                         self.ddns_server._tcp_ctxs[fileno][0])
+
+    def test_select_send_continued_failed(self):
+        '''Test continuation of sending a TCP response, which fails.'''
+        # Let the socket raise an exception in the second call to send().
+        self.__send_select_tcp(5, raise_after_select=True)
+
+        # Only the data before select() have been transmitted, socket is
+        # closed due to the failure, and the context is removed from the
+        # server.
+        self.assertEqual(5, len(self.__tcp_sock._sent_data))
+        self.assertEqual(1, self.__tcp_sock._close_called)
+        self.assertEqual(0, len(self.ddns_server._tcp_ctxs))
+
+    def test_select_multi_tcp(self):
+        '''Test continuation of sending a TCP response, multiple sockets.'''
+        # Check if the implementation still works with multiple outstanding
+        # TCP contexts.  We use three (arbitray choice), of which two will be
+        # writable after select and complete the send.
+        tcp_socks = []
+        for i in range(0, 3):
+            # Use faked FD of 100, 101, 102 (again, arbitrary choice)
+            s = FakeSocket(100 + i, proto=socket.IPPROTO_TCP)
+            ctx = DNSTCPContext(s)
+            self.ddns_server._tcp_ctxs[s.fileno()] = (ctx, TEST_CLIENT6)
+            s._send_buflen = 7  # make sure it requires two send's
+            self.assertEqual(DNSTCPContext.SENDING, ctx.send(self.__tcp_data))
+            s.make_send_ready()
+
+            tcp_socks.append(s)
+
+        self.__select_expected = ([1, 2], [100, 101, 102], [], None)
+        self.__select_answer = ([], [100, 102], [])
+        self.ddns_server.run()
+
+        for i in [0, 2]:
+            self.assertEqual(14, len(tcp_socks[i]._sent_data))
+            self.assertEqual(1, tcp_socks[i]._close_called)
+        self.assertEqual(1, len(self.ddns_server._tcp_ctxs))
+
+    def test_select_bad_writefd(self):
+        # There's no outstanding TCP context, but select somehow returns
+        # writable FD.  It should result in an uncaught exception, killing
+        # the server.  This is okay, because it shouldn't happen and should be
+        # an internal bug.
+        self.__select_expected = ([1, 2], [], [], None)
+        self.__select_answer = ([], [10], [])
+        self.assertRaises(KeyError, self.ddns_server.run)
+
 def create_msg(opcode=Opcode.UPDATE(), zones=[TEST_ZONE_RECORD], prereq=[],
                tsigctx=None):
     msg = Message(Message.RENDER)
@@ -640,7 +775,7 @@ class TestDDNSSession(unittest.TestCase):
                                  self.__faked_result)
 
     def check_update_response(self, resp_wire, expected_rcode=Rcode.NOERROR(),
-                              tsig_ctx=None):
+                              tsig_ctx=None, tcp=False):
         '''Check if given wire data are valid form of update response.
 
         In this implementation, zone/prerequisite/update sections should be
@@ -650,7 +785,15 @@ class TestDDNSSession(unittest.TestCase):
         be TSIG signed and the signature should be verifiable with the context
         that has signed the corresponding request.
 
+        if tcp is True, the wire data are expected to be prepended with
+        a 2-byte length field.
+
         '''
+        if tcp:
+            data_len = resp_wire[0] * 256 + resp_wire[1]
+            resp_wire = resp_wire[2:]
+            self.assertEqual(len(resp_wire), data_len)
+
         msg = Message(Message.PARSE)
         msg.from_wire(resp_wire)
         if tsig_ctx is not None:
@@ -723,19 +866,98 @@ class TestDDNSSession(unittest.TestCase):
         self.__sock._raise_on_send = True
         # handle_request indicates the failure
         self.assertFalse(self.server.handle_request((self.__sock, TEST_SERVER6,
-                                                     TEST_SERVER4,
+                                                     TEST_CLIENT6,
                                                      create_msg())))
         # this check ensures sendto() was really attempted.
         self.check_update_response(self.__sock._sent_data, Rcode.NOERROR())
 
     def test_tcp_request(self):
-        # Right now TCP request is not supported.
+        # A simple case using TCP: all resopnse data are sent out at once.
         s = self.__sock
         s.proto = socket.IPPROTO_TCP
+        self.assertTrue(self.server.handle_request((s, TEST_SERVER6,
+                                                    TEST_CLIENT6,
+                                                    create_msg())))
+        self.check_update_response(s._sent_data, Rcode.NOERROR(), tcp=True)
+        # In the current implementation, the socket should be closed
+        # immedidately after a successful send.
+        self.assertEqual(1, s._close_called)
+        # TCP context shouldn't be held in the server.
+        self.assertEqual(0, len(self.server._tcp_ctxs))
+
+    def test_tcp_request_incomplete(self):
+        # set the size of the socket "send buffer" to a small value, which
+        # should cause partial send.
+        s = self.__sock
+        s.proto = socket.IPPROTO_TCP
+        s._send_buflen = 7
+        # before this request there should be no outstanding TCP context.
+        self.assertEqual(0, len(self.server._tcp_ctxs))
+        self.assertTrue(self.server.handle_request((s, TEST_SERVER6,
+                                                    TEST_CLIENT6,
+                                                    create_msg())))
+        # Only the part of data that fit the send buffer should be transmitted.
+        self.assertEqual(s._send_buflen, len(s._sent_data))
+        # the socket is not yet closed.
+        self.assertEqual(0, s._close_called)
+        # and a new context is stored in the server.
+        self.assertEqual(1, len(self.server._tcp_ctxs))
+
+        # clear the "send buffer" of the fake socket, and continue the send
+        # by hand.  The next attempt should complete the send, and the combined
+        # data should be the expected response.
+        s.make_send_ready()
+        self.assertEqual(DNSTCPContext.SEND_DONE,
+                         self.server._tcp_ctxs[s.fileno()][0].send_ready())
+        self.check_update_response(s._sent_data, Rcode.NOERROR(), tcp=True)
+
+    def test_tcp_request_error(self):
+        # initial send() on the TCP socket will fail.  The request handling
+        # will be considered failure.
+        s = self.__sock
+        s.proto = socket.IPPROTO_TCP
+        s._raise_on_send = True
         self.assertFalse(self.server.handle_request((s, TEST_SERVER6,
-                                                     TEST_SERVER4,
+                                                     TEST_CLIENT6,
                                                      create_msg())))
-        self.assertEqual((None, None), (s._sent_data, s._sent_addr))
+        # the socket should have been closed.
+        self.assertEqual(1, s._close_called)
+
+    def test_tcp_request_quota(self):
+        '''Test'''
+        # Originally the TCP context map should be empty.
+        self.assertEqual(0, len(self.server._tcp_ctxs))
+
+        class FakeReceiver:
+            '''Faked SessionReceiver, just returning given param by pop()'''
+            def __init__(self, param):
+                self.__param = param
+            def pop(self):
+                return self.__param
+
+        def check_tcp_ok(fd, expect_grant):
+            '''Supplemental checker to see if TCP request is handled.'''
+            s = FakeSocket(fd, proto=socket.IPPROTO_TCP)
+            s._send_buflen = 7
+            self.server._socksession_receivers[s.fileno()] = \
+                (None, FakeReceiver((s, TEST_SERVER6, TEST_CLIENT6,
+                                     create_msg())))
+            self.assertEqual(expect_grant,
+                             self.server.handle_session(s.fileno()))
+            self.assertEqual(0 if expect_grant else 1, s._close_called)
+
+        # By default up to 10 TCP clients can coexist (use hardcode
+        # intentionally so we can test the default value itself)
+        for i in range(0, 10):
+            check_tcp_ok(i, True)
+        self.assertEqual(10, len(self.server._tcp_ctxs))
+
+        # Beyond that, it should be rejected (by reset)
+        check_tcp_ok(11, False)
+
+        # If we remove one context from the server, new client can go in again.
+        self.server._tcp_ctxs.pop(5)
+        check_tcp_ok(12, True)
 
     def test_request_message(self):
         '''Test if the request message stores RRs separately.'''

src/lib/python/isc/server_common/Makefile.am

@@ -1,6 +1,7 @@
 SUBDIRS = tests
 
-python_PYTHON = __init__.py tsig_keyring.py auth_command.py
+python_PYTHON = __init__.py tsig_keyring.py auth_command.py dns_tcp.py \
+python_PYTHON += logger.py
 
 pythondir = $(pyexecdir)/isc/server_common
 

src/lib/python/isc/server_common/auth_command.py

@@ -19,11 +19,7 @@ from isc.dns import *
 import isc.log
 from isc.config.ccsession import create_command
 from isc.log_messages.server_common_messages import *
-
-# Import tsig_keyring just to share the logger.  Once #2003 is merged, this
-# should be replaced with the package level logger:
-# from isc.server_common.logger import logger
-from isc.server_common.tsig_keyring import logger
+from isc.server_common.logger import logger
 
 AUTH_MODULE_NAME = 'Auth'
 

src/lib/python/isc/server_common/dns_tcp.py

@@ -0,0 +1,280 @@
+# Copyright (C) 2012  Internet Systems Consortium, Inc. ("ISC")
+#
+# Permission to use, copy, modify, and distribute this software for any
+# purpose with or without fee is hereby granted, provided that the above
+# copyright notice and this permission notice appear in all copies.
+#
+# THE SOFTWARE IS PROVIDED "AS IS" AND INTERNET SYSTEMS CONSORTIUM
+# DISCLAIMS ALL WARRANTIES WITH REGARD TO THIS SOFTWARE INCLUDING ALL
+# IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL
+# INTERNET SYSTEMS CONSORTIUM BE LIABLE FOR ANY SPECIAL, DIRECT,
+# INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES WHATSOEVER RESULTING
+# FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION OF CONTRACT,
+# NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION
+# WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
+
+"""Utility for handling DNS transactions over TCP.
+
+This module defines a few convenient utility classes for handling DNS
+transactions via a TCP socket.
+
+"""
+
+import isc.log
+from isc.server_common.logger import logger
+from isc.log_messages.server_common_messages import *
+from isc.ddns.logger import ClientFormatter
+import errno
+import socket
+import struct
+
+class DNSTCPSendBuffer:
+    '''A composite buffer for a DNS message sent over TCP.
+
+    This class encapsulates binary data supposed to be a complete DNS
+    message, taking into account the 2-byte length field preceeding the
+    actual data.
+
+    An object of this class is constructed with a binary object for the
+    DNS message data (in wire-format), conceptually "appended" to the
+    2-byte length field.  The length is automatically calculated and
+    converted to the wire-format data in the network byte order.
+
+    Its get_data() method returns a binary object corresponding to the
+    consecutive region of the conceptual buffer starting from the specified
+    position.  The returned region may not necessarily contain all remaining
+    data from the specified position; this class can internally hold multiple
+    separate binary objects to represent the conceptual buffer, and,
+    in that case, get_data() identifies the object that contains the
+    specified position of data, and returns the longest consecutive region
+    from that position.  So the caller must call get_data(), incrementing
+    the position as it transmits the data, until it gets None.
+
+    This class is primarily intended to be a private utility for the
+    DNSTCPContext class, but can be used by other general applications
+    that need to send DNS messages over TCP in their own way.
+
+    '''
+    def __init__(self, data):
+        '''Consructor.
+
+        Parameter:
+          data (binary): A binary sequence that is supposed to be a
+            complete DNS message in the wire format.  It must not
+            exceed 65535 bytes in length; otherwise ValueError will be
+            raised.  This class does not check any further validity on
+            the data as a DNS message.
+
+        '''
+        self.__data_size = len(data)
+        self.__len_size = 2     # fixed length
+        if self.__data_size > 0xffff:
+            raise ValueError('Too large data for DNS/TCP, size: ' +
+                             str(self.__data_size))
+        self.__lenbuf = struct.pack('H', socket.htons(self.__data_size))
+        self.__databuf = data
+
+    def get_total_len(self):
+        '''Return the total length of the buffer, including the length field.
+
+        '''
+        return self.__data_size + self.__len_size
+
+    def get_data(self, pos):
+        '''Return a portion of data from a specified position.
+
+        Parameter:
+          pos (int): The position in the TCP DNS message data (including
+          the 2-byte length field) from which the data are to be returned.
+
+        Return:
+          A Python binary object that corresponds to a part of the TCP
+          DNS message data starting at the specified position.  It may
+          or may not contain all remaining data from that position.
+          If the given position is beyond the end of the enrire data,
+          None will be returned.
+
+        '''
+        if pos >= self.__len_size:
+            pos -= self.__len_size
+            if pos >= self.__data_size:
+                return None
+            return self.__databuf[pos:]
+        return self.__lenbuf[pos:]
+
+class DNSTCPContextError(Exception):
+    '''An exception raised against logic errors in DNSTCPContext.
+
+    This is raised only when the context class is used in an unexpected way,
+    that is for a caller's bug.
+
+    '''
+    pass
+
+class DNSTCPContext:
+    '''Context of a TCP connection used for DNS transactions.
+
+    This class offers the following services:
+    - Handle the initial 2-byte length field internally.  The user of
+      this class only has to deal with the bare DNS message (just like
+      the one transmiited over UDP).
+    - Asynchronous I/O.  It supports the non blocking operation mode,
+      where method calls never block.  The caller is told whether it's
+      ongoing and it should watch the socket or it's fully completed.
+    - Socket error handling: it internally catches socket related exceptions
+      and handle them in an appropriate way.  A fatal error will be reported
+      to the caller in the form of a normal return value.  The application
+      of this class can therefore assume it's basically exception free.
+
+    Notes:
+      - the initial implementation only supports non blocking mode, but
+        it's intended to be extended so it can work in both blocking or
+        non blocking mode as we see the need for it.
+      - the initial implementation only supports send operations on an
+        already connected socket, but the intent is to extend this class
+        so it can handle receive or connect operations.
+
+    '''
+
+    # Result codes used in send()/send_ready() methods.
+    SEND_DONE = 1
+    SENDING = 2
+    CLOSED = 3
+
+    def __init__(self, sock):
+        '''Constructor.
+
+        Parameter:
+          sock (Python socket): the socket to be used for the transaction.
+            It must represent a TCP socket; otherwise DNSTCPContextError
+            will be raised.  It's also expected to be connected, but it's
+            not checked on construction; a subsequent send operation would
+            fail.
+
+        '''
+        if sock.proto != socket.IPPROTO_TCP:
+            raise DNSTCPContextError('not a TCP socket, proto: ' +
+                                     str(sock.proto))
+        sock.setblocking(False)
+        self.__sock = sock
+        self.__send_buffer = None
+        self.__remote_addr = sock.getpeername() # record it for logging
+
+    def send(self, data):
+        '''Send a DNS message.
+
+        In the non blocking mode, it sends as much data as possible via
+        the underlying TCP socket until it would block or all data are sent
+        out, and returns the corresponding result code.  This method
+        therefore doesn't block in this mode.
+
+          Note: the initial implementation only works in the non blocking
+          mode.
+
+        This method must not be called once an error is detected and
+        CLOSED is returned or a prior send attempt is ongoing (with
+        the result code of SENDING); otherwise DNSTCPContextError is
+        raised.
+
+        Parameter:
+          data (binary): A binary sequence that is supposed to be a
+            complete DNS message in the wire format.  It must meet
+            the assumption that DNSTCPSendBuffer requires.
+
+        Return:
+          An integer constant representing the result:
+          - SEND_DONE All data have been sent out successfully.
+          - SENDING All writable data has been sent out, and further
+              attempt would block at the moment.  The caller is expected
+              to detect it when the underlying socket is writable again
+              and call send_ready() to continue the send.
+          - CLOSED A network error happened before the send operation is
+              completed.  The underlying socket has been closed, and this
+              context object will be unusable.
+
+        '''
+        if self.__sock is None:
+            raise DNSTCPContextError('send() called after close')
+        if self.__send_buffer is not None:
+            raise DNSTCPContextError('duplicate send()')
+
+        self.__send_buffer = DNSTCPSendBuffer(data)
+        self.__send_marker = 0
+        return self.__do_send()
+
+    def send_ready(self):
+        '''Resume sending a DNS message.
+
+        This method is expected to be called followed by a send() call or
+        another send_ready() call that resulted in SENDING, when the caller
+        detects the underlying socket becomes writable.  It works as
+        send() except that it continues the send operation from the suspended
+        position of the data at the time of the previous call.
+
+        This method must not be called once an error is detected and
+        CLOSED is returned or a send() method hasn't been called to
+        start the operation; otherwise DNSTCPContextError is raised.
+
+        Return: see send().
+
+        '''
+        if self.__sock is None:
+            raise DNSTCPContextError('send() called after close')
+        if self.__send_buffer is None:
+            raise DNSTCPContextError('send_ready() called before send')
+
+        return self.__do_send()
+
+    def __do_send(self):
+        while True:
+            data = self.__send_buffer.get_data(self.__send_marker)
+            if data is None:
+                # send complete; clear the internal buffer for next possible
+                # send.
+                logger.debug(logger.DBGLVL_TRACE_DETAIL,
+                             PYSERVER_COMMON_DNS_TCP_SEND_DONE,
+                             ClientFormatter(self.__remote_addr),
+                             self.__send_marker)
+                self.__send_buffer = None
+                self.__send_marker = 0
+                return self.SEND_DONE
+            try:
+                cc = self.__sock.send(data)
+            except socket.error as ex:
+                total_len = self.__send_buffer.get_total_len()
+                if ex.errno == errno.EAGAIN:
+                    logger.debug(logger.DBGLVL_TRACE_DETAIL,
+                                 PYSERVER_COMMON_DNS_TCP_SEND_PENDING,
+                                 ClientFormatter(self.__remote_addr),
+                                 self.__send_marker, total_len)
+                    return self.SENDING
+                logger.warn(PYSERVER_COMMON_DNS_TCP_SEND_ERROR,
+                            ClientFormatter(self.__remote_addr),
+                            self.__send_marker, total_len, ex)
+                self.__sock.close()
+                self.__sock = None
+                return self.CLOSED
+            self.__send_marker += cc
+
+    def close(self):
+        '''Close the socket.
+
+        This method closes the underlying socket.  Once called, the context
+        object is effectively useless; any further method call would result
+        in a DNSTCPContextError exception.
+
+        The underlying socket will be automatically (and implicitly) closed
+        when this object is deallocated, but Python seems to expect socket
+        objects should be explicitly closed before deallocation.  So it's
+        generally advisable for the user of this object to call this method
+        explictily when it doesn't need the context.
+
+        This method can be called more than once or can be called after
+        other I/O related methods have returned CLOSED; it's compatible
+        with the close() method of the Python socket class.
+
+        '''
+        if self.__sock is None:
+            return
+        self.__sock.close()
+        self.__sock = None      # prevent furhter operation

src/lib/python/isc/server_common/logger.py

@@ -0,0 +1,20 @@
+# Copyright (C) 2012  Internet Systems Consortium, Inc. ("ISC")
+#
+# Permission to use, copy, modify, and distribute this software for any
+# purpose with or without fee is hereby granted, provided that the above
+# copyright notice and this permission notice appear in all copies.
+#
+# THE SOFTWARE IS PROVIDED "AS IS" AND INTERNET SYSTEMS CONSORTIUM
+# DISCLAIMS ALL WARRANTIES WITH REGARD TO THIS SOFTWARE INCLUDING ALL
+# IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL
+# INTERNET SYSTEMS CONSORTIUM BE LIABLE FOR ANY SPECIAL, DIRECT,
+# INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES WHATSOEVER RESULTING
+# FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION OF CONTRACT,
+# NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION
+# WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
+
+'''Common definitions regarding logging for the server_common package.'''
+
+import isc.log
+
+logger = isc.log.Logger("server_common")

src/lib/python/isc/server_common/server_common_messages.mes

@@ -27,6 +27,29 @@ There was an invalid name when parsing Auth configuration.
 % PYSERVER_COMMON_AUTH_CONFIG_RRCLASS_ERROR Invalid RRClass when parsing Auth configuration: %1
 There was an invalid RR class when parsing Auth configuration.
 
+% PYSERVER_COMMON_DNS_TCP_SEND_DONE completed sending TCP message to %1 (%2 bytes in total)
+Debug message.  A complete DNS message has been successfully
+transmitted over a TCP connection, possibly after multiple send
+operations.  The destination address and the total size of the message
+(including the 2-byte length field) are shown in the log message.
+
+% PYSERVER_COMMON_DNS_TCP_SEND_ERROR failed to send TCP message to %1 (%2/%3 bytes sent): %4
+A DNS message has been attempted to be sent out over a TCP connection,
+but it failed due to some network error.  Although it's not expected
+to happen too often, it can still happen for various reasons.  The
+administrator may want to examine the cause of the failure, which is
+included in the log message, to see if it requires some action to
+be taken at the server side.  When this message is logged, the
+corresponding  TCP connection was closed immediately after the error
+was detected.
+
+% PYSERVER_COMMON_DNS_TCP_SEND_PENDING sent part TCP message to %1 (up to %2/%3 bytes)
+Debug message.  A part of DNS message has been transmitted over a TCP
+connection, and it's suspended because further attempt would block.
+The destination address and the total size of the message that has
+been transmitted so far (including the 2-byte length field) are shown
+in the log message.
+
 % PYSERVER_COMMON_TSIG_KEYRING_DEINIT Deinitializing global TSIG keyring
 A debug message noting that the global TSIG keyring is being removed from
 memory. Most programs don't do that, they just exit, which is OK.

src/lib/python/isc/server_common/tests/Makefile.am

@@ -1,5 +1,5 @@
 PYCOVERAGE_RUN = @PYCOVERAGE_RUN@
-PYTESTS = tsig_keyring_test.py
+PYTESTS = tsig_keyring_test.py dns_tcp_test.py
 EXTRA_DIST = $(PYTESTS)
 
 # If necessary (rare cases), explicitly specify paths to dynamic libraries

src/lib/python/isc/server_common/tests/dns_tcp_test.py

@@ -0,0 +1,246 @@
+# Copyright (C) 2012  Internet Systems Consortium, Inc. ("ISC")
+#
+# Permission to use, copy, modify, and distribute this software for any
+# purpose with or without fee is hereby granted, provided that the above
+# copyright notice and this permission notice appear in all copies.
+#
+# THE SOFTWARE IS PROVIDED "AS IS" AND INTERNET SYSTEMS CONSORTIUM
+# DISCLAIMS ALL WARRANTIES WITH REGARD TO THIS SOFTWARE INCLUDING ALL
+# IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL
+# INTERNET SYSTEMS CONSORTIUM BE LIABLE FOR ANY SPECIAL, DIRECT,
+# INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES WHATSOEVER RESULTING
+# FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION OF CONTRACT,
+# NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION
+# WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
+
+'''Tests for isc.server_common.dns_tcp'''
+
+import isc.log
+from isc.server_common.dns_tcp import *
+import socket
+import errno
+import unittest
+
+def check_length_field(assert_eq, len_data, expected_len):
+    # Examine the "length field" part of the data.  It should be 2-byte field,
+    # and (in our implementation) always given as a separate chunk of data.
+    # The 16-bit length value of the actual data should be stored in the
+    # network byte order.
+    len_high = (expected_len >> 8) & 0x00ff
+    len_low = (expected_len & 0x00ff)
+    assert_eq(2, len(len_data))
+    assert_eq(len_high, len_data[0])
+    assert_eq(len_low, len_data[1])
+
+class BufferTest(unittest.TestCase):
+    def check_length_field(self, buf, expected_len):
+        '''Common subtest for the main tests that checks the length buffer.'''
+        check_length_field(self.assertEqual, buf.get_data(0), expected_len)
+
+        # Confirm the get_data(1) returns the latter half of the (partial)
+        # buffer.
+        self.assertEqual(1, len(buf.get_data(1)))
+        self.assertEqual(expected_len & 0x00ff, buf.get_data(1)[0])
+
+    def test_small_data(self):
+        # The smallest size (in practice) of data: that of the header field.
+        expected_data = b'x' * 12
+        buf = DNSTCPSendBuffer(expected_data)
+        self.check_length_field(buf, 12)
+
+        self.assertEqual(expected_data, buf.get_data(2))
+        self.assertEqual(b'x' * 11, buf.get_data(3))
+        self.assertEqual(None, buf.get_data(14))
+
+    def test_large_data(self):
+        # Test with an arbitrarily large size of data.
+        buf = DNSTCPSendBuffer(b'x' * 65534)
+        self.check_length_field(buf, 65534)
+        self.assertEqual(b'x' * 65534, buf.get_data(2))
+        self.assertEqual(b'x' * 2, buf.get_data(65534))
+        self.assertEqual(None, buf.get_data(65536))
+
+    def test_largest_data(self):
+        # This is the largest possible size of DNS message.
+        buf = DNSTCPSendBuffer(b'y' * 65535)
+        self.check_length_field(buf, 65535)
+        self.assertEqual(b'y', buf.get_data(65536))
+        self.assertEqual(None, buf.get_data(65537))
+
+    def test_too_large_data(self):
+        # The maximum possible size of a valid DNS message is 65535.
+        # Beyond that, the buffer construction should result in an exception.
+        self.assertRaises(ValueError, DNSTCPSendBuffer, b'0' * 65536)
+
+    def test_empty_data(self):
+        # Unusual, but it's not rejected
+        buf = DNSTCPSendBuffer(b'')
+        self.check_length_field(buf, 0)
+        self.assertEqual(None, buf.get_data(2))
+
+    def test_get_total_len(self):
+        self.assertEqual(14, DNSTCPSendBuffer(b'x' * 12).get_total_len())
+        self.assertEqual(2, DNSTCPSendBuffer(b'').get_total_len())
+        self.assertEqual(65537, DNSTCPSendBuffer(b'X' * 65535).get_total_len())
+
+class FakeSocket:
+    '''Emulating python socket w/o involving IO while allowing inspection.'''
+    def __init__(self, proto=socket.IPPROTO_TCP):
+        self._setblocking_val = None # record the latest value of setblocking()
+        self._closed = False         # set to True on close()
+        self._sent_data = []         # record the transmitted data in send()
+        self._send_buflen = None     # capacity of the faked "send buffer";
+                                     # None means infinity, -1 means "closed"
+        self._send_cc = 0            # waterline of the send buffer
+        self.proto = proto # protocol (should be TCP, but can be faked)
+
+    def setblocking(self, on):
+        self._setblocking_val = on
+
+    def close(self):
+        self._closed = True
+
+    def send(self, data):
+        # Calculate the available space in the "send buffer"
+        if self._send_buflen == -1:
+            raise socket.error(errno.EPIPE, "Broken pipe")
+        elif self._send_buflen is None:
+            available_space = len(data)
+        else:
+            available_space = self._send_buflen - self._send_cc
+        if available_space == 0:
+            # if there's no space, (assuming it's nonblocking mode) raise
+            # EAGAIN.
+            raise socket.error(errno.EAGAIN,
+                               "Resource temporarily unavailable")
+        # determine the sendable part of the data, record it, update "buffer".
+        cc = min(available_space, len(data))
+        self._sent_data.append(data[:cc])
+        self._send_cc += cc
+        return cc
+
+    def make_send_ready(self):
+        # pretend that the accrued data has been cleared, making room in
+        # the send buffer.
+        self._send_cc = 0
+
+    def getpeername(self):
+        '''Return faked remote address'''
+        return ('2001:db8::1', 53000, 0, 0)
+
+class ContextTest(unittest.TestCase):
+    def setUp(self):
+        self.__sock = FakeSocket()
+        # there should be no setblocking value on the fake socket by default.
+        self.assertEqual(None, self.__sock._setblocking_val)
+        self.__ctx = DNSTCPContext(self.__sock)
+        # dummy data that has the same length as the DNS header section:
+        self.__test_data = b'x' * 12
+
+    def test_initialization(self):
+        # Creating a context (in setUp) should make the socket non-blocking.
+        self.assertFalse(self.__sock._setblocking_val)
+
+        # Only a TCP socket is accepted.
+        self.assertRaises(DNSTCPContextError, DNSTCPContext,
+                          FakeSocket(proto=socket.IPPROTO_UDP))
+
+    def test_send_all(self):
+        # By default, a single send() call will send out all data by 2
+        # send() calls: one for the 2-byte length data and the other for the
+        # actual data.
+        self.assertEqual(DNSTCPContext.SEND_DONE,
+                         self.__ctx.send(self.__test_data))
+        self.assertEqual(2, len(self.__sock._sent_data))
+        check_length_field(self.assertEqual, self.__sock._sent_data[0],
+                           len(self.__test_data))
+        self.assertEqual(self.__test_data, self.__sock._sent_data[1])
+
+    def test_send_divided(self):
+        # set the "send buffer" of the fake socket to 7 (half of the size of
+        # len + data).
+        self.__sock._send_buflen = 7
+
+        # The initial send() can only send out the half of the data in
+        # two calls to socket.send(): the first one for the length field,
+        # and the other is for the first 5 bytes of the data
+        self.assertEqual(DNSTCPContext.SENDING,
+                         self.__ctx.send(self.__test_data))
+        self.assertEqual(2, len(self.__sock._sent_data))
+        check_length_field(self.assertEqual, self.__sock._sent_data[0],
+                           len(self.__test_data))
+        self.assertEqual(self.__test_data[:5], self.__sock._sent_data[1])
+
+        # "flush" the send buffer of the fake socket
+        self.__sock.make_send_ready()
+
+        # send_ready() can now complete the send.  The remaining data should
+        # have been passed.
+        self.assertEqual(DNSTCPContext.SEND_DONE, self.__ctx.send_ready())
+        self.assertEqual(3, len(self.__sock._sent_data))
+        self.assertEqual(self.__test_data[5:], self.__sock._sent_data[2])
+
+    def test_send_multi(self):
+        # On a successful completion of send, another send can be done.
+        for i in (0, 2):
+            self.assertEqual(DNSTCPContext.SEND_DONE,
+                             self.__ctx.send(self.__test_data))
+            self.assertEqual(i + 2, len(self.__sock._sent_data))
+            check_length_field(self.assertEqual, self.__sock._sent_data[i],
+                               len(self.__test_data))
+            self.assertEqual(self.__test_data, self.__sock._sent_data[i + 1])
+
+    def test_send_reset(self):
+        # the connection will be "reset" before the initial send.
+        # send() should return CLOSED, and the underlying socket should be
+        # closed.
+        self.__sock._send_buflen = -1
+        self.assertEqual(DNSTCPContext.CLOSED,
+                         self.__ctx.send(self.__test_data))
+        self.assertTrue(self.__sock._closed)
+
+        # Once closed, send() cannot be called any more
+        self.assertRaises(DNSTCPContextError, self.__ctx.send,
+                          self.__test_data)
+        # Calling close() is okay (it's NO-OP)
+        self.__ctx.close()
+
+    def test_send_divided_reset(self):
+        # Similar to send_reset, but send() succeeds, and then the connection
+        # will be "reset".
+        self.__sock._send_buflen = 7
+        self.assertEqual(DNSTCPContext.SENDING,
+                         self.__ctx.send(self.__test_data))
+        self.__sock._send_buflen = -1
+        self.assertEqual(DNSTCPContext.CLOSED, self.__ctx.send_ready())
+        self.assertTrue(self.__sock._closed)
+
+        # Once closed, send_ready() cannot be called any more
+        self.assertRaises(DNSTCPContextError, self.__ctx.send_ready)
+
+    def test_duplicate_send(self):
+        # send() cannot be called until it's completed
+        self.__sock._send_buflen = 7
+        self.assertEqual(DNSTCPContext.SENDING,
+                         self.__ctx.send(self.__test_data))
+        self.assertRaises(DNSTCPContextError, self.__ctx.send,
+                          self.__test_data)
+
+    def test_skip_send(self):
+        # send_ready() cannot be called before send().
+        self.assertRaises(DNSTCPContextError, self.__ctx.send_ready)
+
+    def test_close(self):
+        self.assertEqual(DNSTCPContext.SEND_DONE,
+                         self.__ctx.send(self.__test_data))
+        self.__ctx.close()
+        self.assertTrue(self.__sock._closed)
+
+        # Duplicate close is just ignored, and the socket is still closed.
+        self.__ctx.close()
+        self.assertTrue(self.__sock._closed)
+
+if __name__ == "__main__":
+    isc.log.init("bind10")
+    isc.log.resetUnitTestRootLogger()
+    unittest.main()

src/lib/python/isc/server_common/tsig_keyring.py

@@ -20,10 +20,10 @@ tsig_keys module.
 
 import isc.dns
 import isc.log
+from isc.server_common.logger import logger
 from isc.log_messages.server_common_messages import *
 
 updater = None
-logger = isc.log.Logger("server_common")
 
 class Unexpected(Exception):
     """