Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

recv() is slow #1462

Closed
gborrageiro opened this issue May 11, 2024 · 5 comments
Closed

recv() is slow #1462

gborrageiro opened this issue May 11, 2024 · 5 comments

Comments

@gborrageiro
Copy link

Awaiting websocket.recv() appears to be quite slow. I am scheduling the below consumer() into a task group, nevertheless if we look at the latency statistics:

    async def consumer(self, websocket: WebSocketClientProtocol) -> None:
        s0 = time.time()
        msg = json.loads(await websocket.recv())
        s1 = time.time()
        self._ws_stats.update(s1 - s0)

we see a distribution of waiting times as follows:

ws latency stats: n=5.97e+03, mean=0.3, std=1.83, min=6.44e-06, p25=1.26e-05, p50=1.55e-05, p75=0.00815, p95=0.277, max=35

What would account for the latency here? Presumably if there is no message to receive, control should be returned to the event loop. If there is a message to process, surely the message has been sent already from the websockets server to my client and the waiting times should be better?

@OfferLifted
Copy link

Your timing includes the json.loads() call so your latency measurements include the overhead of those calls. Are you sure you want to measure both or do you just want to measure the await websocket.recv()?
Consider timing the two separately like this:

    async def consumer(self, websocket: WebSocketClientProtocol) -> None:
        s0 = time.monotonic()
        msg = await websocket.recv()
        s1 = time.monotonic()
        self._ws_stats.update(s1 - s0)

        s0 = time.monotonic()
        msg = json.loads(msg)
        s1 = time.monotonic()
        self._json_stats.update(s1 - s0)

You can try switching to orjson instead of json if you need more speed.

@gborrageiro
Copy link
Author

gborrageiro commented May 12, 2024

I have implemented what you have suggested and It's still pretty bad unfortunately.

orjson latency stats: n=1.16e+03, mean=7.43e-06, std=3.12e-06, min=2.37e-06, p25=5.48e-06, p50=7.05e-06, p75=8.84e-06, p95=1.21e-05, max=3.49e-05
    ws latency stats: n=1.16e+03, mean=2.19, std=9.51, min=5.79e-07, p25=9.7e-07, p50=0.00403, p75=0.0278, p95=12.8, max=136

Surprisingly these websockets receive latency stats are worse than Rest messages I send to the same destination geographically speaking, different server of course.

@OfferLifted
Copy link

What do you mean by receive latency? You have to make sure to measure the correct thing if you want your results to be helpful. Maybe look into timing asyncio operations. Without knowing anything else about your test it's hard to point to where the issue might be.

For latency this got added and you can refer this: https://github.com/python-websockets/websockets/issues/1195.

Also look at recv function https://github.com/python-websockets/websockets/blob/12.0/src/websockets/legacy/protocol.py#L502-L578

@gborrageiro
Copy link
Author

recv() latency.
And yes, I have taken a look at it.

@aaugustin
Copy link
Member

aaugustin commented May 14, 2024

Presumably if there is no message to receive, control should be returned to the event loop.

Yes. However, your stopwatch (time.time) is still ticking while the coroutine is at await websocket.recv(), waiting for the event loop to yield back control, so you're effectively measuring time spent waiting for the next message to arrive.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants