diff --git a/secop/logging.py b/secop/logging.py new file mode 100644 index 0000000..77f0722 --- /dev/null +++ b/secop/logging.py @@ -0,0 +1,66 @@ +#!/usr/bin/env python +# -*- coding: utf-8 -*- +# ***************************************************************************** +# This program is free software; you can redistribute it and/or modify it under +# the terms of the GNU General Public License as published by the Free Software +# Foundation; either version 2 of the License, or (at your option) any later +# version. +# +# This program is distributed in the hope that it will be useful, but WITHOUT +# ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS +# FOR A PARTICULAR PURPOSE. See the GNU General Public License for more +# details. +# +# You should have received a copy of the GNU General Public License along with +# this program; if not, write to the Free Software Foundation, Inc., +# 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA +# +# Module authors: +# Markus Zolliker +# ***************************************************************************** + + +from logging import LoggerAdapter +from mlzlog import LOGLEVELS + +OFF = 99 +LOG_LEVELS = dict(LOGLEVELS, off=OFF) +LEVEL_NAMES = {v: k for k, v in LOG_LEVELS.items()} + + +def check_level(level): + try: + if isinstance(level, str): + return LOG_LEVELS[level.lower()] + if level in LEVEL_NAMES: + return level + except KeyError: + pass + raise ValueError('%r is not a valid level' % level) + + +class Adapter(LoggerAdapter): + def __init__(self, modobj): + super().__init__(modobj.log, {}) + self.subscriptions = {} # dict [conn] of level + self.modobj = modobj + + def log(self, level, msg, *args, **kwargs): + super().log(level, msg, *args, **kwargs) + for conn, lev in self.subscriptions.items(): + if level >= lev: + self.modobj.DISPATCHER.send_log_msg( + conn, self.modobj.name, LEVEL_NAMES[level], msg % args) + + def set_log_level(self, conn, level): + level = check_level(level) + if level == OFF: + self.subscriptions.pop(conn, None) + else: + self.subscriptions[conn] = level + + +def set_log_level(modobj, conn, level): + if not isinstance(modobj.log, Adapter): + modobj.log = Adapter(modobj) + modobj.log.set_log_level(conn, level) diff --git a/secop/protocol/dispatcher.py b/secop/protocol/dispatcher.py index 5075b4b..33b4f15 100644 --- a/secop/protocol/dispatcher.py +++ b/secop/protocol/dispatcher.py @@ -45,9 +45,11 @@ from time import time as currenttime from secop.errors import NoSuchCommandError, NoSuchModuleError, \ NoSuchParameterError, ProtocolError, ReadOnlyError, SECoPServerError from secop.params import Parameter +from secop.logging import set_log_level from secop.protocol.messages import COMMANDREPLY, DESCRIPTIONREPLY, \ DISABLEEVENTSREPLY, ENABLEEVENTSREPLY, ERRORPREFIX, EVENTREPLY, \ - HEARTBEATREPLY, IDENTREPLY, IDENTREQUEST, READREPLY, WRITEREPLY + HEARTBEATREPLY, IDENTREPLY, IDENTREQUEST, READREPLY, WRITEREPLY, \ + LOGGING_REPLY, LOG_EVENT def make_update(modulename, pobj): @@ -129,6 +131,7 @@ class Dispatcher: self._connections.remove(conn) for _evt, conns in list(self._subscriptions.items()): conns.discard(conn) + self.set_all_log_levels(conn, 'off') self._active_connections.discard(conn) def register_module(self, moduleobj, modulename, export=True): @@ -372,3 +375,19 @@ class Dispatcher: self._active_connections.discard(conn) # XXX: also check all entries in self._subscriptions? return (DISABLEEVENTSREPLY, None, None) + + def send_log_msg(self, conn, modname, level, msg): + """send log message """ + if conn in self._connections: + conn.send_reply((LOG_EVENT, '%s:%s' % (modname, level), msg)) + + def set_all_log_levels(self, conn, level): + for modobj in self._modules.values(): + set_log_level(modobj, conn, level) + + def handle_logging(self, conn, specifier, level): + if specifier and specifier != '.': + set_log_level(self._modules[specifier], conn, level) + else: + self.set_all_log_levels(conn, level) + return LOGGING_REPLY, specifier, level diff --git a/secop/protocol/messages.py b/secop/protocol/messages.py index 706b6cf..44edfc4 100644 --- a/secop/protocol/messages.py +++ b/secop/protocol/messages.py @@ -65,6 +65,13 @@ ERRORPREFIX = 'error_' # + specifier + json_extended_info(error_report) HELPREQUEST = 'help' # literal HELPREPLY = 'helping' # +line number +json_text +LOGGING_REQUEST = 'logging' +LOGGING_REPLY = 'logging' +# + [module] + json string (loglevel) + +LOG_EVENT = 'log' +# + [module:level] + json_string (message) + # helper mapping to find the REPLY for a REQUEST # do not put IDENTREQUEST/IDENTREPLY here, as this needs anyway extra treatment REQUEST2REPLY = { @@ -77,6 +84,7 @@ REQUEST2REPLY = { READREQUEST: READREPLY, HEARTBEATREQUEST: HEARTBEATREPLY, HELPREQUEST: HELPREPLY, + LOGGING_REQUEST: LOGGING_REPLY, } @@ -89,6 +97,8 @@ HelpMessage = """Try one of the following: '%s ' to request a heartbeat response '%s' to activate async updates '%s' to deactivate updates + '%s [] ' to activate logging events """ % (IDENTREQUEST, DESCRIPTIONREQUEST, READREQUEST, WRITEREQUEST, COMMANDREQUEST, HEARTBEATREQUEST, - ENABLEEVENTSREQUEST, DISABLEEVENTSREQUEST) + ENABLEEVENTSREQUEST, DISABLEEVENTSREQUEST, + LOGGING_REQUEST) diff --git a/test/test_logging.py b/test/test_logging.py new file mode 100644 index 0000000..0351f23 --- /dev/null +++ b/test/test_logging.py @@ -0,0 +1,140 @@ +# -*- coding: utf-8 -*- +# ***************************************************************************** +# +# This program is free software; you can redistribute it and/or modify it under +# the terms of the GNU General Public License as published by the Free Software +# Foundation; either version 2 of the License, or (at your option) any later +# version. +# +# This program is distributed in the hope that it will be useful, but WITHOUT +# ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS +# FOR A PARTICULAR PURPOSE. See the GNU General Public License for more +# details. +# +# You should have received a copy of the GNU General Public License along with +# this program; if not, write to the Free Software Foundation, Inc., +# 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA +# +# Module authors: +# Markus Zolliker +# +# ***************************************************************************** + + +from mlzlog import MLZLogger, Handler, INFO, DEBUG +from secop.modules import Module +from secop.protocol.dispatcher import Dispatcher + + +class LogHandler(Handler): + def __init__(self, result): + super().__init__() + self.result = result + + def emit(self, record): + self.result.append('%s:%s' % (record.levelname, record.getMessage())) + + +class LogRecorder(MLZLogger): + def __init__(self, result): + super().__init__('root') + self.setLevel(INFO) + self.addHandler(LogHandler(result)) + + +class ServerStub: + restart = None + shutdown = None + + +class Connection: + def __init__(self, dispatcher): + self.result = [] + dispatcher.add_connection(self) + + def send_reply(self, msg): + self.result.append(msg) + + def check(self, *args): + assert self.result == list(args) + self.result[:] = [] + + def send(self, *request): + assert srv.dispatcher.handle_request(self, request) == request + + +class Mod(Module): + def __init__(self, name): + self.result = [] + super().__init__(name, LogRecorder(self.result), {'.description': ''}, srv) + srv.dispatcher.register_module(self, name, name) + + def check(self, *args): + assert self.result == list(args) + self.result[:] = [] + + +srv = ServerStub() +srv.dispatcher = Dispatcher('', LogRecorder([]), {}, srv) +conn1 = Connection(srv.dispatcher) +conn2 = Connection(srv.dispatcher) +o1 = Mod('o1') +o2 = Mod('o2') + + +def test_logging1(): + # test normal logging + o1.log.setLevel(INFO) + o2.log.setLevel(DEBUG) + + o1.log.info('i1') + o1.log.debug('d1') + o2.log.info('i2') + o2.log.debug('d2') + + o1.check('INFO:i1') + o2.check('INFO:i2', 'DEBUG:d2') + conn1.check() + conn2.check() + + # test remote logging on + conn1.send('logging', 'o1', 'debug') + conn2.send('logging', 'o1', 'info') + conn2.send('logging', 'o2', 'debug') + + o1.log.info('i1') + o1.log.debug('d1') + o2.log.info('i2') + o2.log.debug('d2') + + o1.check('INFO:i1') + o2.check('INFO:i2', 'DEBUG:d2') + conn1.check(('log', 'o1:info', 'i1'), ('log', 'o1:debug', 'd1')) + conn2.check(('log', 'o1:info', 'i1'), ('log', 'o2:info', 'i2'), ('log', 'o2:debug', 'd2')) + + # test all remote logging + conn1.send('logging', '', 'off') + conn2.send('logging', '', 'off') + + o1.log.info('i1') + o1.log.debug('d1') + o2.log.info('i2') + o2.log.debug('d2') + + o1.check('INFO:i1') + o2.check('INFO:i2', 'DEBUG:d2') + conn1.check() + conn2.check() + + # test all modules on, warning level + conn2.send('logging', '', 'warning') + + o1.log.info('i1') + o1.log.warning('w1') + o2.log.info('i2') + o2.log.warning('w2') + + o1.check('INFO:i1', 'WARNING:w1') + o2.check('INFO:i2', 'WARNING:w2') + conn1.check() + conn2.check(('log', 'o1:warning', 'w1'), ('log', 'o2:warning', 'w2'))