[0.14.9] Report of our MMO event.

[Sabbie]

We organised the /r/factorio MMO event today, trying to get the server to crash, and we did it! At it's peak we had 125 people online and 258 unique players joined.

At the start we had some issues with the login server. Thanks a LOT for responding to that on a Sunday evening. We really appreciate it.

I have emailed you guys the log files since I don't feel comfortable sharing all the IP addresses here.

Between 19:00 and 23:00 we got the server to crash 3 times. The whole sever got a "Server not responding" at the following lines:

in first-log.log:

log stuff

Server not responding @
Got a LOT of these lines:
5529.806 Info ServerRouter.cpp:242: Received message type(TransferBlockRequest) blockNumber(2353) from unknown address(SOMEIP:54667), so the peer id can't be deduced.

Server not responding @
5760.033 Info MatchingServerGameUpdater.cpp:142: Failed to sendHeartbeat to the multiplayer matching server: Downloading failed: Timeout was reached -- Operation too slow. Less than 1 bytes/sec transferred the last 20 seconds

Server not responding @
5733.706 Info RouterBase.cpp:54: Unknown packet type received from IP:59851
5733.706 Info RouterBase.cpp:55: Received: 14 01 de a7 00 00 0d 00 14 00 cb 5d 2d b0 01 00 00 00 04 00 00 00 62 61 73 65 00 00 0d 00 14 00 d4 25 08 57 00 00 00 00 0a 00 00 00 61 66 61 64 65 64 66 61 63 65 00 00 00 00 00 00 00 00

I got a lot of these.

Server not responding @
5869.134 code:28, 1c; Timeout was reached -- Operation too slow. Less than 1 bytes/sec transferred the last 20 seconds
5869.134 Info MatchingServerGameUpdater.cpp:99: Failed to sendFullState to the multiplayer matching server: Couldn't parse the response as JSON: Timeout was reached -- Operation too slow. Less than 1 bytes/sec transferred the last 20 seconds

Server not responding @
6536.005 Warning ServerSynchronizer.cpp:276: Peer (275) sent too many (57) input actions for tick (296630) leaving only the first 20
6536.287 Info ServerMultiplayerManager.cpp:798: Disconnect notification for peer (417)
6536.288 Info ServerSynchronizer.cpp:539: nextHeartbeatSequenceNumber(172683) removing peer(417).



Then a crash followed and we started the server again:
------ NEW LOG
in second-log.log

Server not responding @
3444.027 Info ServerRouter.cpp:242: Received message type(ClientToServerHeartbeat) heartbeat(sequenceNumber(1003203511) ) requestsForHeartbeats() from unknown address(SOMEOTHERIP:60903), so the peer id can't be deduced.
3444.061 Info ServerRouter.cpp:242: Received message type(ClientToServerHeartbeat) heartbeat(sequenceNumber(1003203512) ) requestsForHeartbeats() from unknown address(SOMEOTHERIP:60903), so the peer id can't be deduced.


Server not responding @
3485.432 code:28, 1c; Timeout was reached -- Operation too slow. Less than 1 bytes/sec transferred the last 20 seconds
3485.432 Info MatchingServerGameUpdater.cpp:99: Failed to sendFullState to the multiplayer matching server: Couldn't parse the response as JSON: Timeout was reached -- Operation too slow. Less than 1 bytes/sec transferred the last 20 seconds

Then a crash followed and we started the server again:
------ NEW LOG
in third-log.log

Server not responding @
1266.393 Info ServerSynchronizer.cpp:539: nextHeartbeatSequenceNumber(41946) removing peer(30).
1285.353 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (4) that is not disconnected yet.
1285.353 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (4) that is not disconnected yet.
1285.353 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (4) that is not disconnected yet.
1285.353 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (4) that is not disconnected yet.
1285.353 Warning ServerSynchronizer.cpp:38: Received RequestForHeartbeatWhenDisconnectingMessage for peer (4) that is not disconnected yet.

And at 3 minutes past 23 the game crashed again.

I noticed that we get a lot of "Server not responding" when the game is waiting for a heartbeat response to the login servers. Perhaps this can happen async?

Save is downloadable here:
http://factorio.grunnegers.nl/saves/201 ... _event.zip

[Loewchen]

Please upload the complete log.

[found]

For the curious, here is a picture of the factory at the end of the night.

[Loewchen]

What exactly is the bug you are reporting?

[Sabbie]

Please upload the complete log.

I have emailed it to factorio@factorio.com

What exactly is the bug you are reporting?

Three crashes at the end of the logs mostly. Added some other findings since I thought they might be interesting.

[kovarex]

I don't see any crash in the log, and I don't see any log in our email address. Is the crash reproducible from the save?

[Sabbie]

I'm sorry for the confusion. I have now removed the ip addresses from the logs and attached them to this post.

The crash is not reproducible. It happened under load, the save is an auto-save from a few minutes before the last crash.

[kovarex]

• first log Based on this: 7580.362 Received SIGTERM, shutting down, it looks like it was just terminated from console.
• second-log It is the crash after reconnect after desync problem. I might have found the cause, so it is probably fixed for the 0.14.10
• third-log Crash in movement of biter, I don't know what caused it, can't do much if I don't get save where it can crash reproducibly again with the same problem.

[Sabbie]

You are right. I shouldn't have uploaded the first log. Everybody got disconnected and I restarted the server since I thought it would be faster to restart than to wait for everybody to time-out.

Nice to hear that you found one bug. I'll make a point of saving the game on the client after a server crash if it happens again.

[Sabbie]

I'm watching Steejo's stream for the MMO test 2 and I see you guys have some difficulty explaining the "Server not responding" events. I don't mean to nag, but I'm not sure that you noticed my comment in this thread about that problem. (My not uploading the logs might have been a distraction)

Maybe you guys can check your logs and see if you get the same problem. "Server not responding" at missed heartbeats. Perhaps the problem could be with the matchmaking servers that are missing heartbeats? I could imagine that it happens more with a server from the US since the heartbeats are easier to miss? (I'm imagining the matchmaking servers are in the EU?)