Update on disconnections and server stability
We have been investigating specific disconnection and server stability events over the last few months. I want to give a summary of what we did, what we have found so far, and what is still outstanding. This is a bit of a technical write-up but I hope it’s still accessible to most of you.
Let me start by saying that networking problems are notoriously difficult to debug, and have caused many developers many headaches over the years (myself included).
We’ve looked at this issue many times in the past, and have given up at one point or another due to other issues becoming a higher priority.
However, a couple of months ago we started our investigation again, with the express goal of not stopping until we got to the bottom of it. We started by adding several new metrics on our backend host to get more information on the different reasons why a connection is terminated, as seen from the server. At the same time I increased our idle timeout from 30s to 5 minutes.
This timeout is used to determine how long to wait after sending a ping to a client (this is just a message that means ‘hey are you still there?’) to get a pong (‘I am still here’) response. The reason this timeout exists is that a client may close their connection “ungracefully” (e.g. the game crashes or a PC loses power), and connections are a limited resource for the server, so they can’t be kept around forever.
We believe that this timeout increase did help certain players on slower internet speeds, and particularly those on connections that had poor routing to our server. To explain a bit more, even if you generally have fast internet, it can be that the route your ISP takes to our server is particularly lossy. Because we use websockets (and therefore TCP), a lossy route behaves much like a slow connection. Time of day matters here as well, since your connection may be congested or throttled during periods of high traffic.
This timeout was particularly easy to hit during the loading screen because initial data (e.g. resources, buildings, other players etc.) was sent down with interleaved ping messages. If a ping was preceded by a particularly large update, a client would have to first download the previous message off the wire before it could acknowledge the ping.
The increased timeout was also accompanied by a logic change in the idle timeout extension. Whenever any data (not specifically pong responses) is received by the server, the idle timeout is extended. This meant that even if the client was busy downloading a large message, it could still send its own heartbeat message to indicate that it was still alive.
This seemed to address a subset of the issues that had been reported. However, we also had another problem: mass disconnects, where 50 or more players would all disconnect at the same time without a clear reason why.
The extended timeout and idle timeout logic change didn’t make a difference for these disconnects, and we continued to see them after the previous change was rolled out. As it turned out, the change actually made things worse for the players caught in them. It left the underlying cause completely untouched, but it meant that an affected player now got disconnected twice within a few minutes instead of once. Why that happened took us a while to work out, and it is what the rest of this section is about.
The next time such a mass disconnect event happened we had new data to look at in our dashboards, and we noticed something interesting: the disconnects that were happening in bulk looked like this:
I had looked at the graph for the number of connected clients many times before during disconnection events, and it always looked like a spike down. I had never seen this pattern of a spike up followed by a spike down. On top of that, the disconnection by cause metrics were showing a spike in idle_timeout. It was a bit of a puzzler, and it took me some deep digging in our logs to figure this one out.
What happened with this particular spike is that at around 8:47, roughly 50 clients detected a network error on the client side. We don’t have the client side logs, but from the server logs this must be what happened. The websocket library we use on the client side most likely threw an error because it detected that it was no longer connected to the server. A websocket connection can break in a few different ways, for example the operating system can hand an error straight back to the app because it gave up after retransmitting the same packet too many times and reported the connection as dead. The network interface itself can also change or disappear underneath the game, which happens when Wi-Fi drops for example. The fact that around 50 clients hit this at the same moment implies a shared upstream problem rather than 50 unrelated local problems.
The BitCraft client has an automatic reconnect loop if its connection to the server is lost, and so all the disconnected clients open new connections to the server.
The server accepts these new connections but keeps the old ones around. Importantly, they are kept now for a full 5 minutes after our timeout change. This is why we have this period of time in which we have more connected clients than players. Some of them have two connections open. After the 5 minute idle timeout expires, the server closes the old stale connection. The new one is fine, but when a connection is closed the server notifies the BitCraft module code, which assumes that the client has logged out. We weren’t tracking connections in the BitCraft module, so when the old stale connection is closed, we only check which player it is tied to and not whether that player has a second connection open. The player is then marked as signed out.
Normally this event is never received by the signed out player, after all, they should have no connection open to the server. But in this case they receive an update about being signed out on the second connection. This is an unexpected case on the client, and it surfaces an error to the player telling them they have been signed out and that the server may be under maintenance. The client then also closes the open connection and the player is forced to go back to the login screen. This is the spike down in the graph: it is both the closing of the stale connections and the resulting closing of the valid connections by the clients.
We have now made changes to track connections in the BitCraft module code, and only mark a player as signed out if the connection that is closed is the most recent one that was opened, which means that the second signout should stop happening.
Interestingly, the old 30 second timeout was short enough that the server would close the stale connection well before the client noticed anything was wrong and reconnected, so the two connections never overlapped and this bug in our module code was avoided. Raising the timeout to 5 minutes is what now caused the double disconnect. The underlying event, 50 clients losing their connection at the same moment, was happening before the change as it just showed up as a plain spike down, instead of a spike up followed by a spike down.
The fact that this network error wasn’t visible to our backend server made us suspect that our cloud provider may have some transient networking issue which could cause the dropped connections. We contacted them and they indicated that they were aware of a potential problem that might cause this, and that it would be addressed during a maintenance window in the data center where the game servers are hosted. This gave us a lot of hope, as there was finally a possible explanation and solution to this problem.
Unfortunately this maintenance window (which was on August 5th) has come and gone, and we have still seen disconnection spikes since. This is where we are today: we are still not sure what error these 50 or so clients experience during these disconnection events.
The next update that goes out will add client side reporting of disconnection errors to a server that is hosted in a different data center than the game server. The idea is that if a client gets a network error, it reports that error to this separate server. The errors are queued and sent once a connection is established, for cases where the client is disconnected from the internet entirely. Hopefully this will give us a full picture of what is happening. A few things that might be going on are:
Some other networking problem with our cloud provider which wasn’t addressed by their maintenance
Some node on a specific network route to our server having a transient error
An issue with an ISP
However, we won’t be sure what it is until we have the client side reporting in place and are able to tie a reported disconnection error to a mass disconnect event. Regardless, the solution will be to build a more seamless auto-reconnect on the client so that when a networking error happens the clients can reconnect and at most experience a short lag.
This is something that is being worked on already in parallel to the investigation and will solve this regardless of what the underlying issue is.
We understand that this issue is frustrating for our players, it is for us as well, and it is not being ignored. Additionally, we are looking into other potential causes of client side issues (like memory pressure or memory leaks) that might cause worsening performance or disconnects.
We appreciate your patience.
- Alessandro