linse/frappy
0
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

logging as of 2022-02-01

Browse Source 
Change-Id: I63c681bea9553cd822b214075b163ca6c42fe0cc
This commit is contained in:
zolliker 2022-02-02 09:54:54 +01:00
parent 05d0cfb193
commit 9109170752
3 changed files with 193 additions and 13 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

127
secop/logging.py Normal file
View File

@ -0,0 +1,127 @@
# -*- 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 <markus.zolliker@psi.ch>
#
# *****************************************************************************
import os
from os.path import dirname, join
import mlzlog
from secop.lib import getGeneralConfig
OFF = 99
LOG_LEVELS = dict(mlzlog.LOGLEVELS, off=OFF)
LEVEL_NAMES = {v: k for k, v in LOG_LEVELS.items()}
log = None
rootlogdir = None
def checkLevel(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)
def initLogging(loglevel='info'):
global log, rootlogdir # pylint: disable-global-statement
loglevel = checkLevel(loglevel)
genConfig = getGeneralConfig()
rootname = genConfig.get('rootname', 'secop')
logdir = genConfig.get('logdir')
rootlogdir = join(logdir, rootname)
mlzlog.initLogging(rootname, 'debug', logdir)
for hdl in mlzlog.log.handlers:
hdl.setLevel(loglevel)
return mlzlog.log
class ComlogHandler(mlzlog.LogfileHandler):
"""handler for logging communication
communication is
"""
def format(self, record):
return '%s %s' % (self.formatter.formatTime(record), record.getMessage())
def doRollover(self):
super().doRollover()
max_days = getGeneralConfig().get('comlog_days', 31)
# keep only the last max_days files
with os.scandir(dirname(self.baseFilename)) as it:
files = sorted(entry.path for entry in it if entry.name != 'current')
for filepath in files[-max_days:]:
os.remove(filepath)
def add_comlog_handler(modobj):
global rootlogdir # pylint: disable-global-statement
comlog = getGeneralConfig().get('comlog')
if comlog:
comlog = join(rootlogdir, comlog)
modobj.log.addHandler(ComlogHandler(comlog, modobj.name))
class RemoteLogHandler(mlzlog.Handler):
"""handler for remote logging"""
def __init__(self, modobj):
super().__init__()
self.subscriptions = {} # dict [conn] of level
self.modobj = modobj
self.modobj.log.addHandler(self)
self.used_by = set()
def handle(self, record, name=None):
result = False
for conn, lev in self.subscriptions.items():
if record.levelno >= lev:
msg = record.getMessage()
if self.modobj.DISPATCHER.send_log_msg(
conn, name or self.modobj.name, LEVEL_NAMES[record.levelno], msg):
result = True
if result:
return True
for master in self.used_by:
# this is an iodev, try to handle by one of our masters
if master.remoteLogHandler.handle(record, self.modobj.name):
return True
return False
def set_conn_level(self, conn, level):
level = checkLevel(level)
if level == mlzlog.DEBUG:
iodev = getattr(self.modobj, '_iodev', None)
if iodev:
# we want also to see debug messages of iodev
if iodev.remoteLogHandler is None:
iodev.remoteLogHandler = RemoteLogHandler(self)
iodev.remoteLogHandler.used_by.add(self.modobj)
level = checkLevel(level)
if level == OFF:
self.subscriptions.pop(conn, None)
else:
self.subscriptions[conn] = level

54
secop/modules.py
View File

@ -31,13 +31,21 @@ from secop.datatypes import ArrayOf, BoolType, EnumType, FloatRange, \
IntRange, StatusType, StringType, TextType, TupleOf
from secop.errors import BadValueError, ConfigError, \
ProgrammingError, SECoPError, SilentError, secop_error
from secop.lib import formatException, mkthread
from secop.lib import formatException, mkthread, UniqueObject
from secop.lib.enum import Enum
from secop.params import Accessible, Command, Parameter
from secop.poller import BasicPoller, Poller
from secop.properties import HasProperties, Property
from secop.logging import RemoteLogHandler, add_comlog_handler
Done = object() #: a special return value for a read/write function indicating that the setter is triggered already
class DoneClass:
@classmethod
def __repr__(cls):
return 'Done'
Done = UniqueObject('Done')
class HasAccessibles(HasProperties):
@ -124,20 +132,20 @@ class HasAccessibles(HasProperties):
def wrapped_rfunc(self, pname=pname, rfunc=rfunc):
if rfunc:
self.log.debug("calling %r" % rfunc)
self.log.debug("call read_%s" % pname)
try:
value = rfunc(self)
self.log.debug("rfunc(%s) returned %r" % (pname, value))
self.log.debug("read_%s returned %r" % (pname, value))
if value is Done: # the setter is already triggered
return getattr(self, pname)
except Exception as e:
self.log.debug("rfunc(%s) failed %r" % (pname, e))
self.log.debug("read_%s failed %r" % (pname, e))
self.announceUpdate(pname, None, e)
raise
else:
# return cached value
self.log.debug("rfunc(%s): return cached value" % pname)
value = self.accessibles[pname].value
self.log.debug("return cached %s = %r" % (pname, value))
setattr(self, pname, value) # important! trigger the setter
return value
@ -158,16 +166,19 @@ class HasAccessibles(HasProperties):
if not wrapped:
def wrapped_wfunc(self, value, pname=pname, wfunc=wfunc):
self.log.debug("check validity of %s = %r" % (pname, value))
pobj = self.accessibles[pname]
value = pobj.datatype(value)
if wfunc:
self.log.debug('calling %s %r(%r)' % (wfunc.__name__, wfunc, value))
self.log.debug("check and call write_%s(%r)" % (pname, value))
value = pobj.datatype(value)
returned_value = wfunc(self, value)
self.log.debug('write_%s returned %r' % (pname, returned_value))
if returned_value is Done: # the setter is already triggered
return getattr(self, pname)
if returned_value is not None: # goodie: accept missing return value
value = returned_value
else:
self.log.debug("check %s = %r" % (pname, value))
value = pobj.datatype(value)
setattr(self, pname, value)
return value
@ -176,11 +187,17 @@ class HasAccessibles(HasProperties):
setattr(cls, 'write_' + pname, wrapped_wfunc)
wrapped_wfunc.__wrapped__ = True
# check information about Command's
# check for programming errors
for attrname in cls.__dict__:
if attrname.startswith('do_'):
prefix, _, pname = attrname.partition('_')
if not pname:
continue
if prefix == 'do':
raise ProgrammingError('%r: old style command %r not supported anymore'
% (cls.__name__, attrname))
elif prefix in ('read', 'write') and not isinstance(accessibles.get(pname), Parameter):
raise ProgrammingError('%s.%s defined, but %r is no parameter'
% (cls.__name__, attrname, pname))
res = {}
# collect info about properties
@ -434,6 +451,10 @@ class Module(HasAccessibles):
errors.append('%s: %s' % (aname, e))
if errors:
raise ConfigError(errors)
self.remoteLogHandler = None
self._earlyInitDone = False
self._initModuleDone = False
self._startModuleDone = False
# helper cfg-editor
def __iter__(self):
@ -579,6 +600,11 @@ class Module(HasAccessibles):
started_callback()
self.startModuleDone = True
def setRemoteLogging(self, conn, level):
if self.remoteLogHandler is None:
self.remoteLogHandler = RemoteLogHandler(self)
self.remoteLogHandler.set_conn_level(conn, level)
class Readable(Module):
"""basic readable module"""
@ -697,6 +723,10 @@ class Drivable(Writable):
class Communicator(Module):
"""basic abstract communication module"""
def initModule(self):
super().initModule()
add_comlog_handler(self)
@Command(StringType(), result=StringType())
def communicate(self, command):
"""communicate command
@ -708,7 +738,7 @@ class Communicator(Module):
class Attached(Property):
"""a special property, defining an attached modle
"""a special property, defining an attached module
assign a module name to this property in the cfg file,
and the server will create an attribute with this module

25
secop/protocol/dispatcher.py
View File

@ -130,6 +130,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):
@ -375,11 +376,33 @@ class Dispatcher:
# 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', '%s:%s' % (modname, level), msg))
return True
return False
def set_all_log_levels(self, conn, level):
for modobj in self._modules.values():
modobj.setRemoteLogging(conn, level)
def handle_logging(self, conn, specifier, level):
if specifier and specifier != '.':
modobj = self._modules[specifier]
iodev = getattr(modobj, '_iodev', None)
if iodev and iodev.remoteLogHandler is None:
iodev.setRemoteLogging(conn, 'off')
iodev.remoteLogHandler.used_by.add(modobj)
modobj.setRemoteLogging(conn, level)
else:
self.set_all_log_levels(conn, level)
return 'logging', specifier, level
def close(self):
for conn in self._connections:
try:
# - may be used for the 'closed' message in serial interface
# - is used in frappy history for indicating the close time
conn.close_message((ERRORCLOSED, None, None))
except AttributeError:
pass