Merge branch 'trac762'

src/bin/xfrout/Makefile.am

@@ -6,11 +6,12 @@ pkglibexec_SCRIPTS = b10-xfrout
 
 b10_xfroutdir = $(pkgdatadir)
 b10_xfrout_DATA = xfrout.spec
+pyexec_DATA = xfrout_messages.py
 
-CLEANFILES=	b10-xfrout xfrout.pyc xfrout.spec
+CLEANFILES=	b10-xfrout xfrout.pyc xfrout.spec xfrout_messages.py xfrout_messages.pyc
 
 man_MANS = b10-xfrout.8
-EXTRA_DIST = $(man_MANS) b10-xfrout.xml
+EXTRA_DIST = $(man_MANS) b10-xfrout.xml xfrout_messages.mes
 
 if ENABLE_MAN
 
@@ -19,12 +20,15 @@ b10-xfrout.8: b10-xfrout.xml
 
 endif
 
+# Define rule to build logging source files from message file
+xfrout_messages.py: xfrout_messages.mes
+	$(top_builddir)/src/lib/log/compiler/message -p $(top_srcdir)/src/bin/xfrout/xfrout_messages.mes
 
 xfrout.spec: xfrout.spec.pre
 	$(SED) -e "s|@@LOCALSTATEDIR@@|$(localstatedir)|" xfrout.spec.pre >$@
 
 # this is done here since configure.ac AC_OUTPUT doesn't expand exec_prefix
-b10-xfrout: xfrout.py
+b10-xfrout: xfrout.py xfrout_messages.py
 	$(SED) -e "s|@@PYTHONPATH@@|@pyexecdir@|" \
 	       -e "s|@@LOCALSTATEDIR@@|$(localstatedir)|" xfrout.py >$@
 	chmod a+x $@

src/bin/xfrout/xfrout.py.in

@@ -26,7 +26,6 @@ from isc.datasrc import sqlite3_ds
 from socketserver import *
 import os
 from isc.config.ccsession import *
-#from isc.log.log import *
 from isc.cc import SessionError, SessionTimeout
 from isc.notify import notify_out
 import isc.util.process
@@ -36,13 +35,18 @@ import errno
 from optparse import OptionParser, OptionValueError
 from isc.util import socketserver_mixin
 
+from xfrout_messages import *
+
+isc.log.init("b10-xfrout")
+logger = isc.log.Logger("xfrout")
+
 try:
     from libutil_io_python import *
     from pydnspp import *
 except ImportError as e:
     # C++ loadable module may not be installed; even so the xfrout process
     # must keep running, so we warn about it and move forward.
-    sys.stderr.write('[b10-xfrout] failed to import DNS or isc.util.io module: %s\n' % str(e))
+    log.error(XFROUT_IMPORT, str(e))
 
 isc.util.process.rename()
 
@@ -110,7 +114,7 @@ class XfroutSession():
             self.dns_xfrout_start(self._sock_fd, self._request_data)
             #TODO, avoid catching all exceptions
         except Exception as e:
-            #self._log.log_message("error", str(e))
+            logger.error(XFROUT_HANDLE_QUERY_ERROR, str(e))
             pass
 
         os.close(self._sock_fd)
@@ -138,7 +142,7 @@ class XfroutSession():
             rcode = self._check_request_tsig(msg, mdata)
 
         except Exception as err:
-            #self._log.log_message("error", str(err))
+            logger.error(XFROUT_PARSE_QUERY_ERROR, str(err))
             return Rcode.FORMERR(), None
 
         return rcode, msg
@@ -147,6 +151,9 @@ class XfroutSession():
         question = msg.get_question()[0]
         return question.get_name().to_text()
 
+    def _get_query_zone_class(self, msg):
+        question = msg.get_question()[0]
+        return question.get_class().to_text()
 
     def _send_data(self, sock_fd, data):
         size = len(data)
@@ -243,19 +250,23 @@ class XfroutSession():
             return self._reply_query_with_format_error(msg, sock_fd)
 
         zone_name = self._get_query_zone_name(msg)
+        zone_class_str = self._get_query_zone_class(msg)
+        # TODO: should we not also include class in the check?
         rcode_ = self._check_xfrout_available(zone_name)
+
         if rcode_ != Rcode.NOERROR():
-            #self._log.log_message("info", "transfer of '%s/IN' failed: %s",
-            #                      zone_name, rcode_.to_text())
+            logger.info(XFROUT_AXFR_TRANSFER_FAILED, zone_name,
+                        zone_class_str, rcode_.to_text())
             return self. _reply_query_with_error_rcode(msg, sock_fd, rcode_)
 
         try:
-            #self._log.log_message("info", "transfer of '%s/IN': AXFR started" % zone_name)
+            logger.info(XFROUT_AXFR_TRANSFER_STARTED, zone_name, zone_class_str)
             self._reply_xfrout_query(msg, sock_fd, zone_name)
-            #self._log.log_message("info", "transfer of '%s/IN': AXFR end" % zone_name)
         except Exception as err:
-            #self._log.log_message("error", str(err))
+            logger.error(XFROUT_AXFR_TRANSFER_ERROR, zone_name,
+                         zone_class_str, str(err))
             pass
+        logger.info(XFROUT_AXFR_TRANSFER_DONE, zone_name, zone_class_str)
 
         self._server.decrease_transfers_counter()
         return
@@ -319,7 +330,7 @@ class XfroutSession():
 
         for rr_data in sqlite3_ds.get_zone_datas(zone_name, self._server.get_db_file()):
             if  self._server._shutdown_event.is_set(): # Check if xfrout is shutdown
-                #self._log.log_message("info", "xfrout process is being shutdown")
+                logger.info(XFROUT_STOPPING)
                 return
             # TODO: RRType.SOA() ?
             if RRType(rr_data[5]) == RRType("SOA"): #ignore soa record
@@ -396,7 +407,7 @@ class UnixSockServer(socketserver_mixin.NoPollMixIn, ThreadingUnixStreamServer):
         try:
             request, client_address = self.get_request()
         except socket.error:
-            #self._log.log_message("error", "Failed to fetch request")
+            logger.error(XFROUT_FETCH_REQUEST_ERROR)
             return
 
         # Check self._shutdown_event to ensure the real shutdown comes.
@@ -410,7 +421,7 @@ class UnixSockServer(socketserver_mixin.NoPollMixIn, ThreadingUnixStreamServer):
                     (rlist, wlist, xlist) = ([], [], [])
                     continue
                 else:
-                    #self._log.log_message("error", "Error with select(): %s" %e)
+                    logger.error(XFROUT_SOCKET_SELECT_ERROR, str(e))
                     break
 
             # self.server._shutdown_event will be set by now, if it is not a false
@@ -420,9 +431,8 @@ class UnixSockServer(socketserver_mixin.NoPollMixIn, ThreadingUnixStreamServer):
 
             try:
                 self.process_request(request)
-            except:
-                #self._log.log_message("error", "Exception happened during processing of %s"
-                #                      % str(client_address))
+            except Exception as pre:
+                log.error(XFROUT_PROCESS_REQUEST_ERROR, str(pre))
                 break
 
     def _handle_request_noblock(self):
@@ -440,8 +450,8 @@ class UnixSockServer(socketserver_mixin.NoPollMixIn, ThreadingUnixStreamServer):
             # This may happen when one xfrout process try to connect to
             # xfrout unix socket server, to check whether there is another
             # xfrout running.
-            #if sock_fd == FD_COMM_ERROR:
-                #self._log.log_message("error", "Failed to receive the file descriptor for XFR connection")
+            if sock_fd == FD_COMM_ERROR:
+                logger.error(XFROUT_RECEIVE_FILE_DESCRIPTOR_ERROR)
             return
 
         # receive request msg
@@ -466,8 +476,7 @@ class UnixSockServer(socketserver_mixin.NoPollMixIn, ThreadingUnixStreamServer):
         If it's not a socket file or nobody is listening
         , it will be removed. If it can't be removed, exit from python. '''
         if self._sock_file_in_use(sock_file):
-            #self._log.log_message("error", "Fail to start xfrout process, unix socket file '%s'"
-            #                     " is being used by another xfrout process\n" % sock_file)
+            logger.error(XFROUT_UNIX_SOCKET_FILE_IN_USE, sock_file)
             sys.exit(0)
         else:
             if not os.path.exists(sock_file):
@@ -476,7 +485,7 @@ class UnixSockServer(socketserver_mixin.NoPollMixIn, ThreadingUnixStreamServer):
             try:
                 os.unlink(sock_file)
             except OSError as err:
-                #self._log.log_message("error", "[b10-xfrout] Fail to remove file %s: %s\n" % (sock_file, err))
+                logger.error(XFROUT_REMOVE_OLD_UNIX_SOCKET_FILE_ERROR, sock_file, str(err))
                 sys.exit(0)
 
     def _sock_file_in_use(self, sock_file):
@@ -497,18 +506,17 @@ class UnixSockServer(socketserver_mixin.NoPollMixIn, ThreadingUnixStreamServer):
         try:
             os.unlink(self._sock_file)
         except Exception as e:
-            #self._log.log_message('error', str(e))
+            logger.error(XFROUT_REMOVE_UNIX_SOCKET_FILE_ERROR, self._sock_file, str(e))
             pass
 
     def update_config_data(self, new_config):
         '''Apply the new config setting of xfrout module. '''
-        #self._log.log_message('info', 'update config data start.')
+        logger.info(XFROUT_NEW_CONFIG)
         self._lock.acquire()
         self._max_transfers_out = new_config.get('transfers_out')
         self.set_tsig_key_ring(new_config.get('tsig_key_ring'))
-        #self._log.log_message('info', 'max transfer out : %d', self._max_transfers_out)
         self._lock.release()
-        #self._log.log_message('info', 'update config data complete.')
+        logger.info(XFROUT_NEW_CONFIG_DONE)
 
     def set_tsig_key_ring(self, key_list):
         """Set the tsig_key_ring , given a TSIG key string list representation. """
@@ -523,8 +531,7 @@ class UnixSockServer(socketserver_mixin.NoPollMixIn, ThreadingUnixStreamServer):
             try:
                 self.tsig_key_ring.add(TSIGKey(key_item))
             except InvalidParameter as ipe:
-                errmsg = "bad TSIG key string: " + str(key_item)
-                #self._log.log_message('error', '%s' % errmsg)
+                logger.error(XFROUT_BAD_TSIG_KEY_STRING, str(key_item))
 
     def get_db_file(self):
         file, is_default = self._cc.get_remote_config_value("Auth", "database_file")
@@ -624,7 +631,7 @@ class XfroutServer:
 
     def command_handler(self, cmd, args):
         if cmd == "shutdown":
-            #self._log.log_message("info", "Received shutdown command.")
+            logger.info(XFROUT_RECEIVED_SHUTDOWN_COMMAND)
             self.shutdown()
             answer = create_answer(0)
 
@@ -632,8 +639,7 @@ class XfroutServer:
             zone_name = args.get('zone_name')
             zone_class = args.get('zone_class')
             if zone_name and zone_class:
-                #self._log.log_message("info", "zone '%s/%s': receive notify others command" \
-                #                       % (zone_name, zone_class))
+                logger.info(XFROUT_NOTIFY_COMMAND, zone_name, zone_class)
                 self.send_notify(zone_name, zone_class)
                 answer = create_answer(0)
             else:
@@ -676,15 +682,11 @@ if '__main__' == __name__:
         xfrout_server = XfroutServer()
         xfrout_server.run()
     except KeyboardInterrupt:
-        sys.stderr.write("[b10-xfrout] exit xfrout process\n")
+        logger.INFO(XFROUT_STOPPED_BY_KEYBOARD)
     except SessionError as e:
-        sys.stderr.write("[b10-xfrout] Error creating xfrout, "
-                           "is the command channel daemon running?\n")
+        logger.error(XFROUT_CC_SESSION_ERROR, str(e))
     except SessionTimeout as e:
-        sys.stderr.write("[b10-xfrout] Error creating xfrout, "
-                           "is the configuration manager running?\n")
-    except ModuleCCSessionError as e:
-        sys.stderr.write("[b10-xfrout] exit xfrout process:%s\n" % str(e))
+        logger.error(XFROUT_CC_SESSION_TIMEOUT_ERROR)
 
     if xfrout_server:
         xfrout_server.shutdown()

src/bin/xfrout/xfrout_messages.mes

@@ -0,0 +1,140 @@
+# Copyright (C) 2011  Internet Systems Consortium, Inc. ("ISC")
+#
+# Permission to use, copy, modify, and/or 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 ISC DISCLAIMS ALL WARRANTIES WITH
+# REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF MERCHANTABILITY
+# AND FITNESS.  IN NO EVENT SHALL ISC 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.
+
+# No namespace declaration - these constants go in the global namespace
+# of the xfrout messages python module.
+
+% XFROUT_AXFR_TRANSFER_DONE transfer of %1/%2 complete
+The transfer of the given zone has been completed successfully, or was
+aborted due to a shutdown event.
+
+% XFROUT_AXFR_TRANSFER_ERROR error transferring zone %1/%2: %3
+An uncaught exception was encountered while sending the response to
+an AXFR query. The error message of the exception is included in the
+log message, but this error most likely points to incomplete exception
+handling in the code.
+
+% XFROUT_AXFR_TRANSFER_FAILED transfer of %1/%2 failed, rcode: %3
+A transfer out for the given zone failed. An error response is sent
+to the client. The given rcode is the rcode that is set in the error
+response. This is either NOTAUTH (we are not authoritative for the
+zone), SERVFAIL (our internal database is missing the SOA record for
+the zone), or REFUSED (the limit of simultaneous outgoing AXFR
+transfers, as specified by the configuration value
+Xfrout/max_transfers_out, has been reached).
+# Still a TODO, but when implemented, REFUSED can also mean
+# the client is not allowed to transfer the zone
+
+% XFROUT_AXFR_TRANSFER_STARTED transfer of zone %1/%2 has started
+A transfer out of the given zone has started.
+
+% XFROUT_BAD_TSIG_KEY_STRING bad TSIG key string: %1
+The TSIG key string as read from the configuration does not represent
+a valid TSIG key.
+
+% XFROUT_CC_SESSION_ERROR error reading from cc channel: %1
+There was a problem reading from the command and control channel. The
+most likely cause is that the msgq daemon is not running.
+
+% XFROUT_CC_SESSION_TIMEOUT_ERROR timeout waiting for cc response
+There was a problem reading a response from antoher module over the
+command and control channel. The most likely cause is that the
+configuration manager b10-cfgmgr is not running.
+
+% XFROUT_FETCH_REQUEST_ERROR socket error while fetching a request from the auth daemon
+There was a socket error while contacting the b10-auth daemon to
+fetch a transfer request. The auth daemon may have shutdown.
+
+% XFROUT_HANDLE_QUERY_ERROR error while handling query: %1
+There was a general error handling an xfrout query. The error is shown
+in the message. In principle this error should not appear, and points
+to an oversight catching exceptions in the right place. However, to
+ensure the daemon keeps running, this error is caught and reported.
+
+% XFROUT_IMPORT error importing python module: %1
+There was an error importing a python module. One of the modules needed
+by xfrout could not be found. This suggests that either some libraries
+are missing on the system, or the PYTHONPATH variable is not correct.
+The specific place where this library needs to be depends on your
+system and your specific installation.
+
+% XFROUT_NEW_CONFIG Update xfrout configuration
+New configuration settings have been sent from the configuration
+manager. The xfrout daemon will now apply them.
+
+% XFROUT_NEW_CONFIG_DONE Update xfrout configuration done
+The xfrout daemon is now done reading the new configuration settings
+received from the configuration manager.
+
+% XFROUT_NOTIFY_COMMAND received command to send notifies for %1/%2
+The xfrout daemon received a command on the command channel that
+NOTIFY packets should be sent for the given zone.
+
+% XFROUT_PARSE_QUERY_ERROR error parsing query: %1
+There was a parse error while reading an incoming query. The parse
+error is shown in the log message. A remote client sent a packet we
+do not understand or support. The xfrout request will be ignored.
+In general, this should only occur for unexpected problems like
+memory allocation failures, as the query should already have been
+parsed by the b10-auth daemon, before it was passed here.
+
+% XFROUT_PROCESS_REQUEST_ERROR error processing transfer request: %2
+There was an error processing a transfer request. The error is included
+in the log message, but at this point no specific information other
+than that could be given. This points to incomplete exception handling
+in the code.
+
+% XFROUT_RECEIVE_FILE_DESCRIPTOR_ERROR error receiving the file descriptor for an XFR connection
+There was an error receiving the file descriptor for the transfer
+request. Normally, the request is received by b10-auth, and passed on
+to the xfrout daemon, so it can answer directly. However, there was a
+problem receiving this file descriptor. The request will be ignored.
+
+% XFROUT_RECEIVED_SHUTDOWN_COMMAND shutdown command received
+The xfrout daemon received a shutdown command from the command channel
+and will now shut down.
+
+% XFROUT_REMOVE_UNIX_SOCKET_FILE_ERROR error clearing unix socket file %1: %2
+When shutting down, the xfrout daemon tried to clear the unix socket
+file used for communication with the auth daemon. It failed to remove
+the file. The reason for the failure is given in the error message.
+
+% XFROUT_REMOVE_OLD_UNIX_SOCKET_FILE_ERROR error removing unix socket file %1: %2
+The unix socket file xfrout needs for contact with the auth daemon
+already exists, and needs to be removed first, but there is a problem
+removing it. It is likely that we do not have permission to remove
+this file. The specific error is show in the log message. The xfrout
+daemon will shut down.
+
+% XFROUT_SOCKET_SELECT_ERROR error while calling select() on request socket: %1
+There was an error while calling select() on the socket that informs
+the xfrout daemon that a new xfrout request has arrived. This should
+be a result of rare local error such as memory allocation failure and
+shouldn't happen under normal conditions. The error is included in the
+log message.
+
+% XFROUT_STOPPED_BY_KEYBOARD keyboard interrupt, shutting down
+There was a keyboard interrupt signal to stop the xfrout daemon. The
+daemon will now shut down.
+
+% XFROUT_STOPPING the xfrout daemon is shutting down
+The current transfer is aborted, as the xfrout daemon is shutting down.
+
+% XFROUT_UNIX_SOCKET_FILE_IN_USE another xfrout process seems to be using the unix socket file %1
+While starting up, the xfrout daemon tried to clear the unix domain
+socket needed for contacting the b10-auth daemon to pass requests
+on, but the file is in use. The most likely cause is that another
+xfrout daemon process is still running. This xfrout daemon (the one
+printing this message) will not start.
+