improve error messages

- treat validation errors of the result of write_ and read_ messages
  properly
- add info about the called read_* and write_ methods to the error
  message, in case the error is not raised in the outmost method
- as subsequent errors in poll functions are logged only once, log an
  info when a poll function succeeds again
- remove DiscouragedConversion error

Change-Id: Ib66e001cc95de8225751a1464a92594c369ceb3f
Reviewed-on: https://forge.frm2.tum.de/review/c/secop/frappy/+/30788
Tested-by: Jenkins Automated Tests <pedersen+jenkins@frm2.tum.de>
Reviewed-by: Markus Zolliker <markus.zolliker@psi.ch>
This commit is contained in:
zolliker 2023-03-24 17:22:02 +01:00
parent df8bc1c203
commit d0af831b1f
5 changed files with 127 additions and 98 deletions

View File

@ -28,8 +28,8 @@
import sys import sys
from base64 import b64decode, b64encode from base64 import b64decode, b64encode
from frappy.errors import ConfigError, DiscouragedConversion, \ from frappy.errors import ConfigError, ProgrammingError, \
ProgrammingError, ProtocolError, RangeError, WrongTypeError ProtocolError, RangeError, WrongTypeError
from frappy.lib import clamp, generalConfig from frappy.lib import clamp, generalConfig
from frappy.lib.enum import Enum from frappy.lib.enum import Enum
from frappy.parse import Parser from frappy.parse import Parser
@ -223,11 +223,11 @@ class FloatRange(HasUnit, DataType):
value += 0.0 # do not accept strings here value += 0.0 # do not accept strings here
except Exception: except Exception:
try: try:
if not generalConfig.lazy_number_validation:
raise
value = float(value) value = float(value)
except Exception: except Exception:
raise WrongTypeError('can not convert %s to a float' % shortrepr(value)) from None raise WrongTypeError('can not convert %s to a float' % shortrepr(value)) from None
if not generalConfig.lazy_number_validation:
raise DiscouragedConversion('automatic string to float conversion no longer supported') from None
# map +/-infty to +/-max possible number # map +/-infty to +/-max possible number
return clamp(-sys.float_info.max, value, sys.float_info.max) return clamp(-sys.float_info.max, value, sys.float_info.max)
@ -240,8 +240,9 @@ class FloatRange(HasUnit, DataType):
if self.min - prec <= value <= self.max + prec: if self.min - prec <= value <= self.max + prec:
# silently clamp when outside by not more than prec # silently clamp when outside by not more than prec
return clamp(self.min, value, self.max) return clamp(self.min, value, self.max)
raise RangeError('%.14g must be between %d and %d' % info = self.exportProperties()
(value, self.min, self.max)) raise RangeError('%.14g must be between %g and %g' %
(value, info.get('min', float('-inf')), info.get('max', float('inf'))))
def __repr__(self): def __repr__(self):
hints = self.get_info() hints = self.get_info()
@ -308,12 +309,12 @@ class IntRange(DataType):
value = int(value) value = int(value)
except Exception: except Exception:
try: try:
if not generalConfig.lazy_number_validation:
raise
fvalue = float(value) fvalue = float(value)
value = int(value) value = int(value)
except Exception: except Exception:
raise WrongTypeError('can not convert %s to an int' % shortrepr(value)) from None raise WrongTypeError('can not convert %s to an int' % shortrepr(value)) from None
if not generalConfig.lazy_number_validation:
raise DiscouragedConversion('automatic string to float conversion no longer supported') from None
if round(fvalue) != fvalue: if round(fvalue) != fvalue:
raise WrongTypeError('%r should be an int') raise WrongTypeError('%r should be an int')
return value return value
@ -430,11 +431,11 @@ class ScaledInteger(HasUnit, DataType):
value += 0.0 # do not accept strings here value += 0.0 # do not accept strings here
except Exception: except Exception:
try: try:
if not generalConfig.lazy_number_validation:
raise
value = float(value) value = float(value)
except Exception: except Exception:
raise WrongTypeError('can not convert %s to float' % shortrepr(value)) from None raise WrongTypeError('can not convert %s to float' % shortrepr(value)) from None
if not generalConfig.lazy_number_validation:
raise DiscouragedConversion('automatic string to float conversion no longer supported') from None
intval = int(round(value / self.scale)) intval = int(round(value / self.scale))
return float(intval * self.scale) # return 'actual' value (which is more discrete than a float) return float(intval * self.scale) # return 'actual' value (which is more discrete than a float)

View File

@ -34,6 +34,8 @@ class SECoPError(RuntimeError):
clsname2class = {} # needed to convert error reports back to classes clsname2class = {} # needed to convert error reports back to classes
name = 'InternalError' name = 'InternalError'
name2class = {} name2class = {}
report_error = True
raising_methods = None
def __init_subclass__(cls): def __init_subclass__(cls):
cls.clsname2class[cls.__name__] = cls cls.clsname2class[cls.__name__] = cls
@ -43,20 +45,46 @@ class SECoPError(RuntimeError):
def __init__(self, *args, **kwds): def __init__(self, *args, **kwds):
super().__init__() super().__init__()
self.args = args self.args = args
self.kwds = kwds
for k, v in list(kwds.items()): for k, v in list(kwds.items()):
setattr(self, k, v) setattr(self, k, v)
self.raising_methods = []
def __repr__(self): def __repr__(self):
args = ', '.join(map(repr, self.args))
kwds = ', '.join(['%s=%r' % i for i in list(self.__dict__.items())
if i[0] != 'silent'])
res = [] res = []
if args: res.extend((repr(a) for a in self.args))
res.append(args) #res.extend(('%s=%r' % i for i in self.kwds.items()))
if kwds:
res.append(kwds)
return '%s(%s)' % (self.name or type(self).__name__, ', '.join(res)) return '%s(%s)' % (self.name or type(self).__name__, ', '.join(res))
def __str__(self):
return self.format(True)
def format(self, stripped):
"""format with info about raising methods
:param stripped: strip last method.
Use stripped=True (or str()) for the following cases, as the last method can be derived from the context:
- stored in pobj.readerror: read_<pobj.name>
- error message from a change command: write_<pname>
- error message from a read command: read_<pname>
Use stripped=False for the log file, as the related parameter is not known
:return: the formatted error message
"""
mlist = self.raising_methods
if mlist and stripped:
mlist = mlist[:-1] # do not pop, as this would change self.raising_methods
prefix = '' if self.name2class.get(self.name) == type(self) else type(self).__name__
prefix += ''.join(' in ' + m for m in mlist).strip()
if prefix:
return '%s: %s' % (prefix, super().__str__())
return super().__str__()
def __eq__(self, other):
return type(self) is type(other) and self.args == other.args and self.kwds == other.kwds
def __ne__(self, other):
return not self == other
class InternalError(SECoPError): class InternalError(SECoPError):
"""uncatched error""" """uncatched error"""
@ -122,7 +150,7 @@ class BadValueError(SECoPError):
"""do not raise, but might used for instance checks (WrongTypeError, RangeError)""" """do not raise, but might used for instance checks (WrongTypeError, RangeError)"""
class RangeError(ValueError, BadValueError): class RangeError(BadValueError, ValueError):
"""data out of range """data out of range
The requested parameter change or Command can not be performed as the The requested parameter change or Command can not be performed as the
@ -143,7 +171,7 @@ class BadJSONError(SECoPError):
name = 'BadJSON' name = 'BadJSON'
class WrongTypeError(TypeError, BadValueError): class WrongTypeError(BadValueError, TypeError):
"""Wrong data type """Wrong data type
The requested parameter change or Command can not be performed as the The requested parameter change or Command can not be performed as the
@ -153,11 +181,6 @@ class WrongTypeError(TypeError, BadValueError):
name = 'WrongType' name = 'WrongType'
class DiscouragedConversion(ProgrammingError):
"""the discouraged conversion string - > float happened"""
log_message = True
class CommandFailedError(SECoPError): class CommandFailedError(SECoPError):
name = 'CommandFailed' name = 'CommandFailed'
@ -244,8 +267,6 @@ def make_secop_error(name, text):
def secop_error(exc): def secop_error(exc):
"""turn into InternalError, if not already a SECoPError""" """turn into InternalError, if not already a SECoPError"""
if isinstance(exc, SECoPError): if isinstance(exc, SECoPError):
if SECoPError.name2class.get(exc.name) != type(exc):
return type(exc)('%s: %s' % (type(exc).__name__, exc))
return exc return exc
return InternalError('%s: %s' % (type(exc).__name__, exc)) return InternalError('%s: %s' % (type(exc).__name__, exc))

View File

@ -28,7 +28,7 @@ import threading
from collections import OrderedDict from collections import OrderedDict
from frappy.datatypes import ArrayOf, BoolType, EnumType, FloatRange, \ from frappy.datatypes import ArrayOf, BoolType, EnumType, FloatRange, \
IntRange, StatusType, StringType, TextType, TupleOf, DiscouragedConversion, \ IntRange, StatusType, StringType, TextType, TupleOf, \
NoneOr NoneOr
from frappy.errors import BadValueError, CommunicationFailedError, ConfigError, \ from frappy.errors import BadValueError, CommunicationFailedError, ConfigError, \
ProgrammingError, SECoPError, secop_error, RangeError ProgrammingError, SECoPError, secop_error, RangeError
@ -128,13 +128,17 @@ class HasAccessibles(HasProperties):
try: try:
value = rfunc(self) value = rfunc(self)
self.log.debug("read_%s returned %r", pname, value) self.log.debug("read_%s returned %r", pname, value)
if value is Done: # TODO: to be removed when all code using Done is updated
return getattr(self, pname)
pobj = self.accessibles[pname]
value = pobj.datatype(value)
except Exception as e: except Exception as e:
self.log.debug("read_%s failed with %r", pname, e) self.log.debug("read_%s failed with %r", pname, e)
self.announceUpdate(pname, None, e) if isinstance(e, SECoPError):
e.raising_methods.append('%s.read_%s' % (self.name, pname))
self.announceUpdate(pname, err=e)
raise raise
if value is Done: # TODO: to be removed when all code using Done is updated self.announceUpdate(pname, value, validate=False)
return getattr(self, pname)
setattr(self, pname, value) # important! trigger the setter
return value return value
new_rfunc.poll = getattr(rfunc, 'poll', True) new_rfunc.poll = getattr(rfunc, 'poll', True)
@ -166,41 +170,32 @@ class HasAccessibles(HasProperties):
cfuncs = tuple(filter(None, (b.__dict__.get(cname) for b in cls.__mro__))) cfuncs = tuple(filter(None, (b.__dict__.get(cname) for b in cls.__mro__)))
wname = 'write_' + pname wname = 'write_' + pname
wfunc = getattr(cls, wname, None) wfunc = getattr(cls, wname, None)
if wfunc: if wfunc or not pobj.readonly:
# allow write method even when parameter is readonly, but internally writable # allow write method even when parameter is readonly, but internally writable
def new_wfunc(self, value, pname=pname, wfunc=wfunc, check_funcs=cfuncs): def new_wfunc(self, value, pname=pname, wfunc=wfunc, check_funcs=cfuncs):
with self.accessLock: with self.accessLock:
pobj = self.accessibles[pname] self.log.debug('validate %r to datatype of %r', value, pname)
self.log.debug('convert %r to datatype of %r', value, pname) validate = self.parameters[pname].datatype.validate
# we do not need to handle errors here, we do not try:
# want to make a parameter invalid, when a write failed new_value = validate(value)
new_value = pobj.datatype(value) for c in check_funcs:
for c in check_funcs: if c(self, value):
if c(self, value): break
break if wfunc:
new_value = wfunc(self, new_value) new_value = wfunc(self, new_value)
self.log.debug('write_%s(%r) returned %r', pname, value, new_value) self.log.debug('write_%s(%r) returned %r', pname, value, new_value)
if new_value is Done: # TODO: to be removed when all code using Done is updated if new_value is Done: # TODO: to be removed when all code using Done is updated
return getattr(self, pname) return getattr(self, pname)
if new_value is None: new_value = value if new_value is None else validate(new_value)
new_value = value except Exception as e:
setattr(self, pname, new_value) # important! trigger the setter if isinstance(e, SECoPError):
e.raising_methods.append('%s.write_%s' % (self.name, pname))
self.announceUpdate(pname, err=e)
raise
self.announceUpdate(pname, new_value, validate=False)
return new_value return new_value
elif pobj.readonly:
new_wfunc = None
else:
def new_wfunc(self, value, pname=pname, check_funcs=cfuncs):
value = self.accessibles[pname].datatype(value)
for c in check_funcs:
if c(self, value):
break
setattr(self, pname, value)
return value
if new_wfunc:
new_wfunc.__name__ = wname new_wfunc.__name__ = wname
new_wfunc.__qualname__ = wrapped_name + '.' + wname new_wfunc.__qualname__ = wrapped_name + '.' + wname
new_wfunc.__module__ = cls.__module__ new_wfunc.__module__ = cls.__module__
@ -260,7 +255,7 @@ class PollInfo:
self.interval = pollinterval self.interval = pollinterval
self.last_main = 0 self.last_main = 0
self.last_slow = 0 self.last_slow = 0
self.last_error = {} # dict [<name of poll func>] of (None or str(last exception)) self.pending_errors = set()
self.polled_parameters = [] self.polled_parameters = []
self.fast_flag = False self.fast_flag = False
self.trigger_event = trigger_event self.trigger_event = trigger_event
@ -377,7 +372,7 @@ class Module(HasAccessibles):
(key, value, self.propertyDict[key].datatype)) (key, value, self.propertyDict[key].datatype))
# 3) set automatic properties # 3) set automatic properties
mycls = self.__class__ mycls, = self.__class__.__bases__ # skip the wrapper class
myclassname = '%s.%s' % (mycls.__module__, mycls.__name__) myclassname = '%s.%s' % (mycls.__module__, mycls.__name__)
self.implementation = myclassname self.implementation = myclassname
# list of all 'secop' modules # list of all 'secop' modules
@ -525,43 +520,50 @@ class Module(HasAccessibles):
for pobj in self.parameters.values(): for pobj in self.parameters.values():
pobj.datatype.set_main_unit(mainunit) pobj.datatype.set_main_unit(mainunit)
def announceUpdate(self, pname, value=None, err=None, timestamp=None): def announceUpdate(self, pname, value=None, err=None, timestamp=None, validate=True):
"""announce a changed value or readerror""" """announce a changed value or readerror
:param pname: parameter name
:param value: new value or None in case of error
:param err: None or an exception
:param timestamp: a timestamp or None for taking current time
:param validate: True: convert to datatype, in case of error store in readerror
:return:
when err=None and validate=False, the value must already be converted to the datatype
"""
with self.updateLock: with self.updateLock:
# TODO: remove readerror 'property' and replace value with exception
pobj = self.parameters[pname] pobj = self.parameters[pname]
timestamp = timestamp or time.time() timestamp = timestamp or time.time()
try: if not err:
value = pobj.datatype(value) try:
changed = pobj.value != value if validate:
# store the value even in case of error value = pobj.datatype(value)
pobj.value = value except Exception as e:
except Exception as e:
if isinstance(e, DiscouragedConversion):
if DiscouragedConversion.log_message:
self.log.error(str(e))
self.log.error('you may disable this behaviour by running the server with --relaxed')
DiscouragedConversion.log_message = False
if not err: # do not overwrite given error
err = e err = e
else:
changed = pobj.value != value
# store the value even in case of error
pobj.value = value
if err: if err:
err = secop_error(err) if secop_error(err) == pobj.readerror:
if str(err) == str(pobj.readerror): err.report_error = False
return # no updates for repeated errors return # no updates for repeated errors
err = secop_error(err)
elif not changed and timestamp < (pobj.timestamp or 0) + pobj.omit_unchanged_within: elif not changed and timestamp < (pobj.timestamp or 0) + pobj.omit_unchanged_within:
# no change within short time -> omit # no change within short time -> omit
return return
pobj.timestamp = timestamp or time.time() pobj.timestamp = timestamp or time.time()
pobj.readerror = err
if pobj.export:
self.DISPATCHER.announce_update(self.name, pname, pobj)
if err: if err:
callbacks = self.errorCallbacks callbacks = self.errorCallbacks
arg = err pobj.readerror = arg = err
else: else:
callbacks = self.valueCallbacks callbacks = self.valueCallbacks
arg = value arg = value
pobj.readerror = None
if pobj.export:
self.DISPATCHER.announce_update(self.name, pname, pobj)
cblist = callbacks[pname] cblist = callbacks[pname]
for cb in cblist: for cb in cblist:
try: try:
@ -666,21 +668,25 @@ class Module(HasAccessibles):
"""call read method with proper error handling""" """call read method with proper error handling"""
try: try:
rfunc() rfunc()
self.pollInfo.last_error[rfunc.__name__] = None if rfunc.__name__ in self.pollInfo.pending_errors:
self.log.info('%s: o.k.', rfunc.__name__)
self.pollInfo.pending_errors.discard(rfunc.__name__)
except Exception as e: except Exception as e:
name = rfunc.__name__ if getattr(e, 'report_error', True):
if str(e) != self.pollInfo.last_error.get(name): name = rfunc.__name__
self.pollInfo.last_error[name] = str(e) self.pollInfo.pending_errors.add(name) # trigger o.k. message after error is resolved
if isinstance(e, SECoPError): if isinstance(e, SECoPError):
e.raising_methods.append(name)
if e.silent: if e.silent:
self.log.debug('%s: %s', name, str(e)) self.log.debug('%s', e.format(False))
else: else:
self.log.error('%s: %s', name, str(e)) self.log.error('%s', e.format(False))
if raise_com_failed and isinstance(e, CommunicationFailedError):
raise
else: else:
# uncatched error: this is more serious # not a SECoPError: this is proabably a programming error
self.log.error('%s: %s', name, formatException()) # we want to log the traceback
if raise_com_failed and isinstance(e, CommunicationFailedError): self.log.error('%s', formatException())
raise
def __pollThread(self, modules, started_callback): def __pollThread(self, modules, started_callback):
"""poll thread body """poll thread body
@ -735,7 +741,8 @@ class Module(HasAccessibles):
pinfo = mobj.pollInfo pinfo = mobj.pollInfo
wait_time = min(pinfo.last_main + pinfo.interval - now, wait_time, wait_time = min(pinfo.last_main + pinfo.interval - now, wait_time,
pinfo.last_slow + mobj.slowinterval - now) pinfo.last_slow + mobj.slowinterval - now)
if wait_time > 0: if wait_time > 0 and not to_poll:
# nothing to do
self.triggerPoll.wait(wait_time) self.triggerPoll.wait(wait_time)
self.triggerPoll.clear() self.triggerPoll.clear()
continue continue

View File

@ -26,7 +26,7 @@
import pytest import pytest
from frappy.datatypes import ArrayOf, BLOBType, BoolType, CommandType, \ from frappy.datatypes import ArrayOf, BLOBType, BoolType, CommandType, \
ConfigError, DataType, DiscouragedConversion, EnumType, FloatRange, \ ConfigError, DataType, EnumType, FloatRange, \
IntRange, ProgrammingError, ScaledInteger, StatusType, StringType, \ IntRange, ProgrammingError, ScaledInteger, StatusType, StringType, \
StructOf, TextType, TupleOf, ValueType, get_datatype StructOf, TextType, TupleOf, ValueType, get_datatype
from frappy.errors import BadValueError, RangeError, WrongTypeError from frappy.errors import BadValueError, RangeError, WrongTypeError
@ -702,7 +702,7 @@ def test_lazy_validation(dt):
generalConfig.defaults['lazy_number_validation'] = True generalConfig.defaults['lazy_number_validation'] = True
dt('0') dt('0')
generalConfig.defaults['lazy_number_validation'] = False generalConfig.defaults['lazy_number_validation'] = False
with pytest.raises(DiscouragedConversion): with pytest.raises(WrongTypeError):
dt('0') dt('0')

View File

@ -23,7 +23,7 @@
import pytest import pytest
from frappy.errors import RangeError, WrongTypeError, ProgrammingError, \ from frappy.errors import RangeError, WrongTypeError, ProgrammingError, \
ConfigError, InternalError, DiscouragedConversion, secop_error, make_secop_error ConfigError, InternalError, TimeoutSECoPError, secop_error, make_secop_error
@pytest.mark.parametrize('exc, name, text, echk', [ @pytest.mark.parametrize('exc, name, text, echk', [
@ -32,7 +32,7 @@ from frappy.errors import RangeError, WrongTypeError, ProgrammingError, \
(ProgrammingError('x'), 'InternalError', 'ProgrammingError: x', None), (ProgrammingError('x'), 'InternalError', 'ProgrammingError: x', None),
(ConfigError('y'), 'InternalError', 'ConfigError: y', None), (ConfigError('y'), 'InternalError', 'ConfigError: y', None),
(InternalError('z'), 'InternalError', 'z', None), (InternalError('z'), 'InternalError', 'z', None),
(DiscouragedConversion('w'), 'InternalError', 'DiscouragedConversion: w', None), (TimeoutSECoPError('t'), 'TimeoutError', 't', None),
(ValueError('v'), 'InternalError', "ValueError: v", InternalError("ValueError: v")), (ValueError('v'), 'InternalError', "ValueError: v", InternalError("ValueError: v")),
(None, 'InternalError', "UnknownError: v", InternalError("UnknownError: v")), (None, 'InternalError', "UnknownError: v", InternalError("UnknownError: v")),
]) ])