[1512] log events when update request somehow failed.

src/lib/python/isc/ddns/libddns_messages.mes

@@ -14,3 +14,6 @@
 
 # No namespace declaration - these constants go in the global namespace
 # of the libddns_messages python module.
+
+% LIBDDNS_UPDATE_ERROR client %1 for zone %2: %3
+TBD

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

@@ -0,0 +1,77 @@
+# Copyright (C) 2012  Internet Systems Consortium.
+#
+# 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.
+
+""" This is a logging utility module for other modules of the ddns library
+package.
+
+"""
+
+import isc.log
+
+# The logger for this package
+logger = isc.log.Logger('libddns')
+
+class ClientFormatter:
+    """A utility class to convert a client address to string.
+
+    This class is constructed with a Python standard socket address tuple.
+    If it's 2-element tuple, it's assumed to be an IPv4 socket address
+    and will be converted to the form of '<addr>:<port>'.
+    If it's 4-element tuple, it's assumed to be an IPv6 socket address.
+    and will be converted to the form of '[<addr>]:<por>'.
+
+    This class is designed to delay the conversion until it's explicitly
+    requested, so the conversion doesn't happen if the corresponding log
+    message is suppressed because of its log level (which is often the case
+    for debug messages).
+
+    """
+    def __init__(self, addr):
+        self.__addr = addr
+
+    def __str__(self):
+        if len(self.__addr) == 2:
+            return self.__addr[0] + ':' + str(self.__addr[1])
+        elif len(self.__addr) == 4:
+            return '[' + self.__addr[0] + ']:' + str(self.__addr[1])
+        return None
+
+class ZoneFormatter:
+    """A utility class to convert zone name and class to string.
+
+    This class is constructed with a name of a zone (isc.dns.Name object)
+    and its RR class (isc.dns.RRClass object).  Its text conversion method
+    (__str__) converts them into a string in the form of
+    '<zone name>/<zone class>' where the trailing dot of the zone name
+    is omitted.
+
+    If the given zone name on construction is None, it's assumed to be
+    the zone isn't identified but needs to be somehow logged.  The conversion
+    method returns a special string to indicate this case.
+
+    This class is designed to delay the conversion until it's explicitly
+    requested, so the conversion doesn't happen if the corresponding log
+    message is suppressed because of its log level (which is often the case
+    for debug messages).
+
+    """
+    def __init__(self, zname, zclass):
+        self.__zname = zname
+        self.__zclass = zclass
+
+    def __str__(self):
+        if self.__zname is None:
+            return '(zone unknown/not determined)'
+        return self.__zname.to_text(True) + '/' + self.__zclass.to_text()

src/lib/python/isc/ddns/session.py

@@ -13,8 +13,11 @@
 # NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION
 # WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
 
-import isc.dns
+from isc.dns import *
 import isc.ddns.zone_config
+from isc.log import *
+from isc.ddns.logger import logger, ClientFormatter, ZoneFormatter
+from isc.log_messages.libddns_messages import *
 
 # Result codes for UpdateSession.handle()
 UPDATE_SUCCESS = 0
@@ -22,13 +25,15 @@ UPDATE_ERROR = 1
 UPDATE_DROP = 2
 
 # Convenient aliases of update-specific section names
-SECTION_ZONE = isc.dns.Message.SECTION_QUESTION
-SECTION_PREREQUISITE = isc.dns.Message.SECTION_ANSWER
-SECTION_UPDATE = isc.dns.Message.SECTION_AUTHORITY
-
-class ZoneError(Exception):
-    def __init__(self, msg, rcode):
-        Exception(msg)
+SECTION_ZONE = Message.SECTION_QUESTION
+SECTION_PREREQUISITE = Message.SECTION_ANSWER
+SECTION_UPDATE = Message.SECTION_AUTHORITY
+
+class UpdateError(Exception):
+    def __init__(self, msg, zname, zclass, rcode):
+        Exception.__init__(self, msg)
+        self.zname = zname
+        self.zclass = zclass
         self.rcode = rcode
 
 class UpdateSession:
@@ -39,6 +44,7 @@ class UpdateSession:
     '''
     def __init__(self, req_message, req_data, client_addr, zone_config):
         self.__message = req_message
+        self.__client_addr = client_addr
         self.__zone_config = zone_config
 
     def get_message(self):
@@ -77,7 +83,10 @@ class UpdateSession:
             # self.__do_update()
             # self.__make_response(Rcode.NOERROR())
             return UPDATE_SUCCESS, zname, zclass
-        except ZoneError as e:
+        except UpdateError as e:
+            logger.debug(logger.DBGLVL_TRACE_BASIC, LIBDDNS_UPDATE_ERROR,
+                         ClientFormatter(self.__client_addr),
+                         ZoneFormatter(e.zname, e.zclass), e)
             self.__make_response(e.rcode)
         return UPDATE_ERROR, None, None
 
@@ -93,13 +102,14 @@ class UpdateSession:
         '''
         # Validation: the zone section must contain exactly one question,
         # and it must be of type SOA.
-        if self.__message.get_rr_count(SECTION_ZONE) != 1:
-            raise ZoneError('Invalid number of records in zone section: ' +
-                            str(1), isc.dns.Rcode.FORMERR())
+        n_zones = self.__message.get_rr_count(SECTION_ZONE)
+        if n_zones != 1:
+            raise UpdateError('Invalid number of records in zone section: ' +
+                              str(n_zones), None, None, Rcode.FORMERR())
         zrecord = self.__message.get_question()[0]
-        if zrecord.get_type() != isc.dns.RRType.SOA():
-            raise ZoneError('update zone section contains non-SOA',
-                            isc.dns.Rcode.FORMERR())
+        if zrecord.get_type() != RRType.SOA():
+            raise UpdateError('update zone section contains non-SOA',
+                              None, None, Rcode.FORMERR())
 
         # See if we're serving a primary zone specified in the zone section.
         zname = zrecord.get_name()
@@ -109,8 +119,8 @@ class UpdateSession:
             return datasrc_client, zname, zclass
         elif zone_type == isc.ddns.zone_config.ZONE_SECONDARY:
             # unconditionally refused forwarding (we don't support it yet)
-            raise ZoneError('Update forwarding not supported',
-                            isc.dns.Rcode.REFUSED())
+            raise UpdateError('Update forwarding not supported',
+                              zname, zclass, Rcode.REFUSED())
 
     def __make_response(self, rcode):
         '''Transform the internal message to the update response.

src/lib/python/isc/ddns/tests/session_tests.py

@@ -24,6 +24,8 @@ TEST_ZONE_NAME = Name('example.com')
 UPDATE_RRTYPE = RRType.SOA()
 TEST_RRCLASS = RRClass.IN()
 TEST_ZONE_RECORD = Question(TEST_ZONE_NAME, TEST_RRCLASS, UPDATE_RRTYPE)
+TEST_CLIENT6 = ('2001:db8::1', 53, 0, 0)
+TEST_CLIENT4 = ('192.0.2.1', 53)
 
 def create_update_msg(zones=[TEST_ZONE_RECORD]):
     msg = Message(Message.RENDER)
@@ -45,11 +47,9 @@ def create_update_msg(zones=[TEST_ZONE_RECORD]):
 class SessionTest(unittest.TestCase):
     '''Session tests'''
     def setUp(self):
-        self.__client_addr = ('192.0.2.1', 53)
         self.__update_msgdata, self.__update_msg = create_update_msg()
         self.__session = UpdateSession(self.__update_msg,
-                                       self.__update_msgdata,
-                                       self.__client_addr,
+                                       self.__update_msgdata, TEST_CLIENT4,
                                        ZoneConfig([(Name("example.org"),
                                                     TEST_RRCLASS)]))
 
@@ -67,7 +67,7 @@ class SessionTest(unittest.TestCase):
     def test_broken_request(self):
         # Zone section is empty
         msg_data, msg = create_update_msg(zones=[])
-        session = UpdateSession(msg, msg_data, None, None)
+        session = UpdateSession(msg, msg_data, TEST_CLIENT6, None)
         result, zname, zclass = session.handle()
         self.assertEqual(UPDATE_ERROR, result)
         self.assertEqual(None, zname)
@@ -77,7 +77,7 @@ class SessionTest(unittest.TestCase):
         # Zone section contains multiple records
         msg_data, msg = create_update_msg(zones=[TEST_ZONE_RECORD,
                                                  TEST_ZONE_RECORD])
-        session = UpdateSession(msg, msg_data, None, None)
+        session = UpdateSession(msg, msg_data, TEST_CLIENT4, None)
         self.assertEqual(UPDATE_ERROR, session.handle()[0])
         self.check_response(session.get_message(), Rcode.FORMERR())
 
@@ -85,7 +85,7 @@ class SessionTest(unittest.TestCase):
         msg_data, msg = create_update_msg(zones=[Question(TEST_ZONE_NAME,
                                                           TEST_RRCLASS,
                                                           RRType.A())])
-        session = UpdateSession(msg, msg_data, None, None)
+        session = UpdateSession(msg, msg_data, TEST_CLIENT4, None)
         self.assertEqual(UPDATE_ERROR, session.handle()[0])
         self.check_response(session.get_message(), Rcode.FORMERR())
 
@@ -97,7 +97,7 @@ class SessionTest(unittest.TestCase):
         msg_data, msg = create_update_msg(zones=[Question(sec_zone,
                                                           TEST_RRCLASS,
                                                           RRType.SOA())])
-        session = UpdateSession(msg, msg_data, None,
+        session = UpdateSession(msg, msg_data, TEST_CLIENT4,
                                 ZoneConfig([(sec_zone, TEST_RRCLASS)]))
         self.assertEqual(UPDATE_ERROR, session.handle()[0])
         self.check_response(session.get_message(), Rcode.REFUSED())

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

@@ -12,6 +12,7 @@ EXTRA_DIST += zonemgr_messages.py
 EXTRA_DIST += cfgmgr_messages.py
 EXTRA_DIST += config_messages.py
 EXTRA_DIST += notify_out_messages.py
+EXTRA_DIST += libddns_messages.py
 EXTRA_DIST += libxfrin_messages.py
 EXTRA_DIST += server_common_messages.py
 EXTRA_DIST += dbutil_messages.py
@@ -28,6 +29,7 @@ CLEANFILES += zonemgr_messages.pyc
 CLEANFILES += cfgmgr_messages.pyc
 CLEANFILES += config_messages.pyc
 CLEANFILES += notify_out_messages.pyc
+CLEANFILES += libddns_messages.pyc
 CLEANFILES += libxfrin_messages.pyc
 CLEANFILES += server_common_messages.pyc
 CLEANFILES += dbutil_messages.pyc

src/lib/python/isc/log_messages/libddns_messages.py

@@ -0,0 +1 @@
+from work.libddns_messages import *