BIND 10 trac1190, updated. 95483cb529b42683002528186eb29d6854e7ce0e [1190] Put logging into MSGQ

BIND 10 source code commits bind10-changes at lists.isc.org
Wed Dec 19 11:50:13 UTC 2012


The branch, trac1190 has been updated
       via  95483cb529b42683002528186eb29d6854e7ce0e (commit)
      from  44f6dc45fffe9a44d8700bbb601dab169568f7ac (commit)

Those revisions listed above that are new to this repository have
not appeared on any other notification email; so we list those
revisions in full, below.

- Log -----------------------------------------------------------------
commit 95483cb529b42683002528186eb29d6854e7ce0e
Author: Michal 'vorner' Vaner <michal.vaner at nic.cz>
Date:   Wed Dec 19 12:49:05 2012 +0100

    [1190] Put logging into MSGQ
    
    Add the logging calls. Other things need to be tweaked (putting it into
    a file, making tests work, etc).

-----------------------------------------------------------------------

Summary of changes:
 src/bin/msgq/msgq.py.in         |   48 +++++++++++++---------------
 src/bin/msgq/msgq_messages.mes  |   67 +++++++++++++++++++++++++++++++++++++++
 src/bin/msgq/run_msgq.sh.in     |   18 ++++++++++-
 src/bin/msgq/tests/msgq_test.py |    2 ++
 4 files changed, 108 insertions(+), 27 deletions(-)

-----------------------------------------------------------------------
diff --git a/src/bin/msgq/msgq.py.in b/src/bin/msgq/msgq.py.in
index 71b8d28..49e9e4c 100755
--- a/src/bin/msgq/msgq.py.in
+++ b/src/bin/msgq/msgq.py.in
@@ -37,6 +37,10 @@ from isc.log_messages.msgq_messages import *
 import isc.cc
 
 isc.util.process.rename()
+logger = isc.log.Logger("msgq")
+TRACE_START = logger.DBGLVL_START_SHUT
+TRACE_BASIC = logger.DBGLVL_TRACE_BASIC
+TRACE_DETAIL = logger.DBGLVL_TRACE_DETAIL
 
 # This is the version that gets displayed to the user.
 # The VERSION string consists of the module name, the module version
@@ -53,11 +57,11 @@ class SubscriptionManager:
         """Add a subscription."""
         target = ( group, instance )
         if target in self.subscriptions:
-            print("[b10-msgq] Appending to existing target")
+            logger.debug(TRACE_BASIC, MSGQ_SUBS_APPEND_TARGET, group, instance)
             if socket not in self.subscriptions[target]:
                 self.subscriptions[target].append(socket)
         else:
-            print("[b10-msgq] Creating new target")
+            logger.debug(TRACE_BASIC, MSGQ_SUBS_NEW_TARGET, group, instance)
             self.subscriptions[target] = [ socket ]
 
     def unsubscribe(self, group, instance, socket):
@@ -164,9 +168,7 @@ class MsgQ:
 
     def setup_listener(self):
         """Set up the listener socket.  Internal function."""
-        if self.verbose:
-            sys.stdout.write("[b10-msgq] Setting up socket at %s\n" %
-                             self.socket_file)
+        logger.debug(TRACE_BASIC, MSGQ_LISTENER_SETUP, self.socket_file)
 
         self.listen_socket = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM)
 
@@ -181,8 +183,7 @@ class MsgQ:
             if os.path.exists(self.socket_file):
                 os.remove(self.socket_file)
             self.listen_socket.close()
-            sys.stderr.write("[b10-msgq] failed to setup listener on %s: %s\n"
-                             % (self.socket_file, str(e)))
+            logger.fatal(MSGQ_LISTENER_FAILED, self.socket_file, e)
             raise e
 
         if self.poller:
@@ -199,8 +200,7 @@ class MsgQ:
         self.setup_poller()
         self.setup_listener()
 
-        if self.verbose:
-            sys.stdout.write("[b10-msgq] Listening\n")
+        logger.debug(TRACE_START, MSGQ_LISTENER_STARTED);
 
         self.runnable = True
 
@@ -228,7 +228,7 @@ class MsgQ:
     def process_socket(self, fd):
         """Process a read on a socket."""
         if not fd in self.sockets:
-            sys.stderr.write("[b10-msgq] Got read on Strange Socket fd %d\n" % fd)
+            logger.error(MSGQ_READ_UNKNOWN_FD, fd)
             return
         sock = self.sockets[fd]
 #        sys.stderr.write("[b10-msgq] Got read on fd %d\n" %fd)
@@ -245,7 +245,7 @@ class MsgQ:
         del self.sockets[fd]
         if fd in self.sendbuffs:
             del self.sendbuffs[fd]
-        sys.stderr.write("[b10-msgq] Closing socket fd %d\n" % fd)
+        logger.debug(TRACE_BASIC, MSGQ_SOCK_CLOSE, fd)
 
     def getbytes(self, fd, sock, length):
         """Get exactly the requested bytes, or raise an exception if
@@ -288,14 +288,14 @@ class MsgQ:
             routing, data = self.read_packet(fd, sock)
         except MsgQReceiveError as err:
             self.kill_socket(fd, sock)
-            sys.stderr.write("[b10-msgq] Receive error: %s\n" % err)
+            logger.error(MSGQ_RECV_ERR, fd, err)
             return
 
         try:
             routingmsg = isc.cc.message.from_wire(routing)
         except DecodeError as err:
             self.kill_socket(fd, sock)
-            sys.stderr.write("[b10-msgq] Routing decode error: %s\n" % err)
+            logger.error(MSGQ_HDR_DECODE_ERR, fd, err)
             return
 
         self.process_command(fd, sock, routingmsg, data)
@@ -303,9 +303,7 @@ class MsgQ:
     def process_command(self, fd, sock, routing, data):
         """Process a single command.  This will split out into one of the
            other functions."""
-        # TODO: A print statement got removed here (one that prints the
-        # routing envelope). When we have logging with multiple levels,
-        # we might want to re-add that on a high debug verbosity.
+        logger.debug(TRACE_DETAIL, MSGQ_RECV_HDR, routing)
         cmd = routing["type"]
         if cmd == 'send':
             self.process_command_send(sock, routing, data)
@@ -321,7 +319,7 @@ class MsgQ:
         elif cmd == 'stop':
             self.stop()
         else:
-            sys.stderr.write("[b10-msgq] Invalid command: %s\n" % cmd)
+            logger.error(MSGQ_INVALID_CMD, cmd)
 
     def preparemsg(self, env, msg = None):
         if type(env) == dict:
@@ -365,8 +363,8 @@ class MsgQ:
             elif e.errno in [ errno.EPIPE,
                               errno.ECONNRESET,
                               errno.ENOBUFS ]:
-                print("[b10-msgq] " + errno.errorcode[e.errno] +
-                      " on send, dropping message and closing connection")
+                logger.error(MSGQ_SEND_ERR, sock.fileno(),
+                             errno.errorcode[e.errno])
                 self.kill_socket(sock.fileno(), sock)
                 return None
             else:
@@ -493,7 +491,7 @@ class MsgQ:
                 if err.args[0] == errno.EINTR:
                     events = []
                 else:
-                    sys.stderr.write("[b10-msgq] Error with poll(): %s\n" % err)
+                    logger.error(MSGQ_POLL_ERR, err)
                     break
             for (fd, event) in events:
                 if fd == self.listen_socket.fileno():
@@ -504,7 +502,7 @@ class MsgQ:
                     elif event & select.POLLIN:
                         self.process_socket(fd)
                     else:
-                        print("[b10-msgq] Error: Unknown even in run_poller()")
+                        logger.error(MSGQ_POLL_UNKNOWN_EVENT, event)
 
     def run_kqueue(self):
         while self.running:
@@ -572,21 +570,19 @@ if __name__ == "__main__":
         sev = 'DEBUG'
     LOG_FILE = os.path.join("@localstatedir@", "@PACKAGE_NAME@",
                             "msgq.log").replace("${prefix}", "@prefix@")
-    isc.log.init("b10-msgq", buffer=False, severity=sev, debuglevel=99,
-                 file=LOG_FILE)
+    isc.log.init("b10-msgq", buffer=False, severity=sev, debuglevel=99)
 
     signal.signal(signal.SIGTERM, signal_handler)
 
     # Announce startup.
-    if options.verbose:
-        sys.stdout.write("[b10-msgq] %s\n" % VERSION)
+    logger.debug(TRACE_START, MSGQ_START, VERSION)
 
     msgq = MsgQ(options.msgq_socket_file, options.verbose)
 
     try:
         msgq.setup()
     except Exception as e:
-        sys.stderr.write("[b10-msgq] Error on startup: %s\n" % str(e))
+        logger.fatal(MSGQ_START_FAIL, e)
         sys.exit(1)
 
     try:
diff --git a/src/bin/msgq/msgq_messages.mes b/src/bin/msgq/msgq_messages.mes
index e69de29..af5ee64 100644
--- a/src/bin/msgq/msgq_messages.mes
+++ b/src/bin/msgq/msgq_messages.mes
@@ -0,0 +1,67 @@
+# Copyright (C) 2012  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 ddns messages python module.
+
+# When you add a message to this file, it is a good idea to run
+# <topsrcdir>/tools/reorder_message_file.py to make sure the
+# messages are in the correct order.
+
+% MSGQ_SUBS_NEW_TARGET Creating new target for subscription to group '%1' for instance '%2'
+Debug
+
+% MSGQ_SUBS_APPEND_TARGET Appending to existing target for subscription to group '%1' for instance '%2'
+Debug
+
+% MSGQ_LISTENER_SETUP Starting to listen on socket file '%1'
+Debug
+
+% MSGQ_LISTENER_FAILED Failed to initialize listener on socket file '%1': %2
+Fatal
+
+% MSGQ_LISTENER_STARTED Successfully started to listen
+Debug
+
+% MSGQ_READ_UNKNOWN_FD Got read on strange socket %1
+Error, ignoring
+
+% MSGQ_SOCK_CLOSE Closing socket fd %1
+Debug
+
+% MSGQ_RECV_ERR Error reading from socket %1: %2
+Error
+
+% MSGQ_HDR_DECODE_ERR Error decoding header received from socket %1: %2
+Error
+
+% MSGQ_RECV_HDR Received header: %1
+Debug
+
+% MSGQ_RECV_INVALID_CMD Received invalid command: %1
+Error
+
+% MSGQ_SEND_ERR Error while sending to socket %1: %2
+Error
+
+% MSGQ_POLL_ERR Error while polling for events: %1
+Error
+
+% MSGQ_POLL_UNKNOWN_EVENT Got an unknown event from the poller: %1
+Error
+
+% MSGQ_START Msgq version %1 starting
+Debug
+
+% MSGQ_START_FAIL Error during startup: %1
diff --git a/src/bin/msgq/run_msgq.sh.in b/src/bin/msgq/run_msgq.sh.in
index 3e464be..3ab4024 100644
--- a/src/bin/msgq/run_msgq.sh.in
+++ b/src/bin/msgq/run_msgq.sh.in
@@ -20,9 +20,25 @@ export PYTHON_EXEC
 
 MYPATH_PATH=@abs_top_builddir@/src/bin/msgq
 
-PYTHONPATH=@abs_top_srcdir@/src/lib/python
+PYTHONPATH=@abs_top_builddir@/src/lib/python/isc/log_messages:@abs_top_builddir@/src/lib/python:@abs_top_builddir@/src/lib/log/.libs
 export PYTHONPATH
 
+# If necessary (rare cases), explicitly specify paths to dynamic libraries
+# required by loadable python modules.
+SET_ENV_LIBRARY_PATH=@SET_ENV_LIBRARY_PATH@
+if test $SET_ENV_LIBRARY_PATH = yes; then
+    @ENV_LIBRARY_PATH@=@abs_top_builddir@/src/lib/dns/.libs:@abs_top_builddir@/src/lib/dns/python/.libs:@abs_top_builddir@/src/lib/cryptolink/.libs:@abs_top_builddir@/src/lib/cc/.libs:@abs_top_builddir@/src/lib/config/.libs:@abs_top_builddir@/src/lib/log/.libs:@abs_top_builddir@/src/lib/acl/.libs:@abs_top_builddir@/src/lib/util/.libs:@abs_top_builddir@/src/lib/util/io/.libs:@abs_top_builddir@/src/lib/exceptions/.libs:@abs_top_builddir@/src/lib/datasrc/.libs:$@ENV_LIBRARY_PATH@
+    export @ENV_LIBRARY_PATH@
+fi
+
+B10_FROM_SOURCE=@abs_top_srcdir@
+export B10_FROM_SOURCE
+# TODO: We need to do this feature based (ie. no general from_source)
+# But right now we need a second one because some spec files are
+# generated and hence end up under builddir
+B10_FROM_BUILD=@abs_top_builddir@
+export B10_FROM_BUILD
+
 BIND10_MSGQ_SOCKET_FILE=@abs_top_builddir@/msgq_socket
 export BIND10_MSGQ_SOCKET_FILE
 
diff --git a/src/bin/msgq/tests/msgq_test.py b/src/bin/msgq/tests/msgq_test.py
index 4060190..e74f118 100644
--- a/src/bin/msgq/tests/msgq_test.py
+++ b/src/bin/msgq/tests/msgq_test.py
@@ -10,6 +10,7 @@ import errno
 import threading
 import isc.cc
 import collections
+import isc.log
 
 #
 # Currently only the subscription part and some sending is implemented...
@@ -457,4 +458,5 @@ class SendNonblock(unittest.TestCase):
 
 
 if __name__ == '__main__':
+    isc.log.resetUnitTestRootLogger()
     unittest.main()



More information about the bind10-changes mailing list