Power actions sometimes fail with "readuntil() called while another coroutine is already waiting for incoming data"

Sometimes, power actions fail to execute with a `readuntil() called while another coroutine is already waiting for incoming data` error.

This is a setup using an EH-TW3200 with ser2net on a Raspberry Pi, talking to Home Assistant on a different machine.

Log:
```
2025-06-09 17:05:58.421 ERROR (MainThread) [homeassistant.components.automation.projector_auto_power_off] Projector auto power off: Error executing script. Unexpected error for call_service at pos 1: readuntil() called while another coroutine is already waiting for incoming data
Traceback (most recent call last):
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/homeassistant/helpers/script.py", line 524, in _async_step
    await getattr(self, handler)()
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/homeassistant/helpers/script.py", line 1008, in _async_step_call_service
    response_data = await self._async_run_long_action(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    ...<9 lines>...
    )
    ^
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/homeassistant/helpers/script.py", line 624, in _async_run_long_action
    return await long_task
           ^^^^^^^^^^^^^^^
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/homeassistant/core.py", line 2794, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/homeassistant/core.py", line 2837, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/homeassistant/helpers/service.py", line 1007, in entity_service_call
    single_response = await _handle_entity_call(
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^
        hass, entity, func, data, call.context
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/homeassistant/helpers/service.py", line 1079, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/homeassistant/components/epson/media_player.py", line 170, in async_turn_off
    await self._projector.send_command(TURN_OFF)
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/epson_projector/projector.py", line 88, in send_command
    return await self._projector.send_command(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
        command, get_timeout(command, self._timeout_scale)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/epson_projector/projector_serial.py", line 102, in send_command
    response = await self.send_request(timeout=timeout, command=command + CR)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/epson_projector/projector_serial.py", line 116, in send_request
    response = await self._reader.readuntil(COLON.encode())
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib64/python3.13/asyncio/streams.py", line 677, in readuntil
    await self._wait_for_data('readuntil')
  File "/usr/lib64/python3.13/asyncio/streams.py", line 525, in _wait_for_data
    raise RuntimeError(
        f'{func_name}() called while another coroutine is '
        f'already waiting for incoming data')
RuntimeError: readuntil() called while another coroutine is already waiting for incoming data
2025-06-09 17:05:58.427 ERROR (MainThread) [homeassistant.components.automation.projector_auto_power_off] While executing automation automation.projector_auto_power_off
Traceback (most recent call last):
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/homeassistant/components/automation/__init__.py", line 717, in async_trigger
    return await self.action_script.async_run(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
        variables, trigger_context, started_action
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/homeassistant/helpers/script.py", line 1827, in async_run
    return await asyncio.shield(create_eager_task(run.async_run()))
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/homeassistant/helpers/script.py", line 460, in async_run
    await self._async_step(log_exceptions=False)
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/homeassistant/helpers/script.py", line 526, in _async_step
    self._handle_exception(
    ~~~~~~~~~~~~~~~~~~~~~~^
        ex, continue_on_error, self._log_exceptions or log_exceptions
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/homeassistant/helpers/script.py", line 556, in _handle_exception
    raise exception
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/homeassistant/helpers/script.py", line 524, in _async_step
    await getattr(self, handler)()
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/homeassistant/helpers/script.py", line 1008, in _async_step_call_service
    response_data = await self._async_run_long_action(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    ...<9 lines>...
    )
    ^
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/homeassistant/helpers/script.py", line 624, in _async_run_long_action
    return await long_task
           ^^^^^^^^^^^^^^^
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/homeassistant/core.py", line 2794, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/homeassistant/core.py", line 2837, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/homeassistant/helpers/service.py", line 1007, in entity_service_call
    single_response = await _handle_entity_call(
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^
        hass, entity, func, data, call.context
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/homeassistant/helpers/service.py", line 1079, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/homeassistant/components/epson/media_player.py", line 170, in async_turn_off
    await self._projector.send_command(TURN_OFF)
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/epson_projector/projector.py", line 88, in send_command
    return await self._projector.send_command(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
        command, get_timeout(command, self._timeout_scale)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/epson_projector/projector_serial.py", line 102, in send_command
    response = await self.send_request(timeout=timeout, command=command + CR)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/var/lib/homeassistant/venv/lib64/python3.13/site-packages/epson_projector/projector_serial.py", line 116, in send_request
    response = await self._reader.readuntil(COLON.encode())
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib64/python3.13/asyncio/streams.py", line 677, in readuntil
    await self._wait_for_data('readuntil')
  File "/usr/lib64/python3.13/asyncio/streams.py", line 525, in _wait_for_data
    raise RuntimeError(
        f'{func_name}() called while another coroutine is '
        f'already waiting for incoming data')
RuntimeError: readuntil() called while another coroutine is already waiting for incoming data
```

From looking at a strace of the ser2net process, I think the problem is that the integration issues a `PWR?\r` query immediately before the power off command, so the power off command is racing with a status query (and fails when it tries to read data from the projector while the query is already waiting for data):

```
read(8, "PWR?\r", 1024)                 = 5
writev(9, [{iov_base="PWR?\r", iov_len=5}], 1) = 5
epoll_ctl(3, EPOLL_CTL_MOD, 8, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP|EPOLLONESHOT, {u32=8, u64=8}}) = 0
clock_gettime64(CLOCK_MONOTONIC, {tv_sec=4607, tv_nsec=31069782}) = 0
rt_sigprocmask(SIG_SETMASK, NULL, [], 8) = 0
epoll_pwait(3, [{EPOLLIN, {u32=8, u64=8}}], 1, 517, [], 8) = 1
read(8, "PWR OFF\r", 1024)              = 8
writev(9, [{iov_base="PWR OFF\r", iov_len=8}], 1) = 8
```

I guess there is some missing locking. Since the serial protocol is single-threaded, actions should never be executed concurrently with status queries.

Navigation Menu

Power actions sometimes fail with "readuntil() called while another coroutine is already waiting for incoming data" #27

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Power actions sometimes fail with "readuntil() called while another coroutine is already waiting for incoming data" #27

Description

Activity

Metadata

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Issue actions