tornadoweb / tornadoweb/tornado

on_close called before open on short-lived WebSocket connections

Open
#2,958 3 comments 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

websocket
Dominant language
Python
Stars
22.2k
Forks
5.6k
Avg merge
3h 42m
Merged PRs (30d)
16

Description

TL;DR It's possible under the current implementation for on_close to be called before open for short-lived WebSocket connections. This is due to the on_close callback being loaded before the connection is fully established.


I am working on a project where we have a Python tornado-based WebSocket server that communicates with JavaScript WebSocket clients.

As part of our server class, we have overriden the functions open and on_close of websocket.WebSocketHandler.
In open we initialize some client-specific data and in on_close we clean it up.

Recently we have been dealing with a bug that was caused by on_close being called before open. This seems to happen if the client connection is unstable, and several attempts are made by the client before a WebSocket connection is established.

When this happens, our code raises an error, as it is not able to cleanup a non initialized client.

We believe that the problem lies with how tornado accepts a new connection. It seems that the on_close callback is being loaded before the connection is fully established (and open is called), which means that there's a race condition in the open procedure for short lived connections.

We were able to get the error every time by adding time.sleep(1) in self.accept_connection:

async def accept_connection(self, handler: WebSocketHandler) -> None:
    try:
        self._handle_websocket_headers(handler)
    except ValueError:
        handler.set_status(400)
        log_msg = "Missing/Invalid WebSocket headers"
        handler.finish(log_msg)
        gen_log.debug(log_msg)
        return

    try:
        time.sleep(1)
        await self._accept_connection(handler)
    except asyncio.CancelledError:
        self._abort()
        return
    except ValueError:
        gen_log.debug("Malformed WebSocket request received", exc_info=True)
        self._abort()
        return

Has anyone else had this problem? Perhaps we are wrong to assume that on_close will never be called before open?

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start at websocket.WebSocketHandler and the accept_connection/_accept_connection entry points described in the report. Reproduce the short-lived connection with the added delay, then trace when open and on_close are invoked during connection setup and teardown. Done should include a regression test covering the observed callback ordering and a verified intended lifecycle.

Written by the indexing model from the issue text.

Assessment

Tech stack
python
Domain
networking
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
38/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.