diff --git a/configure.ac b/configure.ac index 6a88f4eb2c..df53d4def1 100644 --- a/configure.ac +++ b/configure.ac @@ -1354,7 +1354,6 @@ AC_OUTPUT([doc/version.ent src/bin/usermgr/run_b10-cmdctl-usermgr.sh src/bin/usermgr/b10-cmdctl-usermgr.py src/bin/msgq/msgq.py - src/bin/msgq/tests/msgq_test src/bin/msgq/run_msgq.sh src/bin/auth/auth.spec.pre src/bin/auth/spec_config.h.pre @@ -1420,7 +1419,6 @@ AC_OUTPUT([doc/version.ent chmod +x src/bin/sysinfo/run_sysinfo.sh chmod +x src/bin/usermgr/run_b10-cmdctl-usermgr.sh chmod +x src/bin/msgq/run_msgq.sh - chmod +x src/bin/msgq/tests/msgq_test chmod +x src/lib/dns/gen-rdatacode.py chmod +x src/lib/log/tests/console_test.sh chmod +x src/lib/log/tests/destination_test.sh diff --git a/src/bin/msgq/Makefile.am b/src/bin/msgq/Makefile.am index 4244d07c42..5f377b1eef 100644 --- a/src/bin/msgq/Makefile.am +++ b/src/bin/msgq/Makefile.am @@ -5,10 +5,16 @@ pkglibexecdir = $(libexecdir)/@PACKAGE@ pkglibexec_SCRIPTS = b10-msgq CLEANFILES = b10-msgq msgq.pyc +CLEANFILES += $(PYTHON_LOGMSGPKG_DIR)/work/msgq_messages.py +CLEANFILES += $(PYTHON_LOGMSGPKG_DIR)/work/msgq_messages.pyc man_MANS = b10-msgq.8 DISTCLEANFILES = $(man_MANS) -EXTRA_DIST = $(man_MANS) msgq.xml +EXTRA_DIST = $(man_MANS) msgq.xml msgq_messages.mes + +nodist_pylogmessage_PYTHON = $(PYTHON_LOGMSGPKG_DIR)/work/msgq_messages.py +pylogmessagedir = $(pyexecdir)/isc/log_messages/ +BUILT_SOURCES = $(PYTHON_LOGMSGPKG_DIR)/work/msgq_messages.py if GENERATE_DOCS @@ -23,6 +29,11 @@ $(man_MANS): endif +# Define rule to build logging source files from message file +$(PYTHON_LOGMSGPKG_DIR)/work/msgq_messages.py : msgq_messages.mes + $(top_builddir)/src/lib/log/compiler/message \ + -d $(PYTHON_LOGMSGPKG_DIR)/work -p $(srcdir)/msgq_messages.mes + # this is done here since configure.ac AC_OUTPUT doesn't expand exec_prefix b10-msgq: msgq.py $(SED) "s|@@PYTHONPATH@@|@pyexecdir@|" msgq.py >$@ diff --git a/src/bin/msgq/msgq.py.in b/src/bin/msgq/msgq.py.in index bd13a1c188..693760078c 100755 --- a/src/bin/msgq/msgq.py.in +++ b/src/bin/msgq/msgq.py.in @@ -31,10 +31,16 @@ import select import random from optparse import OptionParser, OptionValueError import isc.util.process +import isc.log +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 @@ -51,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): @@ -162,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) @@ -179,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: @@ -197,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 @@ -226,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) @@ -243,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 @@ -285,15 +287,15 @@ class MsgQ: try: routing, data = self.read_packet(fd, sock) except MsgQReceiveError as err: + logger.error(MSGQ_RECV_ERR, fd, err) self.kill_socket(fd, sock) - sys.stderr.write("[b10-msgq] Receive error: %s\n" % 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) @@ -301,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) @@ -319,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: @@ -363,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: @@ -491,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.fatal(MSGQ_POLL_ERR, err) break for (fd, event) in events: if fd == self.listen_socket.fileno(): @@ -502,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, fd, event) def run_kqueue(self): while self.running: @@ -563,18 +563,25 @@ if __name__ == "__main__": help="UNIX domain socket file the msgq daemon will use") (options, args) = parser.parse_args() + # Init logging, according to the parameters. + # FIXME: Do proper logger configuration, this is just a hack + # This is #2582 + sev = 'INFO' + if options.verbose: + sev = 'DEBUG' + 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 new file mode 100644 index 0000000000..21c5aa8a06 --- /dev/null +++ b/src/bin/msgq/msgq_messages.mes @@ -0,0 +1,88 @@ +# 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 +# /tools/reorder_message_file.py to make sure the +# messages are in the correct order. + +% MSGQ_HDR_DECODE_ERR Error decoding header received from socket %1: %2 +The socket with mentioned file descriptor sent a packet. However, it was not +possible to decode the routing header of the packet. The packet is ignored. +This may be caused by a programmer error (one of the components sending invalid +data) or possibly by incompatible version of msgq and the component (but that's +unlikely, as the protocol is not changed often). + +% MSGQ_LISTENER_FAILED Failed to initialize listener on socket file '%1': %2 +The message queue daemon tried to listen on a file socket (the path is in the +message), but it failed. The error from the operating system is logged. + +% MSGQ_LISTENER_SETUP Starting to listen on socket file '%1' +Debug message. The listener is trying to open a listening socket. + +% MSGQ_LISTENER_STARTED Successfully started to listen +Debug message. The message queue successfully opened a listening socket and +waits for incoming connections. + +% MSGQ_POLL_ERR Error while polling for events: %1 +A low-level error happened when waiting for events, the error is logged. The +reason for this varies, but it usually means the system is short on some +resources. + +% MSGQ_POLL_UNKNOWN_EVENT Got an unknown event from the poller for fd %1: %2 +An unknown event got out from the poll() system call. This should generally not +happen and it is either a programmer error or OS bug. The event is ignored. The +number noted as the event is the raw encoded value, which might be useful to +the authors when figuring the problem out. + +% MSGQ_READ_UNKNOWN_FD Got read on strange socket %1 +The OS reported a file descriptor is ready to read. But the daemon doesn't know +the mentioned file descriptor, which is either a programmer error or OS bug. +The read event is ignored. + +% MSGQ_RECV_ERR Error reading from socket %1: %2 +There was a low-level error when reading from a socket. The error is logged and +the corresponding socket is dropped. + +% MSGQ_RECV_HDR Received header: %1 +Debug message. This message includes the whole routing header of a packet. + +% MSGQ_INVALID_CMD Received invalid command: %1 +An unknown command listed in the log has been received. It is ignored. This +indicates either a programmer error (eg. a typo in the command name) or +incompatible version of a module and message queue daemon. + +% MSGQ_SEND_ERR Error while sending to socket %1: %2 +There was a low-level error when sending data to a socket. The error is logged +and the corresponding socket is dropped. + +% MSGQ_SOCK_CLOSE Closing socket fd %1 +Debug message. Closing the mentioned socket. + +% MSGQ_START Msgq version %1 starting +Debug message. The message queue is starting up. + +% MSGQ_START_FAIL Error during startup: %1 +There was an error during early startup of the daemon. More concrete error is +in the log. The daemon terminates as a result. + +% MSGQ_SUBS_APPEND_TARGET Appending to existing target for subscription to group '%1' for instance '%2' +Debug message. Creating a new subscription by appending it to already existing +data structure. + +% MSGQ_SUBS_NEW_TARGET Creating new target for subscription to group '%1' for instance '%2' +Debug message. Creating a new subscription. Also creating a new data structure +to hold it. diff --git a/src/bin/msgq/run_msgq.sh.in b/src/bin/msgq/run_msgq.sh.in index 3e464bedca..3ab4024718 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/Makefile.am b/src/bin/msgq/tests/Makefile.am index 50b218b915..c9ef5d304d 100644 --- a/src/bin/msgq/tests/Makefile.am +++ b/src/bin/msgq/tests/Makefile.am @@ -21,6 +21,8 @@ endif $(LIBRARY_PATH_PLACEHOLDER) \ PYTHONPATH=$(COMMON_PYTHON_PATH):$(abs_top_builddir)/src/bin/msgq \ BIND10_TEST_SOCKET_FILE=$(builddir)/test_msgq_socket.sock \ + B10_FROM_SOURCE=$(abs_top_srcdir) \ + B10_FROM_BUILD=$(abs_top_builddir) \ $(PYCOVERAGE_RUN) $(abs_srcdir)/$$pytest || exit ; \ done diff --git a/src/bin/msgq/tests/msgq_test.in b/src/bin/msgq/tests/msgq_test.in deleted file mode 100755 index e3aae89249..0000000000 --- a/src/bin/msgq/tests/msgq_test.in +++ /dev/null @@ -1,28 +0,0 @@ -#! /bin/sh - -# Copyright (C) 2010 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. - -PYTHON_EXEC=${PYTHON_EXEC:-@PYTHON@} -export PYTHON_EXEC - -MYPATH_PATH=@abs_top_srcdir@/src/bin/msgq/tests - -PYTHONPATH=@abs_top_srcdir@/src/bin/msgq:@abs_top_srcdir@/src/lib/python - -export PYTHONPATH - -cd ${MYPATH_PATH} -exec ${PYTHON_EXEC} -O msgq_test.py $* diff --git a/src/bin/msgq/tests/msgq_test.py b/src/bin/msgq/tests/msgq_test.py index 4060190913..417418f34b 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,6 @@ class SendNonblock(unittest.TestCase): if __name__ == '__main__': + isc.log.init("b10-msgq") + isc.log.resetUnitTestRootLogger() unittest.main() diff --git a/src/lib/python/isc/log_messages/Makefile.am b/src/lib/python/isc/log_messages/Makefile.am index 2e86ba3865..97ff6e6766 100644 --- a/src/lib/python/isc/log_messages/Makefile.am +++ b/src/lib/python/isc/log_messages/Makefile.am @@ -17,6 +17,7 @@ EXTRA_DIST += libxfrin_messages.py EXTRA_DIST += loadzone_messages.py EXTRA_DIST += server_common_messages.py EXTRA_DIST += dbutil_messages.py +EXTRA_DIST += msgq_messages.py CLEANFILES = __init__.pyc CLEANFILES += bind10_messages.pyc @@ -35,6 +36,7 @@ CLEANFILES += libxfrin_messages.pyc CLEANFILES += loadzone_messages.pyc CLEANFILES += server_common_messages.pyc CLEANFILES += dbutil_messages.pyc +CLEANFILES += msgq_messages.pyc CLEANDIRS = __pycache__ diff --git a/src/lib/python/isc/log_messages/msgq_messages.py b/src/lib/python/isc/log_messages/msgq_messages.py new file mode 100644 index 0000000000..81efa416e9 --- /dev/null +++ b/src/lib/python/isc/log_messages/msgq_messages.py @@ -0,0 +1 @@ +from work.msgq_messages import *