Send server desync log to client

src/crashlog.cpp

@@ -509,7 +509,7 @@ char *CrashLog::FillDesyncCrashLog(char *buffer, const char *last, const DesyncE
  * @param filename_last The last position in the filename buffer.
  * @return true when the crash log was successfully written.
  */
-bool CrashLog::WriteCrashLog(const char *buffer, char *filename, const char *filename_last, const char *name) const
+bool CrashLog::WriteCrashLog(const char *buffer, char *filename, const char *filename_last, const char *name, FILE **crashlog_file) const
 {
 	seprintf(filename, filename_last, "%s%s.log", _personal_dir, name);
 
@@ -519,7 +519,11 @@ bool CrashLog::WriteCrashLog(const char *buffer, char *filename, const char *fil
 	size_t len = strlen(buffer);
 	size_t written = fwrite(buffer, 1, len, file);
 
-	FioFCloseFile(file);
+	if (crashlog_file) {
+		*crashlog_file = file;
+	} else {
+		FioFCloseFile(file);
+	}
 	return len == written;
 }
 
@@ -653,14 +657,14 @@ bool CrashLog::MakeDesyncCrashLog(const std::string *log_in, std::string *log_ou
 	printf("Desync encountered (%s), generating desync log...\n", mode);
 	char *b = this->FillDesyncCrashLog(buffer, lastof(buffer), info);
 
+	if (log_out) log_out->assign(buffer);
+
 	if (log_in && !log_in->empty()) {
 		b = strecpy(b, "\n", lastof(buffer), true);
 		b = strecpy(b, log_in->c_str(), lastof(buffer), true);
 	}
 
-	if (log_out) log_out->assign(buffer);
+	bool bret = this->WriteCrashLog(buffer, filename, lastof(filename), name_buffer, info.log_file);
-
-	bool bret = this->WriteCrashLog(buffer, filename, lastof(filename), name_buffer);
 	if (bret) {
 		printf("Desync log written to %s. Please add this file to any bug reports.\n\n", filename);
 	} else {

src/crashlog.h

@@ -25,6 +25,7 @@ struct DesyncExtraInfo {
 	};
 
 	Flags flags = DEIF_NONE;
+	FILE **log_file = nullptr; ///< save unclosed log file handle here
 };
 DECLARE_ENUM_AS_BIT_SET(DesyncExtraInfo::Flags)
 
@@ -128,7 +129,7 @@ public:
 
 	char *FillCrashLog(char *buffer, const char *last) const;
 	char *FillDesyncCrashLog(char *buffer, const char *last, const DesyncExtraInfo &info) const;
-	bool WriteCrashLog(const char *buffer, char *filename, const char *filename_last, const char *name = "crash") const;
+	bool WriteCrashLog(const char *buffer, char *filename, const char *filename_last, const char *name = "crash", FILE **crashlog_file = nullptr) const;
 
 	/**
 	 * Write the (crash) dump to a file.

src/network/core/tcp_game.cpp

@@ -41,6 +41,8 @@ NetworkGameSocketHandler::NetworkGameSocketHandler(SOCKET s) : info(nullptr), cl
  */
 NetworkRecvStatus NetworkGameSocketHandler::CloseConnection(bool error)
 {
+	if (this->ignore_close) return NETWORK_RECV_STATUS_CONN_LOST;
+
 	/* Clients drop back to the main menu */
 	if (!_network_server && _networking) {
 		extern void ClientNetworkEmergencySave(); // from network_client.cpp
@@ -102,6 +104,7 @@ NetworkRecvStatus NetworkGameSocketHandler::HandlePacket(Packet *p)
 		case PACKET_CLIENT_QUIT:                  return this->Receive_CLIENT_QUIT(p);
 		case PACKET_CLIENT_ERROR:                 return this->Receive_CLIENT_ERROR(p);
 		case PACKET_CLIENT_DESYNC_LOG:            return this->Receive_CLIENT_DESYNC_LOG(p);
+		case PACKET_SERVER_DESYNC_LOG:            return this->Receive_SERVER_DESYNC_LOG(p);
 		case PACKET_SERVER_QUIT:                  return this->Receive_SERVER_QUIT(p);
 		case PACKET_SERVER_ERROR_QUIT:            return this->Receive_SERVER_ERROR_QUIT(p);
 		case PACKET_SERVER_SHUTDOWN:              return this->Receive_SERVER_SHUTDOWN(p);
@@ -191,6 +194,7 @@ NetworkRecvStatus NetworkGameSocketHandler::Receive_CLIENT_SET_NAME(Packet *p) {
 NetworkRecvStatus NetworkGameSocketHandler::Receive_CLIENT_QUIT(Packet *p) { return this->ReceiveInvalidPacket(PACKET_CLIENT_QUIT); }
 NetworkRecvStatus NetworkGameSocketHandler::Receive_CLIENT_ERROR(Packet *p) { return this->ReceiveInvalidPacket(PACKET_CLIENT_ERROR); }
 NetworkRecvStatus NetworkGameSocketHandler::Receive_CLIENT_DESYNC_LOG(Packet *p) { return this->ReceiveInvalidPacket(PACKET_CLIENT_DESYNC_LOG); }
+NetworkRecvStatus NetworkGameSocketHandler::Receive_SERVER_DESYNC_LOG(Packet *p) { return this->ReceiveInvalidPacket(PACKET_SERVER_DESYNC_LOG); }
 NetworkRecvStatus NetworkGameSocketHandler::Receive_SERVER_QUIT(Packet *p) { return this->ReceiveInvalidPacket(PACKET_SERVER_QUIT); }
 NetworkRecvStatus NetworkGameSocketHandler::Receive_SERVER_ERROR_QUIT(Packet *p) { return this->ReceiveInvalidPacket(PACKET_SERVER_ERROR_QUIT); }
 NetworkRecvStatus NetworkGameSocketHandler::Receive_SERVER_SHUTDOWN(Packet *p) { return this->ReceiveInvalidPacket(PACKET_SERVER_SHUTDOWN); }

src/network/core/tcp_game.h

@@ -124,6 +124,7 @@ enum PacketGameType {
 	PACKET_CLIENT_ERROR,                 ///< A client reports an error to the server.
 	PACKET_SERVER_ERROR_QUIT,            ///< A server tells that a client has hit an error and did quit.
 	PACKET_CLIENT_DESYNC_LOG,            ///< A client reports a desync log
+	PACKET_SERVER_DESYNC_LOG,            ///< A server reports a desync log
 
 	PACKET_END,                          ///< Must ALWAYS be on the end of this list!! (period)
 };
@@ -160,6 +161,7 @@ private:
 	NetworkClientInfo *info;  ///< Client info related to this socket
 
 protected:
+	bool ignore_close = false;
 	NetworkRecvStatus ReceiveInvalidPacket(PacketGameType type);
 
 	/**
@@ -445,6 +447,7 @@ protected:
 	 */
 	virtual NetworkRecvStatus Receive_CLIENT_ERROR(Packet *p);
 	virtual NetworkRecvStatus Receive_CLIENT_DESYNC_LOG(Packet *p);
+	virtual NetworkRecvStatus Receive_SERVER_DESYNC_LOG(Packet *p);
 
 	/**
 	 * Notification that a client left the game:

src/network/network_client.cpp

@@ -33,6 +33,7 @@
 #include "../thread.h"
 #include "../crashlog.h"
 #include "../core/checksum_func.hpp"
+#include "../fileio_func.h"
 
 #include "table/strings.h"
 
@@ -162,6 +163,15 @@ ClientNetworkGameSocketHandler::~ClientNetworkGameSocketHandler()
 	_network_settings_access = false;
 
 	delete this->savegame;
+
+	if (this->desync_log_file) {
+		if (!this->server_desync_log.empty()) {
+			fwrite("\n", 1, 1, this->desync_log_file);
+			fwrite(this->server_desync_log.data(), 1, this->server_desync_log.size(), this->desync_log_file);
+		}
+		FioFCloseFile(this->desync_log_file);
+		this->desync_log_file = nullptr;
+	}
 }
 
 NetworkRecvStatus ClientNetworkGameSocketHandler::CloseConnection(NetworkRecvStatus status)
@@ -175,6 +185,7 @@ NetworkRecvStatus ClientNetworkGameSocketHandler::CloseConnection(NetworkRecvSta
 	 * that code any more complex or more aware of the validity of the socket.
 	 */
 	if (this->sock == INVALID_SOCKET) return status;
+	if (this->status == STATUS_CLOSING) return status;
 
 	DEBUG(net, 1, "Shutting down client connection %d", this->client_id);
 
@@ -192,6 +203,12 @@ NetworkRecvStatus ClientNetworkGameSocketHandler::CloseConnection(NetworkRecvSta
 
 	DEBUG(net, 1, "Shutdown client connection %d", this->client_id);
 
+	if (status == NETWORK_RECV_STATUS_DESYNC) {
+		this->status = STATUS_CLOSING;
+		this->ignore_close = true;
+		this->ReceivePackets();
+	}
+
 	delete this->GetInfo();
 	delete this;
 
@@ -302,6 +319,7 @@ void ClientNetworkGameSocketHandler::ClientError(NetworkRecvStatus res)
 				DEBUG(net, 0, "Sync error detected!");
 
 				std::string desync_log;
+				info.log_file = &(my_client->desync_log_file);
 				CrashLog::DesyncCrashLog(nullptr, &desync_log, info);
 				my_client->SendDesyncLog(desync_log);
 				my_client->ClientError(NETWORK_RECV_STATUS_DESYNC);
@@ -968,6 +986,7 @@ NetworkRecvStatus ClientNetworkGameSocketHandler::Receive_SERVER_MAP_DONE(Packet
 
 NetworkRecvStatus ClientNetworkGameSocketHandler::Receive_SERVER_FRAME(Packet *p)
 {
+	if (this->status == STATUS_CLOSING) return NETWORK_RECV_STATUS_OKAY;
 	if (this->status != STATUS_ACTIVE) return NETWORK_RECV_STATUS_MALFORMED_PACKET;
 
 	_frame_counter_server = p->Recv_uint32();
@@ -1002,6 +1021,7 @@ NetworkRecvStatus ClientNetworkGameSocketHandler::Receive_SERVER_FRAME(Packet *p
 
 NetworkRecvStatus ClientNetworkGameSocketHandler::Receive_SERVER_SYNC(Packet *p)
 {
+	if (this->status == STATUS_CLOSING) return NETWORK_RECV_STATUS_OKAY;
 	if (this->status != STATUS_ACTIVE) return NETWORK_RECV_STATUS_MALFORMED_PACKET;
 
 	_sync_frame = p->Recv_uint32();
@@ -1016,6 +1036,7 @@ NetworkRecvStatus ClientNetworkGameSocketHandler::Receive_SERVER_SYNC(Packet *p)
 
 NetworkRecvStatus ClientNetworkGameSocketHandler::Receive_SERVER_COMMAND(Packet *p)
 {
+	if (this->status == STATUS_CLOSING) return NETWORK_RECV_STATUS_OKAY;
 	if (this->status != STATUS_ACTIVE) return NETWORK_RECV_STATUS_MALFORMED_PACKET;
 
 	CommandPacket cp;
@@ -1035,6 +1056,7 @@ NetworkRecvStatus ClientNetworkGameSocketHandler::Receive_SERVER_COMMAND(Packet
 
 NetworkRecvStatus ClientNetworkGameSocketHandler::Receive_SERVER_CHAT(Packet *p)
 {
+	if (this->status == STATUS_CLOSING) return NETWORK_RECV_STATUS_OKAY;
 	if (this->status != STATUS_ACTIVE) return NETWORK_RECV_STATUS_MALFORMED_PACKET;
 
 	char name[NETWORK_NAME_LENGTH], msg[NETWORK_CHAT_LENGTH];
@@ -1092,6 +1114,7 @@ NetworkRecvStatus ClientNetworkGameSocketHandler::Receive_SERVER_ERROR_QUIT(Pack
 	if (this->status < STATUS_AUTHORIZED) return NETWORK_RECV_STATUS_MALFORMED_PACKET;
 
 	ClientID client_id = (ClientID)p->Recv_uint32();
+	if (client_id == _network_own_client_id) return NETWORK_RECV_STATUS_OKAY; // do not try to clear our own client info
 
 	NetworkClientInfo *ci = NetworkClientInfo::GetByClientID(client_id);
 	if (ci != nullptr) {
@@ -1104,6 +1127,15 @@ NetworkRecvStatus ClientNetworkGameSocketHandler::Receive_SERVER_ERROR_QUIT(Pack
 	return NETWORK_RECV_STATUS_OKAY;
 }
 
+NetworkRecvStatus ClientNetworkGameSocketHandler::Receive_SERVER_DESYNC_LOG(Packet *p)
+{
+	uint size = p->Recv_uint16();
+	this->server_desync_log.resize(this->server_desync_log.size() + size);
+	p->Recv_binary(const_cast<char *>(this->server_desync_log.data() + this->server_desync_log.size() - size), size);
+	DEBUG(net, 2, "Received %u bytes of server desync log", size);
+	return NETWORK_RECV_STATUS_OKAY;
+}
+
 NetworkRecvStatus ClientNetworkGameSocketHandler::Receive_SERVER_QUIT(Packet *p)
 {
 	if (this->status < STATUS_AUTHORIZED) return NETWORK_RECV_STATUS_MALFORMED_PACKET;

src/network/network_client.h

@@ -32,11 +32,15 @@ private:
 		STATUS_MAP_WAIT,      ///< The client is waiting as someone else is downloading the map.
 		STATUS_MAP,           ///< The client is downloading the map.
 		STATUS_ACTIVE,        ///< The client is active within in the game.
+		STATUS_CLOSING,       ///< The client connection is in the process of being closed.
 		STATUS_END,           ///< Must ALWAYS be on the end of this list!! (period)
 	};
 
 	ServerStatus status; ///< Status of the connection with the server.
 
+	FILE *desync_log_file = nullptr;
+	std::string server_desync_log;
+
 protected:
 	friend void NetworkExecuteLocalCommandQueue();
 	friend void NetworkClose(bool close_admins);
@@ -63,6 +67,7 @@ protected:
 	NetworkRecvStatus Receive_SERVER_CHAT(Packet *p) override;
 	NetworkRecvStatus Receive_SERVER_QUIT(Packet *p) override;
 	NetworkRecvStatus Receive_SERVER_ERROR_QUIT(Packet *p) override;
+	NetworkRecvStatus Receive_SERVER_DESYNC_LOG(Packet *p) override;
 	NetworkRecvStatus Receive_SERVER_SHUTDOWN(Packet *p) override;
 	NetworkRecvStatus Receive_SERVER_NEWGAME(Packet *p) override;
 	NetworkRecvStatus Receive_SERVER_RCON(Packet *p) override;

src/network/network_server.cpp

@@ -323,7 +323,14 @@ NetworkRecvStatus ServerNetworkGameSocketHandler::CloseConnection(NetworkRecvSta
 	NetworkClientSocket *cs;
 	FOR_ALL_CLIENT_SOCKETS(cs) {
 		if (cs->writable) {
-			if (cs->SendPackets() != SPS_CLOSED && cs->status == STATUS_MAP) {
+			if (cs->status == STATUS_CLOSE_PENDING) {
+				SendPacketsState send_state = cs->SendPackets(true);
+				if (send_state == SPS_CLOSED) {
+					cs->CloseConnection(NETWORK_RECV_STATUS_CONN_LOST);
+				} else if (send_state != SPS_PARTLY_SENT && send_state != SPS_NONE_SENT) {
+					ShutdownSocket(cs->sock, true, false, 2);
+				}
+			} else if (cs->SendPackets() != SPS_CLOSED && cs->status == STATUS_MAP) {
 				/* This client is in the middle of a map-send, call the function for that */
 				cs->SendMap();
 			}
@@ -464,6 +471,20 @@ NetworkRecvStatus ServerNetworkGameSocketHandler::SendError(NetworkErrorCode err
 	return this->CloseConnection(NETWORK_RECV_STATUS_SERVER_ERROR);
 }
 
+NetworkRecvStatus ServerNetworkGameSocketHandler::SendDesyncLog(const std::string &log)
+{
+	for (size_t offset = 0; offset < log.size();) {
+		Packet *p = new Packet(PACKET_SERVER_DESYNC_LOG);
+		size_t size = min<size_t>(log.size() - offset, SHRT_MAX - 2 - p->size);
+		p->Send_uint16(size);
+		p->Send_binary(log.data() + offset, size);
+		this->SendPacket(p);
+
+		offset += size;
+	}
+	return NETWORK_RECV_STATUS_OKAY;
+}
+
 /** Send the check for the NewGRFs. */
 NetworkRecvStatus ServerNetworkGameSocketHandler::SendNewGRFCheck()
 {
@@ -1214,15 +1235,22 @@ NetworkRecvStatus ServerNetworkGameSocketHandler::Receive_CLIENT_ERROR(Packet *p
 	NetworkAdminClientError(this->client_id, errorno);
 
 	if (errorno == NETWORK_ERROR_DESYNC) {
-		CrashLog::DesyncCrashLog(&(this->desync_log), nullptr, DesyncExtraInfo{});
+		std::string server_desync_log;
+		CrashLog::DesyncCrashLog(&(this->desync_log), &server_desync_log, DesyncExtraInfo{});
+		this->SendDesyncLog(server_desync_log);
 
 		// decrease the sync frequency for this point onwards
 		_settings_client.network.sync_freq = min<uint16>(_settings_client.network.sync_freq, 16);
 
 		// have the server and all clients run some sanity checks
 		NetworkSendCommand(0, 0, 0, CMD_DESYNC_CHECK, nullptr, nullptr, _local_company, 0);
-	}
 
+		SendPacketsState send_state = this->SendPackets(true);
+		if (send_state != SPS_CLOSED) {
+			this->status = STATUS_CLOSE_PENDING;
+			return NETWORK_RECV_STATUS_OKAY;
+		}
+	}
 	return this->CloseConnection(NETWORK_RECV_STATUS_CONN_LOST);
 }
 
@@ -1956,6 +1984,7 @@ void NetworkServer_Tick(bool send_frame)
 				break;
 
 			case NetworkClientSocket::STATUS_MAP_WAIT:
+			case NetworkClientSocket::STATUS_CLOSE_PENDING:
 				/* This is an internal state where we do not wait
 				 * on the client to move to a different state. */
 				break;
@@ -1965,7 +1994,7 @@ void NetworkServer_Tick(bool send_frame)
 				NOT_REACHED();
 		}
 
-		if (cs->status >= NetworkClientSocket::STATUS_PRE_ACTIVE) {
+		if (cs->status >= NetworkClientSocket::STATUS_PRE_ACTIVE && cs->status != NetworkClientSocket::STATUS_CLOSE_PENDING) {
 			/* Check if we can send command, and if we have anything in the queue */
 			NetworkHandleCommandQueue(cs);
 
@@ -2027,7 +2056,8 @@ void NetworkServerShowStatusToConsole()
 		"loading map",
 		"map done",
 		"ready",
-		"active"
+		"active",
+		"close pending"
 	};
 	assert_compile(lengthof(stat_str) == NetworkClientSocket::STATUS_END);
 

src/network/network_server.h

@@ -64,6 +64,7 @@ public:
 		STATUS_DONE_MAP,      ///< The client has downloaded the map.
 		STATUS_PRE_ACTIVE,    ///< The client is catching up the delayed frames.
 		STATUS_ACTIVE,        ///< The client is active within in the game.
+		STATUS_CLOSE_PENDING, ///< The client connection is pending closure.
 		STATUS_END,           ///< Must ALWAYS be on the end of this list!! (period).
 	};
 
@@ -100,6 +101,7 @@ public:
 
 	NetworkRecvStatus SendClientInfo(NetworkClientInfo *ci);
 	NetworkRecvStatus SendError(NetworkErrorCode error);
+	NetworkRecvStatus SendDesyncLog(const std::string &log);
 	NetworkRecvStatus SendChat(NetworkAction action, ClientID client_id, bool self_send, const char *msg, NetworkTextMessageData data);
 	NetworkRecvStatus SendJoin(ClientID client_id);
 	NetworkRecvStatus SendFrame();