[master] Merge branch 'trac2879'

src/lib/python/isc/notify/notify_out.py

@@ -41,7 +41,6 @@ ZONE_XFRIN_FAILED = 'zone_xfrin_failed'
 
 _MAX_NOTIFY_NUM = 30
 _MAX_NOTIFY_TRY_NUM = 5
-_EVENT_NONE = 0
 _EVENT_READ = 1
 _EVENT_TIMEOUT = 2
 _NOTIFY_TIMEOUT = 1
@@ -211,7 +210,8 @@ class NotifyOut:
 
             for name_ in not_replied_zones:
                 if not_replied_zones[name_].notify_timeout <= time.time():
-                    self._zone_notify_handler(not_replied_zones[name_], _EVENT_TIMEOUT)
+                    self._zone_notify_handler(not_replied_zones[name_],
+                                              _EVENT_TIMEOUT)
 
     def dispatcher(self, daemon=False):
         """Spawns a thread that will handle notify related events.
@@ -421,20 +421,45 @@ class NotifyOut:
         return replied_zones, not_replied_zones
 
     def _zone_notify_handler(self, zone_notify_info, event_type):
-        '''Notify handler for one zone. The first notify message is
-        always triggered by the event "_EVENT_TIMEOUT" since when
-        one zone prepares to notify its slaves, its notify_timeout
-        is set to now, which is used to trigger sending notify
-        message when dispatcher() scanning zones. '''
+        """Notify handler for one zone.
+
+        For the event type of _EVENT_READ, this method reads a new notify
+        response message from the corresponding socket.  If it succeeds
+        and the response is the expected one, it will send another notify
+        to the next slave for the zone (if any) or the next zone (if any)
+        waiting for its turn of sending notifies.
+
+        In the case of _EVENT_TIMEOUT, or if the read fails or the response
+        is not an expected one in the case of _EVENT_READ, this method will
+        resend the notify request to the same slave up to _MAX_NOTIFY_TRY_NUM
+        times.  If it reaches the max, it will swith to the next slave or
+        the next zone like the successful case above.
+
+        The first notify message is always triggered by the event
+        "_EVENT_TIMEOUT" since when one zone prepares to notify its slaves,
+        its notify_timeout is set to now, which is used to trigger sending
+        notify message when dispatcher() scanning zones.
+
+        Parameters:
+        zone_notify_info(ZoneNotifyInfo): the notify context for the event
+        event_type(int): either _EVENT_READ or _EVENT_TIMEOUT constant
+
+        """
         tgt = zone_notify_info.get_current_notify_target()
         if event_type == _EVENT_READ:
+            # Note: _get_notify_reply() should also check the response's
+            # source address (see #2924).  When it's done the following code
+            # should also be adjusted a bit.
             reply = self._get_notify_reply(zone_notify_info.get_socket(), tgt)
             if reply is not None:
-                if self._handle_notify_reply(zone_notify_info, reply, tgt):
+                if (self._handle_notify_reply(zone_notify_info, reply, tgt) ==
+                    _REPLY_OK):
                     self._notify_next_target(zone_notify_info)
 
-        elif event_type == _EVENT_TIMEOUT and zone_notify_info.notify_try_num > 0:
-            logger.info(NOTIFY_OUT_TIMEOUT, AddressFormatter(tgt))
+        else:
+            assert event_type == _EVENT_TIMEOUT
+            if zone_notify_info.notify_try_num > 0:
+                logger.info(NOTIFY_OUT_TIMEOUT, AddressFormatter(tgt))
 
         tgt = zone_notify_info.get_current_notify_target()
         if tgt:
@@ -444,8 +469,9 @@ class NotifyOut:
                             _MAX_NOTIFY_TRY_NUM)
                 self._notify_next_target(zone_notify_info)
             else:
-                # set exponential backoff according rfc1996 section 3.6
-                retry_timeout = _NOTIFY_TIMEOUT * pow(2, zone_notify_info.notify_try_num)
+                # set exponential backoff according to rfc1996 section 3.6
+                retry_timeout = (_NOTIFY_TIMEOUT *
+                                 pow(2, zone_notify_info.notify_try_num))
                 zone_notify_info.notify_timeout = time.time() + retry_timeout
                 self._send_notify_message_udp(zone_notify_info, tgt)
 
@@ -537,9 +563,12 @@ class NotifyOut:
         return soa_rrset
 
     def _handle_notify_reply(self, zone_notify_info, msg_data, from_addr):
-        '''Parse the notify reply message.
-        rcode will not checked here, If we get the response
-        from the slave, it means the slaves has got the notify.'''
+        """Parse the notify reply message.
+
+        rcode will not be checked here; if we get the response
+        from the slave, it means the slave got the notify.
+
+        """
         msg = Message(Message.PARSE)
         try:
             msg.from_wire(msg_data)
@@ -574,7 +603,7 @@ class NotifyOut:
 
         logger.debug(logger.DBGLVL_TRACE_BASIC, NOTIFY_OUT_REPLY_RECEIVED,
                      zone_notify_info.zone_name, zone_notify_info.zone_class,
-                     from_addr[0], from_addr[1], msg.get_rcode())
+                     AddressFormatter(from_addr), msg.get_rcode())
 
         return _REPLY_OK
 

src/lib/python/isc/notify/notify_out_messages.mes

@@ -60,7 +60,7 @@ given address, but the reply did not have the QR bit set to one.
 Since there was a response, no more notifies will be sent to this
 server for this notification event.
 
-% NOTIFY_OUT_REPLY_RECEIVED Zone %1/%2: notify response from %3:%4: %5
+% NOTIFY_OUT_REPLY_RECEIVED Zone %1/%2: notify response from %3: %4
 The notify_out library sent a notify message to the nameserver at
 the given address, and received a response.  Its Rcode will be shown,
 too.

src/lib/python/isc/notify/tests/notify_out_test.py

@@ -25,10 +25,32 @@ from isc.dns import *
 
 TESTDATA_SRCDIR = os.getenv("TESTDATASRCDIR")
 
+def get_notify_msgdata(zone_name, qid=0):
+    """A helper function to generate a notify response in wire format.
+
+    Parameters:
+    zone_name(isc.dns.Name()) The zone name for the notify.  Used as the
+    question name.
+    qid (int): The QID of the response.  In most test cases a value of 0 is
+    expected.
+
+    """
+    m = Message(Message.RENDER)
+    m.set_opcode(Opcode.NOTIFY)
+    m.set_rcode(Rcode.NOERROR)
+    m.set_qid(qid)
+    m.set_header_flag(Message.HEADERFLAG_QR)
+    m.add_question(Question(zone_name, RRClass.IN, RRType.SOA))
+
+    renderer = MessageRenderer()
+    m.to_wire(renderer)
+    return renderer.get_data()
+
 # our fake socket, where we can read and insert messages
 class MockSocket():
     def __init__(self):
         self._local_sock, self._remote_sock = socket.socketpair()
+        self.__raise_on_recv = False # see set_raise_on_recv()
 
     def connect(self, to):
         pass
@@ -44,6 +66,8 @@ class MockSocket():
         return self._local_sock.send(data)
 
     def recvfrom(self, length):
+        if self.__raise_on_recv:
+            raise socket.error('fake error')
         data = self._local_sock.recv(length)
         return (data, None)
 
@@ -51,6 +75,14 @@ class MockSocket():
     def remote_end(self):
         return self._remote_sock
 
+    def set_raise_on_recv(self, on):
+        """A helper to force recvfrom() to raise an exception or cancel it.
+
+        The next call to recvfrom() will result in an exception iff parameter
+        'on' (bool) is set to True.
+        """
+        self.__raise_on_recv = on
+
 # We subclass the ZoneNotifyInfo class we're testing here, only
 # to override the create_socket() method.
 class MockZoneNotifyInfo(notify_out.ZoneNotifyInfo):
@@ -79,12 +111,12 @@ class TestZoneNotifyInfo(unittest.TestCase):
 
     def test_set_next_notify_target(self):
         self.info.notify_slaves.append(('127.0.0.1', 53))
-        self.info.notify_slaves.append(('1.1.1.1', 5353))
+        self.info.notify_slaves.append(('192.0.2.1', 5353))
         self.info.prepare_notify_out()
         self.assertEqual(self.info.get_current_notify_target(), ('127.0.0.1', 53))
 
         self.info.set_next_notify_target()
-        self.assertEqual(self.info.get_current_notify_target(), ('1.1.1.1', 5353))
+        self.assertEqual(self.info.get_current_notify_target(), ('192.0.2.1', 5353))
         self.info.set_next_notify_target()
         self.assertIsNone(self.info.get_current_notify_target())
 
@@ -105,14 +137,18 @@ class TestNotifyOut(unittest.TestCase):
 
         net_info = self._notify._notify_infos[('example.net.', 'IN')]
         net_info.notify_slaves.append(('127.0.0.1', 53))
-        net_info.notify_slaves.append(('1.1.1.1', 5353))
+        net_info.notify_slaves.append(('192.0.2.1', 5353))
         com_info = self._notify._notify_infos[('example.com.', 'IN')]
-        com_info.notify_slaves.append(('1.1.1.1', 5353))
+        com_info.notify_slaves.append(('192.0.2.1', 5353))
         com_ch_info = self._notify._notify_infos[('example.com.', 'CH')]
-        com_ch_info.notify_slaves.append(('1.1.1.1', 5353))
+        com_ch_info.notify_slaves.append(('192.0.2.1', 5353))
+        # Keep the original library version in case a test case replaces it
+        self.__time_time_orig = notify_out.time.time
 
     def tearDown(self):
         self._notify._counters.clear_all()
+        # restore the original time.time() in case it was replaced.
+        notify_out.time.time = self.__time_time_orig
 
     def test_send_notify(self):
         notify_out._MAX_NOTIFY_NUM = 2
@@ -221,7 +257,7 @@ class TestNotifyOut(unittest.TestCase):
         info = self._notify._notify_infos[('example.net.', 'IN')]
         self._notify._notify_next_target(info)
         self.assertEqual(0, info.notify_try_num)
-        self.assertEqual(info.get_current_notify_target(), ('1.1.1.1', 5353))
+        self.assertEqual(info.get_current_notify_target(), ('192.0.2.1', 5353))
         self.assertEqual(2, self._notify.notify_num)
         self.assertEqual(1, len(self._notify._waiting_zones))
 
@@ -328,39 +364,86 @@ class TestNotifyOut(unittest.TestCase):
                           'zones', 'example.net.', 'notifyoutv4')
 
     def test_zone_notify_handler(self):
-        old_send_msg = self._notify._send_notify_message_udp
-        def _fake_send_notify_message_udp(va1, va2):
+        sent_addrs = []
+        def _fake_send_notify_message_udp(notify_info, addrinfo):
+            sent_addrs.append(addrinfo)
             pass
+        notify_out.time.time = lambda: 42
         self._notify._send_notify_message_udp = _fake_send_notify_message_udp
         self._notify.send_notify('example.net.')
-        self._notify.send_notify('example.com.')
-        notify_out._MAX_NOTIFY_NUM = 2
-        self._notify.send_notify('example.org.')
 
         example_net_info = self._notify._notify_infos[('example.net.', 'IN')]
-        example_net_info.prepare_notify_out()
 
+        # On timeout, the request will be resent until try_num reaches the max
+        self.assertEqual([], sent_addrs)
         example_net_info.notify_try_num = 2
-        self._notify._zone_notify_handler(example_net_info, notify_out._EVENT_TIMEOUT)
+        self._notify._zone_notify_handler(example_net_info,
+                                          notify_out._EVENT_TIMEOUT)
         self.assertEqual(3, example_net_info.notify_try_num)
-
-        time1 = example_net_info.notify_timeout
-        self._notify._zone_notify_handler(example_net_info, notify_out._EVENT_TIMEOUT)
-        self.assertEqual(4, example_net_info.notify_try_num)
-        self.assertGreater(example_net_info.notify_timeout, time1 + 2) # bigger than 2 seconds
-
+        self.assertEqual([('127.0.0.1', 53)], sent_addrs)
+        # the timeout time will be set to "current time(=42)"+2**(new try_num)
+        self.assertEqual(42 + 2**3, example_net_info.notify_timeout)
+
+        # If try num exceeds max, the next slave will be tried (and then
+        # next zone, but for this test it sufficies to check the former case)
+        example_net_info.notify_try_num = 5
+        self._notify._zone_notify_handler(example_net_info,
+                                          notify_out._EVENT_TIMEOUT)
+        self.assertEqual(0, example_net_info.notify_try_num) # should be reset
+        self.assertEqual(('192.0.2.1', 5353), example_net_info._notify_current)
+
+        # Possible event is "read" or "timeout".
         cur_tgt = example_net_info._notify_current
         example_net_info.notify_try_num = notify_out._MAX_NOTIFY_TRY_NUM
-        self._notify._zone_notify_handler(example_net_info, notify_out._EVENT_NONE)
-        self.assertNotEqual(cur_tgt, example_net_info._notify_current)
+        self.assertRaises(AssertionError, self._notify._zone_notify_handler,
+                          example_net_info, notify_out._EVENT_TIMEOUT + 1)
 
-        cur_tgt = example_net_info._notify_current
+    def test_zone_notify_read_handler(self):
+        """Similar to the previous test, but focus on the READ events.
+
+        """
+        sent_addrs = []
+        def _fake_send_notify_message_udp(notify_info, addrinfo):
+            sent_addrs.append(addrinfo)
+            pass
+        self._notify._send_notify_message_udp = _fake_send_notify_message_udp
+        self._notify.send_notify('example.net.')
+
+        example_net_info = self._notify._notify_infos[('example.net.', 'IN')]
         example_net_info.create_socket('127.0.0.1')
-        # dns message, will result in bad_qid, but what we are testing
-        # here is whether handle_notify_reply is called correctly
-        example_net_info._sock.remote_end().send(b'\x2f\x18\xa0\x00\x00\x01\x00\x00\x00\x00\x00\x00\x07example\03com\x00\x00\x06\x00\x01')
-        self._notify._zone_notify_handler(example_net_info, notify_out._EVENT_READ)
-        self.assertNotEqual(cur_tgt, example_net_info._notify_current)
+
+        # A successful case: an expected notify response is received, and
+        # another notify will be sent to the next slave immediately.
+        example_net_info._sock.remote_end().send(
+            get_notify_msgdata(Name('example.net')))
+        self._notify._zone_notify_handler(example_net_info,
+                                          notify_out._EVENT_READ)
+        self.assertEqual(1, example_net_info.notify_try_num)
+        expected_sent_addrs = [('192.0.2.1', 5353)]
+        self.assertEqual(expected_sent_addrs, sent_addrs)
+        self.assertEqual(('192.0.2.1', 5353), example_net_info._notify_current)
+
+        # response's QID doesn't match.  the request will be resent.
+        example_net_info._sock.remote_end().send(
+            get_notify_msgdata(Name('example.net'), qid=1))
+        self._notify._zone_notify_handler(example_net_info,
+                                          notify_out._EVENT_READ)
+        self.assertEqual(2, example_net_info.notify_try_num)
+        expected_sent_addrs.append(('192.0.2.1', 5353))
+        self.assertEqual(expected_sent_addrs, sent_addrs)
+        self.assertEqual(('192.0.2.1', 5353), example_net_info._notify_current)
+
+        # emulate exception from socket.recvfrom().  It will have the same
+        # effect as a bad response.
+        example_net_info._sock.set_raise_on_recv(True)
+        example_net_info._sock.remote_end().send(
+            get_notify_msgdata(Name('example.net')))
+        self._notify._zone_notify_handler(example_net_info,
+                                          notify_out._EVENT_READ)
+        self.assertEqual(3, example_net_info.notify_try_num)
+        expected_sent_addrs.append(('192.0.2.1', 5353))
+        self.assertEqual(expected_sent_addrs, sent_addrs)
+        self.assertEqual(('192.0.2.1', 5353), example_net_info._notify_current)
 
     def test_get_notify_slaves_from_ns(self):
         records = self._notify._get_notify_slaves_from_ns(Name('example.net.'),

tests/lettuce/features/xfrin_notify_handling.feature

@@ -81,8 +81,8 @@ Feature: Xfrin incoming notify handling
     last bindctl output should not contain "error"
     Then the statistics counter notifyoutv4 for the zone _SERVER_ should be 0
     Then the statistics counter notifyoutv4 for the zone example.org. should be 0
-    Then the statistics counter notifyoutv6 for the zone _SERVER_ should be 5
-    Then the statistics counter notifyoutv6 for the zone example.org. should be 5
+    Then the statistics counter notifyoutv6 for the zone _SERVER_ should be 1
+    Then the statistics counter notifyoutv6 for the zone example.org. should be 1
     Then the statistics counter xfrrej for the zone _SERVER_ should be 0
     Then the statistics counter xfrrej for the zone example.org. should be 0
     Then the statistics counter xfrreqdone for the zone _SERVER_ should be 1
@@ -184,8 +184,8 @@ Feature: Xfrin incoming notify handling
     last bindctl output should not contain "error"
     Then the statistics counter notifyoutv4 for the zone _SERVER_ should be 0
     Then the statistics counter notifyoutv4 for the zone example.org. should be 0
-    Then the statistics counter notifyoutv6 for the zone _SERVER_ should be 5
-    Then the statistics counter notifyoutv6 for the zone example.org. should be 5
+    Then the statistics counter notifyoutv6 for the zone _SERVER_ should be 1
+    Then the statistics counter notifyoutv6 for the zone example.org. should be 1
     # The counts of rejection would be between 1 and 2. They are not
     # fixed. It would depend on timing or the platform.
     Then the statistics counter xfrrej for the zone _SERVER_ should be greater than 0