Heroku H15 Error on web socket close

Question

I have a Go service serving as a web socket server on Heroku. The client pings the server every 20 seconds and it seems to keep the connection open. The problem is that when the socket connection is closed, Heroku router throws H15 error thinking that the request took too much time. For example, if web socket connection has been open for 300 seconds, Heroku log would show:

….H15…. dyno=web.1 connect=1ms service=300000ms status=503 bytes=147….

Anyone has experienced this?

Answer 1

yes! I have experienced that situation and after some deep debugging, I came to the conclusion that this is just a "false positive" in the Heroku Router engine. My debugging went like this:

1. Create a WebSocket connection between the client and the WebSocket server running on Heroku.
2. If you're using socket.io or a similar library it will most likely establish an HTTP polling connection before switching protocols to WebSocket. (You can see these GET/POST requests in the Heroku Router logs).
3. Once the connection is established using the WebSocket protocol, the client will keep it alive by sending a heartbeat (actually the server can do this too). Initially, you won't see this request in the Heroku Router logs because it's still pending (it's open and sending packages of data every few seconds, the heartbeat). You can monitor this by using the Chrome DevTools Network tab.
4. The heartbeat prevents Heroku Router from terminating the request, since every time a few bytes are transferred between the client and the server the Heroku Router timeout timer (55secs) is reset.
5. However, whenever your client closes the connection (ie: closes the browser tab, refreshes the page, disconnects from the internet, etc); the Heroku Router detects the request being terminated and (here comes is my guess based on debugging) because the request was "pending" it reacts as if it was idle for X amount of milliseconds, where X is the time from when the request was received until it was closed, that's when you see logs like this: service=79859ms status=101

As a conclusion: Heroku Router will log an Error 15 line whenever your client app terminates a WebSocket connection which was working perfectly fine for X amount of milliseconds. So, in many cases, it can be just users leaving your app.

I hope this helps people and that you guys can go to sleep with one less thing to worry about :)