Send server desync log to client

desync-debugging
Jonathan G Rennison 5 years ago
parent 14e7b2c157
commit d7895d69af

@ -443,7 +443,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);
@ -453,7 +453,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;
}
@ -590,14 +594,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);
bool bret = this->WriteCrashLog(buffer, filename, lastof(filename), name_buffer, info.log_file);
if (bret) {
printf("Desync log written to %s. Please add this file to any bug reports.\n\n", filename);
} else {

@ -23,6 +23,7 @@ struct DesyncExtraInfo {
};
Flags flags = DEIF_NONE;
FILE **log_file = nullptr; ///< save unclosed log file handle here
};
DECLARE_ENUM_AS_BIT_SET(DesyncExtraInfo::Flags)
@ -108,7 +109,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.

@ -39,6 +39,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
@ -98,6 +100,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);
@ -185,6 +188,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); }

@ -119,6 +119,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)
};
@ -152,6 +153,7 @@ private:
NetworkClientInfo *info; ///< Client info related to this socket
protected:
bool ignore_close = false;
NetworkRecvStatus ReceiveInvalidPacket(PacketGameType type);
/**
@ -422,6 +424,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:

@ -30,6 +30,7 @@
#include "../thread.h"
#include "../crashlog.h"
#include "../core/checksum_func.hpp"
#include "../fileio_func.h"
#include "table/strings.h"
@ -156,6 +157,15 @@ ClientNetworkGameSocketHandler::~ClientNetworkGameSocketHandler()
ClientNetworkGameSocketHandler::my_client = nullptr;
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)
@ -169,6 +179,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);
@ -186,6 +197,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;
@ -296,6 +313,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);
@ -942,6 +960,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();
@ -976,6 +995,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();
@ -990,6 +1010,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;
@ -1009,6 +1030,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];
@ -1065,6 +1087,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) {
@ -1077,6 +1100,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;

@ -30,11 +30,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);
@ -60,6 +64,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;

@ -312,7 +312,14 @@ NetworkRecvStatus ServerNetworkGameSocketHandler::CloseConnection(NetworkRecvSta
{
for (NetworkClientSocket *cs : NetworkClientSocket::Iterate()) {
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();
}
@ -456,6 +463,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, SEND_MTU - 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()
{
@ -1162,15 +1183,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, NULL, NULL, _local_company);
}
NetworkSendCommand(0, 0, 0, CMD_DESYNC_CHECK, nullptr, nullptr, _local_company);
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);
}
@ -1902,6 +1930,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;
@ -1911,7 +1940,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);
@ -1973,7 +2002,8 @@ void NetworkServerShowStatusToConsole()
"loading map",
"map done",
"ready",
"active"
"active",
"close pending"
};
assert_compile(lengthof(stat_str) == NetworkClientSocket::STATUS_END);

@ -61,6 +61,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).
};
@ -93,6 +94,7 @@ public:
NetworkRecvStatus SendClientInfo(NetworkClientInfo *ci);
NetworkRecvStatus SendError(NetworkErrorCode error, const char *reason = nullptr);
NetworkRecvStatus SendDesyncLog(const std::string &log);
NetworkRecvStatus SendChat(NetworkAction action, ClientID client_id, bool self_send, const char *msg, int64 data);
NetworkRecvStatus SendJoin(ClientID client_id);
NetworkRecvStatus SendFrame();

Loading…
Cancel
Save