python-websockets / websockets

Library for building WebSocket servers and clients in Python
https://websockets.readthedocs.io/
BSD 3-Clause "New" or "Revised" License
5.15k stars 512 forks source link

cannot call recv while another coroutine is already waiting #1002

Closed adriansev closed 3 years ago

adriansev commented 3 years ago

Hi! This is not really a bug report as the issue happened only recently and only in a specific context, so it's more of a pretty please help request for the expert(s) So, i encountered an strange error in the client usage in the context of the server doing something fishy (the server is a tomcat), so not usually but only for this specific dialogue .. so the error was:

ERROR:2021-06-26 09:27:52,073 cannot call recv while another coroutine is already waiting for the next message
Traceback (most recent call last):
File "/home.hdd/adrian/work-GRID/jalien_py/alienpy/alien.py", line 516, in SendMsg
result = __sendmsg(wb, jsonmsg)
File "/home.hdd/adrian/work-GRID/jalien_py/alienpy/alien.py", line 435, in syncfn
return conc_future.result()
File "/usr/lib64/python3.9/concurrent/futures/_base.py", line 445, in result
return self.__get_result()
File "/usr/lib64/python3.9/concurrent/futures/_base.py", line 390, in __get_result
raise self._exception
File "/home.hdd/adrian/work-GRID/jalien_py/alienpy/alien.py", line 477, in __sendmsg
result = await wb.recv()
File "/home/adrian/.local/lib/python3.9/site-packages/websockets/protocol.py", line 448, in recv
raise RuntimeError(
RuntimeError: cannot call recv while another coroutine is already waiting for the next message

where __sendmsg is this https://github.com/adriansev/jalien_py/blob/master/alienpy/alien.py#L472 so, the recv is tied to send, in a blocking function (there will be no parallel usage of __sendmsg) the blocking part is done by decorator syncify https://github.com/adriansev/jalien_py/blob/master/alienpy/alien.py#L430 that use the asyncio loop started here https://github.com/adriansev/jalien_py/blob/master/alienpy/alien.py#L374

what i do not understand is why would be a second recv when i'm already waiting for an answer.. any idea? Thanks a lot!!

aaugustin commented 3 years ago

If you're able to reproduce the bug, then adding logging when you call recv() and when it returns can help figuring out the cause, especially if you dump the stack trace, because you'll see where the first recv() comes from, not just the second one.

logging.info("calling recv", exc_info=True)
result = await wb.recv()
logging.info("recv returned", exc_info=True)
adriansev commented 3 years ago

@aaugustin thanks a lot! indeed, this way a found the reason for multiple recvs... thanks a lot!!!!