From 7316632fa69d67b7e30b9ee2be618c103c48fe46 Mon Sep 17 00:00:00 2001 From: Markus Zolliker Date: Mon, 11 Apr 2022 18:45:56 +0200 Subject: [PATCH] improve poller error handling - repeated errors on poller are only once logged (per poll function / read_* method) - during exception handling, silent=True on a SECoP error indicates that the error is already logged + fix the name of HardwareError + add test for consistency of SECoPErrors + catch socket.timeout in AsynTcp Change-Id: I9df6c775cc19553b22a4d6e39591092adf7ff9a1 Reviewed-on: https://forge.frm2.tum.de/review/c/sine2020/secop/playground/+/28139 Tested-by: Jenkins Automated Tests Reviewed-by: Markus Zolliker Reviewed-by: Enrico Faulhaber --- secop/errors.py | 15 +++++-------- secop/io.py | 49 ++++++++++++++++++++++++------------------- secop/lib/asynconn.py | 2 +- secop/modules.py | 45 +++++++++++++++++++-------------------- test/test_errors.py | 30 ++++++++++++++++++++++++++ 5 files changed, 84 insertions(+), 57 deletions(-) create mode 100644 test/test_errors.py diff --git a/secop/errors.py b/secop/errors.py index c50cbac..5affb4a 100644 --- a/secop/errors.py +++ b/secop/errors.py @@ -17,12 +17,14 @@ # # Module authors: # Enrico Faulhaber +# Markus Zolliker # # ***************************************************************************** """Define (internal) SECoP Errors""" class SECoPError(RuntimeError): + silent = False # silent = True indicates that the error is already logged def __init__(self, *args, **kwds): super().__init__() @@ -32,7 +34,8 @@ class SECoPError(RuntimeError): def __repr__(self): args = ', '.join(map(repr, self.args)) - kwds = ', '.join(['%s=%r' % i for i in list(self.__dict__.items())]) + kwds = ', '.join(['%s=%r' % i for i in list(self.__dict__.items()) + if i[0] != 'silent']) res = [] if args: res.append(args) @@ -102,14 +105,6 @@ class CommunicationFailedError(SECoPError): pass -class SilentError(SECoPError): - pass - - -class CommunicationSilentError(SilentError, CommunicationFailedError): - name = 'CommunicationFailed' - - class IsBusyError(SECoPError): pass @@ -123,7 +118,7 @@ class DisabledError(SECoPError): class HardwareError(SECoPError): - pass + name = 'HardwareError' def make_secop_error(name, text): diff --git a/secop/io.py b/secop/io.py index d7e09df..07932ef 100644 --- a/secop/io.py +++ b/secop/io.py @@ -31,8 +31,7 @@ import threading from secop.lib.asynconn import AsynConn, ConnectionClosed from secop.datatypes import ArrayOf, BLOBType, BoolType, FloatRange, IntRange, \ StringType, TupleOf, ValueType -from secop.errors import CommunicationFailedError, CommunicationSilentError, \ - ConfigError, ProgrammingError +from secop.errors import CommunicationFailedError, ConfigError, ProgrammingError from secop.modules import Attached, Command, \ Communicator, Done, Module, Parameter, Property from secop.lib import generalConfig @@ -42,6 +41,10 @@ generalConfig.set_default('legacy_hasiodev', False) HEX_CODE = re.compile(r'[0-9a-fA-F][0-9a-fA-F]$') +class SilentError(CommunicationFailedError): + silent = True + + class HasIO(Module): """Mixin for modules using a communicator""" io = Attached() @@ -151,11 +154,10 @@ class IOBase(Communicator): self.callCallbacks() return Done except Exception as e: - if str(e) == self._last_error: - raise CommunicationSilentError(str(e)) from e - self._last_error = str(e) - self.log.error(self._last_error) - raise + if str(e) != self._last_error: + self._last_error = str(e) + self.log.error(self._last_error) + raise SilentError(repr(e)) from e return Done def write_is_connected(self, value): @@ -249,10 +251,10 @@ class StringIO(IOBase): """ command = command.encode(self.encoding) if not self.is_connected: + # do not try to reconnect here + # read_is_connected is doing this when called by its poller self.read_is_connected() # try to reconnect - if not self._conn: - self.log.debug('can not connect to %r' % self.uri) - raise CommunicationSilentError('can not connect to %r' % self.uri) + raise SilentError('disconnected') from None try: with self._lock: # read garbage and wait before send @@ -279,11 +281,12 @@ class StringIO(IOBase): self.comLog('< %s', reply) return reply except Exception as e: - if str(e) == self._last_error: - raise CommunicationSilentError(str(e)) from None - self._last_error = str(e) - self.log.error(self._last_error) - raise + if self._conn is None: + raise SilentError('disconnected') from None + if repr(e) != self._last_error: + self._last_error = str(e) + self.log.error(self._last_error) + raise SilentError(repr(e)) from e @Command(ArrayOf(StringType()), result=ArrayOf(StringType())) def multicomm(self, commands): @@ -357,9 +360,10 @@ class BytesIO(IOBase): def communicate(self, request, replylen): # pylint: disable=arguments-differ """send a request and receive (at least) bytes as reply""" if not self.is_connected: + # do not try to reconnect here + # read_is_connected is doing this when called by its poller self.read_is_connected() # try to reconnect - if not self._conn: - raise CommunicationSilentError('can not connect to %r' % self.uri) + raise SilentError('disconnected') from None try: with self._lock: # read garbage and wait before send @@ -378,11 +382,12 @@ class BytesIO(IOBase): self.comLog('< %s', hexify(reply)) return self.getFullReply(request, reply) except Exception as e: - if str(e) == self._last_error: - raise CommunicationSilentError(str(e)) from None - self._last_error = str(e) - self.log.error(self._last_error) - raise + if self._conn is None: + raise SilentError('disconnected') from None + if repr(e) != self._last_error: + self._last_error = str(e) + self.log.error(self._last_error) + raise SilentError(repr(e)) from e @Command((ArrayOf(TupleOf(BLOBType(), IntRange(0)))), result=ArrayOf(BLOBType())) def multicomm(self, requests): diff --git a/secop/lib/asynconn.py b/secop/lib/asynconn.py index 9d5df16..52d3878 100644 --- a/secop/lib/asynconn.py +++ b/secop/lib/asynconn.py @@ -167,7 +167,7 @@ class AsynTcp(AsynConn): uri = uri[6:] try: self.connection = tcpSocket(uri, self.defaultport, self.timeout) - except (ConnectionRefusedError, socket.gaierror) as e: + except (ConnectionRefusedError, socket.gaierror, socket.timeout) as e: # indicate that retrying might make sense raise CommunicationFailedError(str(e)) from None diff --git a/secop/modules.py b/secop/modules.py index 883815f..48ebfa5 100644 --- a/secop/modules.py +++ b/secop/modules.py @@ -31,7 +31,7 @@ from functools import wraps from secop.datatypes import ArrayOf, BoolType, EnumType, FloatRange, \ IntRange, StatusType, StringType, TextType, TupleOf, DiscouragedConversion from secop.errors import BadValueError, ConfigError, \ - ProgrammingError, SECoPError, SilentError, secop_error + ProgrammingError, SECoPError, secop_error from secop.lib import formatException, mkthread, UniqueObject, generalConfig from secop.lib.enum import Enum from secop.params import Accessible, Command, Parameter @@ -233,7 +233,7 @@ class PollInfo: self.interval = pollinterval self.last_main = 0 self.last_slow = 0 - self.last_error = None + self.last_error = {} # dict [] of (None or str(last exception)) self.polled_parameters = [] self.fast_flag = False self.trigger_event = trigger_event @@ -633,12 +633,19 @@ class Module(HasAccessibles): """call read method with proper error handling""" try: rfunc() - except SilentError: - pass - except SECoPError as e: - self.log.error(str(e)) - except Exception: - self.log.error(formatException()) + self.pollInfo.last_error[rfunc.__name__] = None + except Exception as e: + name = rfunc.__name__ + if str(e) != self.pollInfo.last_error.get(name): + self.pollInfo.last_error[name] = str(e) + if isinstance(e, SECoPError): + if e.silent: + self.log.debug('%s: %s', name, str(e)) + else: + self.log.error('%s: %s', name, str(e)) + else: + # uncatched error: this is more serious + self.log.error('%s: %s', name, formatException()) def __pollThread(self, modules, started_callback): """poll thread body @@ -693,25 +700,14 @@ class Module(HasAccessibles): pinfo = mobj.pollInfo if now > pinfo.last_main + pinfo.interval: pinfo.last_main = (now // pinfo.interval) * pinfo.interval - try: - mobj.doPoll() - pinfo.last_error = None - except Exception as e: - if str(e) != str(pinfo.last_error) and not isinstance(e, SilentError): - mobj.log.error('doPoll: %r', e) - pinfo.last_error = e + mobj.callPollFunc(mobj.doPoll) now = time.time() # find ONE due slow poll and call it loop = True while loop: # loops max. 2 times, when to_poll is at end for mobj, rfunc, pobj in to_poll: if now > pobj.timestamp + mobj.slowinterval * 0.5: - try: - prev_err = pobj.readerror - rfunc() - except Exception as e: - if not isinstance(e, SilentError) and str(pobj.readerror) != str(prev_err): - mobj.log.error('%s: %r', pobj.name, e) + mobj.callPollFunc(rfunc) loop = False # one poll done break else: @@ -744,10 +740,11 @@ class Module(HasAccessibles): try: self.log.debug('initialize parameter %s', pname) wfunc(value) - except SilentError: - pass except SECoPError as e: - self.log.error(str(e)) + if e.silent: + self.log.debug('%s: %s', pname, str(e)) + else: + self.log.error('%s: %s', pname, str(e)) except Exception: self.log.error(formatException()) if started_callback: diff --git a/test/test_errors.py b/test/test_errors.py new file mode 100644 index 0000000..fd455eb --- /dev/null +++ b/test/test_errors.py @@ -0,0 +1,30 @@ +# -*- 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 +# +# ***************************************************************************** +"""test data types.""" + +import secop.errors + + +def test_errors(): + """check consistence of secop.errors.EXCEPTIONS""" + for e in secop.errors.EXCEPTIONS.values(): + assert secop.errors.EXCEPTIONS[e().name] == e