Why do my websocket requests have high service times in the router logs?

Issue

You have an application using websockets and you noticed that the heroku router is reporting large service times for these requests, like so:

Jul 10 16:30:00 my-app heroku/router: at=info method=GET path="/foo" host=my-app.herokuapp.com request_id=0s8re197-069c-4d81-t404-1eef4a2c6d68 fwd="128.128.128.128" dyno=web.1 connect=0ms service=325252ms status=101 bytes=165 protocol=https 

Resolution

Long service times for Websocket requests are expected. The Heroku routing layer was originally designed to handle standard request/response cycles and support for Websockets was added later.

The way websocket requests are handled is that they start out as a normal request but are then "upgraded" to a websocket connection to allow data to be pushed back and forth. The routing layer then monitors the connection to check that some data is passing through at least every 55 seconds in a rolling window.

If no data transfer takes place then the connection is closed with a H15 or H28 error -https://devcenter.heroku.com/articles/http-routing#timeouts

When you see a log line from a websocket connection with status=101 and a long service time, the service time is actually the time of the entire session, rather than just a single request.

Ask on Stack Overflow

Engage with a community of passionate experts to get the answers you need

Ask on Stack Overflow

Heroku Support

Create a support ticket and our support experts will get back to you

Contact Heroku Support