Server websocket closed-opened transition

Community Support
1

ENVIRONMENT
bokeh==2.3.2
panel==0.11.3

TOPOLOGY
bokeh (panel) server running locally via


panel serve server --allow-websocket-origin=127.0.0.1:8080 --keep-alive=3000

Gunicorn+flask app running as separate process (bound to 127.0.01:8080 in the gunicorn_config.py file, omitted for brevity).


gunicorn --config gunicorn.config.py main:app

ISSUE: First and foremost, everything works functionally. Data can be analyzed and visualized per the design. However, scrutiny of the server log messages shows an unexpected websocket transition at client session startup, which I hope to understand if the implications of, if any.

Here’s an excerpt of the relevant portion; those interleaved _memory_use_cb() lines are from a periodic routine that is in my app code – registered as a on-server-created lifecycle hook and running as a thread.

2021-06-10 16:41:11,624 Receiver created for Protocol()
2021-06-10 16:41:11,624 ProtocolHandler created for Protocol()
2021-06-10 16:41:11,624 ServerConnection created
2021-06-10 16:41:11,626 Sending pull-doc-reply from session 'e0BeBYHOCGafqPalkTYy0SeX5NfKUeh3SKCthhCBOF9i'
2021-06-10 16:41:11,629 WebSocket connection closed: code=1000, reason='closed'
2021-06-10 16:41:12.783 _memory_use_cb()   PROFILE [pid:63081] USS  180.093 MB | RSS  286.867 MB

2021-06-10 16:41:13,274 Subprotocol header received
2021-06-10 16:41:13,274 WebSocket connection opened
2021-06-10 16:41:13,275 Receiver created for Protocol()
2021-06-10 16:41:13,275 ProtocolHandler created for Protocol()
2021-06-10 16:41:13,275 ServerConnection created
2021-06-10 16:41:13,276 Sending pull-doc-reply from session 'e0BeBYHOCGafqPalkTYy0SeX5NfKUeh3SKCthhCBOF9i'
2021-06-10 16:41:17.790 _memory_use_cb()   PROFILE [pid:63081] USS  183.214 MB | RSS  316.449 MB

2021-06-10 16:41:22,783 [pid 63081] 1 clients connected
2021-06-10 16:41:22,783 [pid 63081]   /server has 1 sessions with 0 unused
2021-06-10 16:41:22.799 _memory_use_cb()   PROFILE [pid:63081] USS  183.214 MB | RSS  316.449 MB

The thing that raised interest is the “Websocket connection closed: code=1000” entry towards the top of the excerpt. This is then followed by an expected WebSocket connection and ServerConnection.

Any scenario where this makes sense or any reasonable explanation come to mind?

Again, everything works as expected from the user standpoint. Just wanting to button everything up and make sure there are no zombie objects etc. hanging about.

Thanks

2

The only place in the Bokeh codebase that generates that log message is here:

And the other log messages come from _async_open. So AFAIK you can’t/won’t see those messages unless something has actually opened and closed a websocket connection. But that something would be external, e.g. a browser or another process using bokeh.client directly. Maybe panel is attempting connections as some sort of pre-flight check?[1] I don’t really know.

cc @Philipp_Rudiger

  1. If that is the case it would be better to ressurrect and implement Add a preflight session check to Bokeh server? · Issue #8884 · bokeh/bokeh · GitHub ↩︎

3

Thanks.

A few extra details on the gunicorn+flask side of the system. The route that allows an authenticated user to access things embeds the bokeh/panel content via …

    with pull_session(url=PANEL_SERVER_URL, arguments=arguments) as _session:
        script = server_session(session_id=_session.id, url=PANEL_SERVER_URL)
        return render_template("ui.html", script=script, template="Flask")

Here the arguments dict includes a few UUIDs, which the bokeh UI uses to pull large datasets from a Redis in-memory store; the flask-app includes Dropzone widgets to upload user data that she/he wants to analyze and places them temporarily in Redis at locations associated with those UUIDs.

The gunicorn layer is configured with gthread async workers. However, this is a recent customization, and I have seen the above websocket-closed messages when using the default sync worker class.

Thanks again.

4

pull_session would explain the “extra” connect/disconnect AFAIK. I am not sure about the other configuration without more hands-on experimentation.

1 Like
5

Thanks.

Things seem to be working and the log messages show that the short-lived unused connection appears to cleanup okay. As long as the way I’m interfacing makes sense with the observed behavior, I’m happy.

1 Like