Serial Exception: read failed

[Phi2k]

About once per week I get the following exception causing the script to stop.
I suppose this is a system error (it did not happen on my first setup on a Raspberry Pi Zero. The current setup is Raspberry Pi 5, 2x Docker container and 2x serial hardware both containers reporting to two separate MQTT broker.

Is it possible to catch this error (e.g. like that: https://forums.raspberrypi.com/viewtopic.php?t=201976#p1256252) or at least cause the container to exit that it can restart properly? Current situation is that this error does not trigger a restart. My current workaround would be to schedule a restart every day.

ERROR:asyncio:Task exception was never retrieved
future: <Task finished name='Task-22' coro=<Mqtt.listen() done, defined at /comfospot/comfospot40/mqtt.py:30> exception=MqttError('Disconnected during message iteration')>
Traceback (most recent call last):
  File "/comfospot/comfospot40/mqtt.py", line 32, in listen
    async for message in messages:
  File "/usr/lib/python3.11/site-packages/aiomqtt/client.py", line 684, in _generator
    raise MqttError(msg)
aiomqtt.error.MqttError: Disconnected during message iteration
Traceback (most recent call last):
  File "/usr/lib/python3.11/site-packages/serial/serialposix.py", line 500, in read
    raise SerialException(
serial.serialutil.SerialException: device reports readiness to read but returned no data (device disconnected or multiple access on port?)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/comfospot/server.py", line 103, in <module>
    asyncio.run(
  File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run
    return runner.run(main)
           ^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run
    return self._loop.run_until_complete(task)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/asyncio/base_events.py", line 653, in run_until_complete
    return future.result()
           ^^^^^^^^^^^^^^^
  File "/comfospot/server.py", line 46, in main
    state = x.result()
            ^^^^^^^^^^
  File "/comfospot/comfospot40/parser.py", line 86, in run
    self.parserdata, self.parserstate = await self.parserstate(self.parserdata)
                                        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/comfospot/comfospot40/parser.py", line 58, in search_preamble
    readbyte = await self._ser.read(1)
               ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/asyncio/streams.py", line 693, in read
    await self._wait_for_data('read')
  File "/usr/lib/python3.11/asyncio/streams.py", line 525, in _wait_for_data
    await self._waiter
  File "/usr/lib/python3.11/site-packages/serial_asyncio/__init__.py", line 115, in _read_ready
    data = self._serial.read(self._max_read_size)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/serial/serialposix.py", line 509, in read
    raise SerialException('read failed: {}'.format(e))
serial.serialutil.SerialException: read failed: device reports readiness to read but returned no data (device disconnected or multiple access on port?)

Thank you very much

[rubenbe]

@Phi2k I finally found some time to implement this. Let me know if it properly catches the issue.
Thanks!

[Phi2k]

Thanks as well! This looks good. Both systems are now running since 4 days - so 8 days of testing in total without the error.

[Phi2k]

Unfortunately not completely fixed. This one seems to be related and occurs more rarely (once per 2 weeks). Is it possible to catch this error as well? Thank you very much.

` File "/usr/lib/python3.11/asyncio/streams.py", line 674, in read
    raise self._exception
  File "/comfospot/comfospot40/parser.py", line 25, in read_byte
    return await self._ser.read(1)
           ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/asyncio/streams.py", line 674, in read
    raise self._exception
  File "/comfospot/comfospot40/parser.py", line 25, in read_byte
    return await self._ser.read(1)
           ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/asyncio/streams.py", line 693, in read
    await self._wait_for_data('read')
  File "/usr/lib/python3.11/asyncio/streams.py", line 525, in _wait_for_data
    await self._waiter
  File "/usr/lib/python3.11/site-packages/serial_asyncio/__init__.py", line 115, in _read_ready
    data = self._serial.read(self._max_read_size)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/serial/serialposix.py", line 509, in read
    raise SerialException('read failed: {}'.format(e))
serial.serialutil.SerialException: read failed: device reports readiness to read but returned no data (device disconnected or multiple access on port?)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.11/logging/__init__.py", line 1110, in emit
    msg = self.format(record)
          ^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/logging/__init__.py", line 953, in format
    return fmt.format(record)
           ^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/logging/__init__.py", line 687, in format
    record.message = record.getMessage()
                     ^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/logging/__init__.py", line 377, in getMessage
    msg = msg % self.args
          ~~~~^~~~~~~~~~~
TypeError: not all arguments converted during string formatting
Call stack:
  File "/comfospot/server.py", line 103, in <module>
    asyncio.run(
  File "/usr/lib/python3.11/asyncio/runners.py", line 190, in run
    return runner.run(main)
  File "/usr/lib/python3.11/asyncio/runners.py", line 118, in run
    return self._loop.run_until_complete(task)
  File "/usr/lib/python3.11/asyncio/base_events.py", line 640, in run_until_complete
    self.run_forever()
  File "/usr/lib/python3.11/asyncio/base_events.py", line 607, in run_forever
    self._run_once()
  File "/usr/lib/python3.11/asyncio/base_events.py", line 1922, in _run_once
    handle._run()
  File "/usr/lib/python3.11/asyncio/events.py", line 80, in _run
    self._context.run(self._callback, *self._args)
  File "/comfospot/comfospot40/parser.py", line 94, in run
    self.parserdata, self.parserstate = await self.parserstate(self.parserdata)
  File "/comfospot/comfospot40/parser.py", line 66, in search_preamble
    readbyte = await self.read_byte()
  File "/comfospot/comfospot40/parser.py", line 27, in read_byte
    logging.warn("Failed to read serial", e)
Message: 'Failed to read serial'
Arguments: (SerialException('read failed: device reports readiness to read but returned no data (device disconnected or multiple access on port?)'),)
--- Logging error ---
Traceback (most recent call last):
  File "/usr/lib/python3.11/site-packages/serial/serialposix.py", line 500, in read
    raise SerialException(
serial.serialutil.SerialException: device reports readiness to read but returned no data (device disconnected or multiple access on port?)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/comfospot/comfospot40/parser.py", line 25, in read_byte
    return await self._ser.read(1)
           ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/asyncio/streams.py", line 674, in read
    raise self._exception
  File "/comfospot/comfospot40/parser.py", line 25, in read_byte
    return await self._ser.read(1)
           ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/asyncio/streams.py", line 674, in read
    raise self._exception
  File "/comfospot/comfospot40/parser.py", line 25, in read_byte
    return await self._ser.read(1)
           ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/asyncio/streams.py", line 674, in read
    raise self._exception
  File "/comfospot/comfospot40/parser.py", line 25, in read_byte
    return await self._ser.read(1)
           ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/asyncio/streams.py", line 674, in read
    raise self._exception
  File "/comfospot/comfospot40/parser.py", line 25, in read_byte
    return await self._ser.read(1)
           **^^^^^^^^^^^^^^^^^^^^^^^`**

[Phi2k]

The error message is longer. The block

  File "/usr/lib/python3.11/asyncio/streams.py", line 674, in read
    raise self._exception
  File "/comfospot/comfospot40/parser.py", line 25, in read_byte
    return await self._ser.read(1)
           ^^^^^^^^^^^^^^^^^^^^^^^

is repeated like 100 times. The whole error message is printed every second.

[rubenbe]

Hi @Phi2k,

I added a patch that should fix this issue. On an error, the software will retry 5 times before giving up entirely.