diff --git a/src/network/network.cpp b/src/network/network.cpp --- a/src/network/network.cpp +++ b/src/network/network.cpp @@ -633,6 +633,8 @@ public: void OnFailure() override { + Debug(net, 9, "Query::OnFailure(): connection_string={}", this->connection_string); + NetworkGameList *item = NetworkGameListAddItem(connection_string); item->status = NGLS_OFFLINE; item->refreshing = false; @@ -642,6 +644,8 @@ public: void OnConnect(SOCKET s) override { + Debug(net, 9, "Query::OnConnect(): connection_string={}", this->connection_string); + QueryNetworkGameSocketHandler::QueryServer(s, this->connection_string); } }; @@ -654,6 +658,8 @@ void NetworkQueryServer(const std::strin { if (!_network_available) return; + Debug(net, 9, "NetworkQueryServer(): connection_string={}", connection_string); + /* Mark the entry as refreshing, so the GUI can show the refresh is pending. */ NetworkGameList *item = NetworkGameListAddItem(connection_string); item->refreshing = true; @@ -730,11 +736,15 @@ public: void OnFailure() override { + Debug(net, 9, "Client::OnFailure(): connection_string={}", this->connection_string); + ShowNetworkError(STR_NETWORK_ERROR_NOCONNECTION); } void OnConnect(SOCKET s) override { + Debug(net, 9, "Client::OnConnect(): connection_string={}", this->connection_string); + _networking = true; new ClientNetworkGameSocketHandler(s, this->connection_string); IConsoleCmdExec("exec scripts/on_client.scr 0"); @@ -761,6 +771,8 @@ public: */ bool NetworkClientConnectGame(const std::string &connection_string, CompanyID default_company, const std::string &join_server_password, const std::string &join_company_password) { + Debug(net, 9, "NetworkClientConnectGame(): connection_string={}", connection_string); + CompanyID join_as = default_company; std::string resolved_connection_string = ServerAddress::Parse(connection_string, NETWORK_DEFAULT_PORT, &join_as).connection_string; @@ -797,6 +809,7 @@ void NetworkClientJoinGame() NetworkInitialize(); _settings_client.network.last_joined = _network_join.connection_string; + Debug(net, 9, "status = CONNECTING"); _network_join_status = NETWORK_JOIN_STATUS_CONNECTING; ShowJoinStatusWindow(); diff --git a/src/network/network_client.cpp b/src/network/network_client.cpp --- a/src/network/network_client.cpp +++ b/src/network/network_client.cpp @@ -338,7 +338,11 @@ static_assert(NETWORK_SERVER_ID_LENGTH = /** Tell the server we would like to join. */ NetworkRecvStatus ClientNetworkGameSocketHandler::SendJoin() { + Debug(net, 9, "Client::SendJoin()"); + + Debug(net, 9, "Client::status = JOIN"); my_client->status = STATUS_JOIN; + Debug(net, 9, "Client::join_status = AUTHORIZING"); _network_join_status = NETWORK_JOIN_STATUS_AUTHORIZING; SetWindowDirty(WC_NETWORK_STATUS_WINDOW, WN_NETWORK_STATUS_WINDOW_JOIN); @@ -355,6 +359,8 @@ NetworkRecvStatus ClientNetworkGameSocke /** Tell the server we got all the NewGRFs. */ NetworkRecvStatus ClientNetworkGameSocketHandler::SendNewGRFsOk() { + Debug(net, 9, "Client::SendNewGRFsOk()"); + Packet *p = new Packet(PACKET_CLIENT_NEWGRFS_CHECKED); my_client->SendPacket(p); return NETWORK_RECV_STATUS_OKAY; @@ -366,6 +372,8 @@ NetworkRecvStatus ClientNetworkGameSocke */ NetworkRecvStatus ClientNetworkGameSocketHandler::SendGamePassword(const std::string &password) { + Debug(net, 9, "Client::SendGamePassword()"); + Packet *p = new Packet(PACKET_CLIENT_GAME_PASSWORD); p->Send_string(password); my_client->SendPacket(p); @@ -378,6 +386,8 @@ NetworkRecvStatus ClientNetworkGameSocke */ NetworkRecvStatus ClientNetworkGameSocketHandler::SendCompanyPassword(const std::string &password) { + Debug(net, 9, "Client::SendCompanyPassword()"); + Packet *p = new Packet(PACKET_CLIENT_COMPANY_PASSWORD); p->Send_string(GenerateCompanyPasswordHash(password, _password_server_id, _password_game_seed)); my_client->SendPacket(p); @@ -387,6 +397,9 @@ NetworkRecvStatus ClientNetworkGameSocke /** Request the map from the server. */ NetworkRecvStatus ClientNetworkGameSocketHandler::SendGetMap() { + Debug(net, 9, "Client::SendGetMap()"); + + Debug(net, 9, "Client::status = MAP_WAIT"); my_client->status = STATUS_MAP_WAIT; Packet *p = new Packet(PACKET_CLIENT_GETMAP); @@ -397,6 +410,9 @@ NetworkRecvStatus ClientNetworkGameSocke /** Tell the server we received the complete map. */ NetworkRecvStatus ClientNetworkGameSocketHandler::SendMapOk() { + Debug(net, 9, "Client::SendMapOk()"); + + Debug(net, 9, "Client::status = ACTIVE"); my_client->status = STATUS_ACTIVE; Packet *p = new Packet(PACKET_CLIENT_MAP_OK); @@ -407,6 +423,8 @@ NetworkRecvStatus ClientNetworkGameSocke /** Send an acknowledgement from the server's ticks. */ NetworkRecvStatus ClientNetworkGameSocketHandler::SendAck() { + Debug(net, 9, "Client::SendAck()"); + Packet *p = new Packet(PACKET_CLIENT_ACK); p->Send_uint32(_frame_counter); @@ -421,6 +439,8 @@ NetworkRecvStatus ClientNetworkGameSocke */ NetworkRecvStatus ClientNetworkGameSocketHandler::SendCommand(const CommandPacket *cp) { + Debug(net, 9, "Client::SendCommand(): cmd={}", cp->cmd); + Packet *p = new Packet(PACKET_CLIENT_COMMAND); my_client->NetworkGameSocketHandler::SendCommand(p, cp); @@ -431,6 +451,8 @@ NetworkRecvStatus ClientNetworkGameSocke /** Send a chat-packet over the network */ NetworkRecvStatus ClientNetworkGameSocketHandler::SendChat(NetworkAction action, DestType type, int dest, const std::string &msg, int64_t data) { + Debug(net, 9, "Client::SendChat(): action={}, type={}, dest={}", action, type, dest); + Packet *p = new Packet(PACKET_CLIENT_CHAT); p->Send_uint8 (action); @@ -446,6 +468,8 @@ NetworkRecvStatus ClientNetworkGameSocke /** Send an error-packet over the network */ NetworkRecvStatus ClientNetworkGameSocketHandler::SendError(NetworkErrorCode errorno) { + Debug(net, 9, "Client::SendError(): errorno={}", errorno); + Packet *p = new Packet(PACKET_CLIENT_ERROR); p->Send_uint8(errorno); @@ -459,6 +483,8 @@ NetworkRecvStatus ClientNetworkGameSocke */ NetworkRecvStatus ClientNetworkGameSocketHandler::SendSetPassword(const std::string &password) { + Debug(net, 9, "Client::SendSetPassword()"); + Packet *p = new Packet(PACKET_CLIENT_SET_PASSWORD); p->Send_string(GenerateCompanyPasswordHash(password, _password_server_id, _password_game_seed)); @@ -472,6 +498,8 @@ NetworkRecvStatus ClientNetworkGameSocke */ NetworkRecvStatus ClientNetworkGameSocketHandler::SendSetName(const std::string &name) { + Debug(net, 9, "Client::SendSetName()"); + Packet *p = new Packet(PACKET_CLIENT_SET_NAME); p->Send_string(name); @@ -484,6 +512,8 @@ NetworkRecvStatus ClientNetworkGameSocke */ NetworkRecvStatus ClientNetworkGameSocketHandler::SendQuit() { + Debug(net, 9, "Client::SendSetName()"); + Packet *p = new Packet(PACKET_CLIENT_QUIT); my_client->SendPacket(p); @@ -497,6 +527,8 @@ NetworkRecvStatus ClientNetworkGameSocke */ NetworkRecvStatus ClientNetworkGameSocketHandler::SendRCon(const std::string &pass, const std::string &command) { + Debug(net, 9, "Client::SendRCon()"); + Packet *p = new Packet(PACKET_CLIENT_RCON); p->Send_string(pass); p->Send_string(command); @@ -511,6 +543,8 @@ NetworkRecvStatus ClientNetworkGameSocke */ NetworkRecvStatus ClientNetworkGameSocketHandler::SendMove(CompanyID company, const std::string &password) { + Debug(net, 9, "Client::SendMove(): company={}", company); + Packet *p = new Packet(PACKET_CLIENT_MOVE); p->Send_uint8(company); p->Send_string(GenerateCompanyPasswordHash(password, _password_server_id, _password_game_seed)); @@ -537,6 +571,8 @@ extern bool SafeLoad(const std::string & NetworkRecvStatus ClientNetworkGameSocketHandler::Receive_SERVER_FULL(Packet *) { + Debug(net, 9, "Client::Receive_SERVER_FULL()"); + /* We try to join a server which is full */ ShowErrorMessage(STR_NETWORK_ERROR_SERVER_FULL, INVALID_STRING_ID, WL_CRITICAL); @@ -545,6 +581,8 @@ NetworkRecvStatus ClientNetworkGameSocke NetworkRecvStatus ClientNetworkGameSocketHandler::Receive_SERVER_BANNED(Packet *) { + Debug(net, 9, "Client::Receive_SERVER_BANNED()"); + /* We try to join a server where we are banned */ ShowErrorMessage(STR_NETWORK_ERROR_SERVER_BANNED, INVALID_STRING_ID, WL_CRITICAL); @@ -560,6 +598,8 @@ NetworkRecvStatus ClientNetworkGameSocke ClientID client_id = (ClientID)p->Recv_uint32(); CompanyID playas = (CompanyID)p->Recv_uint8(); + Debug(net, 9, "Client::Receive_SERVER_CLIENT_INFO(): client_id={}, playas={}", client_id, playas); + std::string name = p->Recv_string(NETWORK_NAME_LENGTH); if (this->status < STATUS_AUTHORIZED) return NETWORK_RECV_STATUS_MALFORMED_PACKET; @@ -639,6 +679,8 @@ NetworkRecvStatus ClientNetworkGameSocke NetworkErrorCode error = (NetworkErrorCode)p->Recv_uint8(); + Debug(net, 9, "Client::Receive_SERVER_ERROR(): error={}", error); + StringID err = STR_NETWORK_ERROR_LOSTCONNECTION; if (error < (ptrdiff_t)lengthof(network_error_strings)) err = network_error_strings[error]; /* In case of kicking a client, we assume there is a kick message in the packet if we can read one byte */ @@ -662,6 +704,8 @@ NetworkRecvStatus ClientNetworkGameSocke uint grf_count = p->Recv_uint8(); NetworkRecvStatus ret = NETWORK_RECV_STATUS_OKAY; + Debug(net, 9, "Client::Receive_SERVER_CHECK_NEWGRFS(): grf_count={}", grf_count); + /* Check all GRFs */ for (; grf_count > 0; grf_count--) { GRFIdentifier c; @@ -689,8 +733,11 @@ NetworkRecvStatus ClientNetworkGameSocke NetworkRecvStatus ClientNetworkGameSocketHandler::Receive_SERVER_NEED_GAME_PASSWORD(Packet *) { if (this->status < STATUS_JOIN || this->status >= STATUS_AUTH_GAME) return NETWORK_RECV_STATUS_MALFORMED_PACKET; + Debug(net, 9, "Client::status = AUTH_GAME"); this->status = STATUS_AUTH_GAME; + Debug(net, 9, "Client::Receive_SERVER_NEED_GAME_PASSWORD()"); + if (!_network_join.server_password.empty()) { return SendGamePassword(_network_join.server_password); } @@ -703,8 +750,11 @@ NetworkRecvStatus ClientNetworkGameSocke NetworkRecvStatus ClientNetworkGameSocketHandler::Receive_SERVER_NEED_COMPANY_PASSWORD(Packet *p) { if (this->status < STATUS_JOIN || this->status >= STATUS_AUTH_COMPANY) return NETWORK_RECV_STATUS_MALFORMED_PACKET; + Debug(net, 9, "Client::status = AUTH_COMPANY"); this->status = STATUS_AUTH_COMPANY; + Debug(net, 9, "Client::Receive_SERVER_NEED_COMPANY_PASSWORD()"); + _password_game_seed = p->Recv_uint32(); _password_server_id = p->Recv_string(NETWORK_SERVER_ID_LENGTH); if (this->HasClientQuit()) return NETWORK_RECV_STATUS_MALFORMED_PACKET; @@ -721,10 +771,13 @@ NetworkRecvStatus ClientNetworkGameSocke NetworkRecvStatus ClientNetworkGameSocketHandler::Receive_SERVER_WELCOME(Packet *p) { if (this->status < STATUS_JOIN || this->status >= STATUS_AUTHORIZED) return NETWORK_RECV_STATUS_MALFORMED_PACKET; + Debug(net, 9, "Client::status = AUTHORIZED"); this->status = STATUS_AUTHORIZED; _network_own_client_id = (ClientID)p->Recv_uint32(); + Debug(net, 9, "Client::Receive_SERVER_WELCOME(): client_id={}", _network_own_client_id); + /* Initialize the password hash salting variables, even if they were previously. */ _password_game_seed = p->Recv_uint32(); _password_server_id = p->Recv_string(NETWORK_SERVER_ID_LENGTH); @@ -738,7 +791,10 @@ NetworkRecvStatus ClientNetworkGameSocke /* We set the internal wait state when requesting the map. */ if (this->status != STATUS_MAP_WAIT) return NETWORK_RECV_STATUS_MALFORMED_PACKET; + Debug(net, 9, "Client::Receive_SERVER_WAIT()"); + /* But... only now we set the join status to waiting, instead of requesting. */ + Debug(net, 9, "Client::join_status = WAITING"); _network_join_status = NETWORK_JOIN_STATUS_WAITING; _network_join_waiting = p->Recv_uint8(); SetWindowDirty(WC_NETWORK_STATUS_WINDOW, WN_NETWORK_STATUS_WINDOW_JOIN); @@ -749,6 +805,7 @@ NetworkRecvStatus ClientNetworkGameSocke NetworkRecvStatus ClientNetworkGameSocketHandler::Receive_SERVER_MAP_BEGIN(Packet *p) { if (this->status < STATUS_AUTHORIZED || this->status >= STATUS_MAP) return NETWORK_RECV_STATUS_MALFORMED_PACKET; + Debug(net, 9, "Client::status = MAP"); this->status = STATUS_MAP; if (this->savegame != nullptr) return NETWORK_RECV_STATUS_MALFORMED_PACKET; @@ -757,9 +814,12 @@ NetworkRecvStatus ClientNetworkGameSocke _frame_counter = _frame_counter_server = _frame_counter_max = p->Recv_uint32(); + Debug(net, 9, "Client::Receive_SERVER_MAP_BEGIN(): frame_counter={}", _frame_counter); + _network_join_bytes = 0; _network_join_bytes_total = 0; + Debug(net, 9, "Client::join_status = DOWNLOADING"); _network_join_status = NETWORK_JOIN_STATUS_DOWNLOADING; SetWindowDirty(WC_NETWORK_STATUS_WINDOW, WN_NETWORK_STATUS_WINDOW_JOIN); @@ -774,6 +834,8 @@ NetworkRecvStatus ClientNetworkGameSocke _network_join_bytes_total = p->Recv_uint32(); SetWindowDirty(WC_NETWORK_STATUS_WINDOW, WN_NETWORK_STATUS_WINDOW_JOIN); + Debug(net, 9, "Client::Receive_SERVER_MAP_SIZE(): bytes_total={}", _network_join_bytes_total); + return NETWORK_RECV_STATUS_OKAY; } @@ -796,6 +858,9 @@ NetworkRecvStatus ClientNetworkGameSocke if (this->status != STATUS_MAP) return NETWORK_RECV_STATUS_MALFORMED_PACKET; if (this->savegame == nullptr) return NETWORK_RECV_STATUS_MALFORMED_PACKET; + Debug(net, 9, "Client::Receive_SERVER_MAP_DONE()"); + + Debug(net, 9, "Client::join_status = PROCESSING"); _network_join_status = NETWORK_JOIN_STATUS_PROCESSING; SetWindowDirty(WC_NETWORK_STATUS_WINDOW, WN_NETWORK_STATUS_WINDOW_JOIN); @@ -837,6 +902,7 @@ NetworkRecvStatus ClientNetworkGameSocke if (_network_join.company != COMPANY_SPECTATOR) { /* We have arrived and ready to start playing; send a command to make a new company; * the server will give us a client-id and let us in */ + Debug(net, 9, "Client::join_status = REGISTERING"); _network_join_status = NETWORK_JOIN_STATUS_REGISTERING; ShowJoinStatusWindow(); Command::SendNet(STR_NULL, _local_company, CCA_NEW, INVALID_COMPANY, CRR_NONE, INVALID_CLIENT_ID); @@ -875,8 +941,6 @@ NetworkRecvStatus ClientNetworkGameSocke /* Receive the token. */ if (p->CanReadFromPacket(sizeof(uint8_t))) this->token = p->Recv_uint8(); - Debug(net, 7, "Received FRAME {}", _frame_counter_server); - /* Let the server know that we received this frame correctly * We do this only once per day, to save some bandwidth ;) */ if (!_network_first_time && last_ack_frame < _frame_counter) { @@ -898,6 +962,8 @@ NetworkRecvStatus ClientNetworkGameSocke _sync_seed_2 = p->Recv_uint32(); #endif + Debug(net, 9, "Client::Receive_SERVER_SYNC(): sync_frame={}, sync_seed_1={}", _sync_frame, _sync_seed_1); + return NETWORK_RECV_STATUS_OKAY; } @@ -910,6 +976,8 @@ NetworkRecvStatus ClientNetworkGameSocke cp.frame = p->Recv_uint32(); cp.my_cmd = p->Recv_bool(); + Debug(net, 9, "Client::Receive_SERVER_COMMAND(): cmd={}, frame={}", cp.cmd, cp.frame); + if (err != nullptr) { IConsolePrint(CC_WARNING, "Dropping server connection due to {}.", err); return NETWORK_RECV_STATUS_MALFORMED_PACKET; @@ -933,6 +1001,8 @@ NetworkRecvStatus ClientNetworkGameSocke std::string msg = p->Recv_string(NETWORK_CHAT_LENGTH); int64_t data = p->Recv_uint64(); + Debug(net, 9, "Client::Receive_SERVER_CHAT(): action={}, client_id={}, self_send={}", action, client_id, self_send); + ci_to = NetworkClientInfo::GetByClientID(client_id); if (ci_to == nullptr) return NETWORK_RECV_STATUS_OKAY; @@ -978,6 +1048,8 @@ NetworkRecvStatus ClientNetworkGameSocke std::string user = p->Recv_string(NETWORK_CHAT_LENGTH); std::string msg = p->Recv_string(NETWORK_CHAT_LENGTH); + Debug(net, 9, "Client::Receive_SERVER_EXTERNAL_CHAT(): source={}", source); + if (!IsValidConsoleColour(colour)) return NETWORK_RECV_STATUS_MALFORMED_PACKET; NetworkTextMessage(NETWORK_ACTION_EXTERNAL_CHAT, colour, false, user, msg, 0, source); @@ -991,6 +1063,8 @@ NetworkRecvStatus ClientNetworkGameSocke ClientID client_id = (ClientID)p->Recv_uint32(); + Debug(net, 9, "Client::Receive_SERVER_ERROR_QUIT(): client_id={}", client_id); + NetworkClientInfo *ci = NetworkClientInfo::GetByClientID(client_id); if (ci != nullptr) { NetworkTextMessage(NETWORK_ACTION_LEAVE, CC_DEFAULT, false, ci->client_name, "", GetNetworkErrorMsg((NetworkErrorCode)p->Recv_uint8())); @@ -1008,6 +1082,8 @@ NetworkRecvStatus ClientNetworkGameSocke ClientID client_id = (ClientID)p->Recv_uint32(); + Debug(net, 9, "Client::Receive_SERVER_QUIT(): client_id={}", client_id); + NetworkClientInfo *ci = NetworkClientInfo::GetByClientID(client_id); if (ci != nullptr) { NetworkTextMessage(NETWORK_ACTION_LEAVE, CC_DEFAULT, false, ci->client_name, "", STR_NETWORK_MESSAGE_CLIENT_LEAVING); @@ -1028,6 +1104,8 @@ NetworkRecvStatus ClientNetworkGameSocke ClientID client_id = (ClientID)p->Recv_uint32(); + Debug(net, 9, "Client::Receive_SERVER_JOIN(): client_id={}", client_id); + NetworkClientInfo *ci = NetworkClientInfo::GetByClientID(client_id); if (ci != nullptr) { NetworkTextMessage(NETWORK_ACTION_JOIN, CC_DEFAULT, false, ci->client_name); @@ -1040,6 +1118,8 @@ NetworkRecvStatus ClientNetworkGameSocke NetworkRecvStatus ClientNetworkGameSocketHandler::Receive_SERVER_SHUTDOWN(Packet *) { + Debug(net, 9, "Client::Receive_SERVER_SHUTDOWN()"); + /* Only when we're trying to join we really * care about the server shutting down. */ if (this->status >= STATUS_JOIN) { @@ -1053,6 +1133,8 @@ NetworkRecvStatus ClientNetworkGameSocke NetworkRecvStatus ClientNetworkGameSocketHandler::Receive_SERVER_NEWGAME(Packet *) { + Debug(net, 9, "Client::Receive_SERVER_NEWGAME()"); + /* Only when we're trying to join we really * care about the server shutting down. */ if (this->status >= STATUS_JOIN) { @@ -1072,6 +1154,8 @@ NetworkRecvStatus ClientNetworkGameSocke { if (this->status < STATUS_AUTHORIZED) return NETWORK_RECV_STATUS_MALFORMED_PACKET; + Debug(net, 9, "Client::Receive_SERVER_RCON()"); + TextColour colour_code = (TextColour)p->Recv_uint16(); if (!IsValidConsoleColour(colour_code)) return NETWORK_RECV_STATUS_MALFORMED_PACKET; @@ -1090,6 +1174,8 @@ NetworkRecvStatus ClientNetworkGameSocke ClientID client_id = (ClientID)p->Recv_uint32(); CompanyID company_id = (CompanyID)p->Recv_uint8(); + Debug(net, 9, "Client::Receive_SERVER_MOVE(): client_id={}, comapny_id={}", client_id, company_id); + if (client_id == 0) { /* definitely an invalid client id, debug message and do nothing. */ Debug(net, 1, "Received invalid client index = 0"); @@ -1118,6 +1204,8 @@ NetworkRecvStatus ClientNetworkGameSocke _network_server_name = p->Recv_string(NETWORK_NAME_LENGTH); SetWindowClassesDirty(WC_CLIENT_LIST); + Debug(net, 9, "Client::Receive_SERVER_CONFIG_UPDATE(): max_companies={}", _network_server_max_companies); + return NETWORK_RECV_STATUS_OKAY; } @@ -1129,6 +1217,8 @@ NetworkRecvStatus ClientNetworkGameSocke _network_company_passworded = p->Recv_uint16(); SetWindowClassesDirty(WC_COMPANY); + Debug(net, 9, "Client::Receive_SERVER_COMPANY_UPDATE()"); + return NETWORK_RECV_STATUS_OKAY; } @@ -1168,6 +1258,9 @@ void NetworkClient_Connected() _frame_counter = 0; _frame_counter_server = 0; last_ack_frame = 0; + + Debug(net, 9, "Client::NetworkClient_Connected()"); + /* Request the game-info */ MyClient::SendJoin(); } diff --git a/src/network/network_query.cpp b/src/network/network_query.cpp --- a/src/network/network_query.cpp +++ b/src/network/network_query.cpp @@ -81,12 +81,16 @@ void QueryNetworkGameSocketHandler::Send */ NetworkRecvStatus QueryNetworkGameSocketHandler::SendGameInfo() { + Debug(net, 9, "Query::SendGameInfo()"); + this->SendPacket(new Packet(PACKET_CLIENT_GAME_INFO)); return NETWORK_RECV_STATUS_OKAY; } NetworkRecvStatus QueryNetworkGameSocketHandler::Receive_SERVER_FULL(Packet *) { + Debug(net, 9, "Query::Receive_SERVER_FULL()"); + NetworkGameList *item = NetworkGameListAddItem(this->connection_string); item->status = NGLS_FULL; item->refreshing = false; @@ -98,6 +102,8 @@ NetworkRecvStatus QueryNetworkGameSocket NetworkRecvStatus QueryNetworkGameSocketHandler::Receive_SERVER_BANNED(Packet *) { + Debug(net, 9, "Query::Receive_SERVER_BANNED()"); + NetworkGameList *item = NetworkGameListAddItem(this->connection_string); item->status = NGLS_BANNED; item->refreshing = false; @@ -109,6 +115,8 @@ NetworkRecvStatus QueryNetworkGameSocket NetworkRecvStatus QueryNetworkGameSocketHandler::Receive_SERVER_GAME_INFO(Packet *p) { + Debug(net, 9, "Query::Receive_SERVER_GAME_INFO()"); + NetworkGameList *item = NetworkGameListAddItem(this->connection_string); /* Clear any existing GRFConfig chain. */ @@ -130,6 +138,8 @@ NetworkRecvStatus QueryNetworkGameSocket { NetworkErrorCode error = (NetworkErrorCode)p->Recv_uint8(); + Debug(net, 9, "Query::Receive_SERVER_ERROR(): error={}", error); + NetworkGameList *item = NetworkGameListAddItem(this->connection_string); if (error == NETWORK_ERROR_NOT_EXPECTED) { diff --git a/src/network/network_server.cpp b/src/network/network_server.cpp --- a/src/network/network_server.cpp +++ b/src/network/network_server.cpp @@ -215,6 +215,8 @@ ServerNetworkGameSocketHandler::ServerNe this->client_id = _network_client_id++; this->receive_limit = _settings_client.network.bytes_per_frame_burst; + Debug(net, 9, "client[{}] status = INACTIVE", this->client_id); + /* The Socket and Info pools need to be the same in size. After all, * each Socket will be associated with at most one Info object. As * such if the Socket was allocated the Info object can as well. */ @@ -345,6 +347,8 @@ static void NetworkHandleCommandQueue(Ne */ NetworkRecvStatus ServerNetworkGameSocketHandler::SendClientInfo(NetworkClientInfo *ci) { + Debug(net, 9, "client[{}] SendClientInfo(): client_id={}", this->client_id, ci->client_id); + if (ci->client_id != INVALID_CLIENT_ID) { Packet *p = new Packet(PACKET_SERVER_CLIENT_INFO); p->Send_uint32(ci->client_id); @@ -359,6 +363,8 @@ NetworkRecvStatus ServerNetworkGameSocke /** Send the client information about the server. */ NetworkRecvStatus ServerNetworkGameSocketHandler::SendGameInfo() { + Debug(net, 9, "client[{}] SendGameInfo()", this->client_id); + Packet *p = new Packet(PACKET_SERVER_GAME_INFO, TCP_MTU); SerializeNetworkGameInfo(p, GetCurrentNetworkServerGameInfo()); @@ -374,6 +380,8 @@ NetworkRecvStatus ServerNetworkGameSocke */ NetworkRecvStatus ServerNetworkGameSocketHandler::SendError(NetworkErrorCode error, const std::string &reason) { + Debug(net, 9, "client[{}] SendError(): error={}", this->client_id, error); + Packet *p = new Packet(PACKET_SERVER_ERROR); p->Send_uint8(error); @@ -417,6 +425,8 @@ NetworkRecvStatus ServerNetworkGameSocke /** Send the check for the NewGRFs. */ NetworkRecvStatus ServerNetworkGameSocketHandler::SendNewGRFCheck() { + Debug(net, 9, "client[{}] SendNewGRFCheck()", this->client_id); + Packet *p = new Packet(PACKET_SERVER_CHECK_NEWGRFS, TCP_MTU); const GRFConfig *c; uint grf_count = 0; @@ -437,9 +447,12 @@ NetworkRecvStatus ServerNetworkGameSocke /** Request the game password. */ NetworkRecvStatus ServerNetworkGameSocketHandler::SendNeedGamePassword() { + Debug(net, 9, "client[{}] SendNeedGamePassword()", this->client_id); + /* Invalid packet when status is STATUS_AUTH_GAME or higher */ if (this->status >= STATUS_AUTH_GAME) return this->CloseConnection(NETWORK_RECV_STATUS_MALFORMED_PACKET); + Debug(net, 9, "client[{}] status = AUTH_GAME", this->client_id); this->status = STATUS_AUTH_GAME; /* Reset 'lag' counters */ this->last_frame = this->last_frame_server = _frame_counter; @@ -452,9 +465,12 @@ NetworkRecvStatus ServerNetworkGameSocke /** Request the company password. */ NetworkRecvStatus ServerNetworkGameSocketHandler::SendNeedCompanyPassword() { + Debug(net, 9, "client[{}] SendNeedCompanyPassword()", this->client_id); + /* Invalid packet when status is STATUS_AUTH_COMPANY or higher */ if (this->status >= STATUS_AUTH_COMPANY) return this->CloseConnection(NETWORK_RECV_STATUS_MALFORMED_PACKET); + Debug(net, 9, "client[{}] status = AUTH_COMPANY", this->client_id); this->status = STATUS_AUTH_COMPANY; /* Reset 'lag' counters */ this->last_frame = this->last_frame_server = _frame_counter; @@ -469,11 +485,14 @@ NetworkRecvStatus ServerNetworkGameSocke /** Send the client a welcome message with some basic information. */ NetworkRecvStatus ServerNetworkGameSocketHandler::SendWelcome() { + Debug(net, 9, "client[{}] SendWelcome()", this->client_id); + Packet *p; /* Invalid packet when status is AUTH or higher */ if (this->status >= STATUS_AUTHORIZED) return this->CloseConnection(NETWORK_RECV_STATUS_MALFORMED_PACKET); + Debug(net, 9, "client[{}] status = AUTHORIZED", this->client_id); this->status = STATUS_AUTHORIZED; /* Reset 'lag' counters */ this->last_frame = this->last_frame_server = _frame_counter; @@ -499,6 +518,8 @@ NetworkRecvStatus ServerNetworkGameSocke /** Tell the client that its put in a waiting queue. */ NetworkRecvStatus ServerNetworkGameSocketHandler::SendWait() { + Debug(net, 9, "client[{}] SendWait()", this->client_id); + int waiting = 1; // current player getting the map counts as 1 Packet *p; @@ -516,6 +537,8 @@ NetworkRecvStatus ServerNetworkGameSocke void ServerNetworkGameSocketHandler::CheckNextClientToSendMap(NetworkClientSocket *ignore_cs) { + Debug(net, 9, "client[{}] CheckNextClientToSendMap()", this->client_id); + /* Find the best candidate for joining, i.e. the first joiner. */ NetworkClientSocket *best = nullptr; for (NetworkClientSocket *new_cs : NetworkClientSocket::Iterate()) { @@ -550,6 +573,8 @@ NetworkRecvStatus ServerNetworkGameSocke } if (this->status == STATUS_AUTHORIZED) { + Debug(net, 9, "client[{}] SendMap(): first_packet", this->client_id); + WaitTillSaved(); this->savegame = new PacketWriter(this); @@ -559,6 +584,7 @@ NetworkRecvStatus ServerNetworkGameSocke this->SendPacket(p); NetworkSyncCommandQueue(this); + Debug(net, 9, "client[{}] status = MAP", this->client_id); this->status = STATUS_MAP; /* Mark the start of download */ this->last_frame = _frame_counter; @@ -571,12 +597,15 @@ NetworkRecvStatus ServerNetworkGameSocke if (this->status == STATUS_MAP) { bool last_packet = this->savegame->TransferToNetworkQueue(this); if (last_packet) { + Debug(net, 9, "client[{}] SendMap(): last_packet", this->client_id); + /* Done reading, make sure saving is done as well */ this->savegame->Destroy(); this->savegame = nullptr; /* Set the status to DONE_MAP, no we will wait for the client * to send it is ready (maybe that happens like never ;)) */ + Debug(net, 9, "client[{}] status = DONE_MAP", this->client_id); this->status = STATUS_DONE_MAP; this->CheckNextClientToSendMap(); @@ -591,6 +620,8 @@ NetworkRecvStatus ServerNetworkGameSocke */ NetworkRecvStatus ServerNetworkGameSocketHandler::SendJoin(ClientID client_id) { + Debug(net, 9, "client[{}] SendJoin(): client_id={}", this->client_id, client_id); + Packet *p = new Packet(PACKET_SERVER_JOIN); p->Send_uint32(client_id); @@ -625,6 +656,8 @@ NetworkRecvStatus ServerNetworkGameSocke /** Request the client to sync. */ NetworkRecvStatus ServerNetworkGameSocketHandler::SendSync() { + Debug(net, 9, "client[{}] SendSync(), frame_counter={}, sync_seed_1={}", this->client_id, _frame_counter, _sync_seed_1); + Packet *p = new Packet(PACKET_SERVER_SYNC); p->Send_uint32(_frame_counter); p->Send_uint32(_sync_seed_1); @@ -642,6 +675,8 @@ NetworkRecvStatus ServerNetworkGameSocke */ NetworkRecvStatus ServerNetworkGameSocketHandler::SendCommand(const CommandPacket *cp) { + Debug(net, 9, "client[{}] SendCommand(): cmd={}", this->client_id, cp->cmd); + Packet *p = new Packet(PACKET_SERVER_COMMAND); this->NetworkGameSocketHandler::SendCommand(p, cp); @@ -662,6 +697,8 @@ NetworkRecvStatus ServerNetworkGameSocke */ NetworkRecvStatus ServerNetworkGameSocketHandler::SendChat(NetworkAction action, ClientID client_id, bool self_send, const std::string &msg, int64_t data) { + Debug(net, 9, "client[{}] SendChat(): action={}, client_id={}, self_send={}", this->client_id, action, client_id, self_send); + if (this->status < STATUS_PRE_ACTIVE) return NETWORK_RECV_STATUS_OKAY; Packet *p = new Packet(PACKET_SERVER_CHAT); @@ -685,6 +722,8 @@ NetworkRecvStatus ServerNetworkGameSocke */ NetworkRecvStatus ServerNetworkGameSocketHandler::SendExternalChat(const std::string &source, TextColour colour, const std::string &user, const std::string &msg) { + Debug(net, 9, "client[{}] SendExternalChat(): source={}", this->client_id, source); + if (this->status < STATUS_PRE_ACTIVE) return NETWORK_RECV_STATUS_OKAY; Packet *p = new Packet(PACKET_SERVER_EXTERNAL_CHAT); @@ -705,6 +744,8 @@ NetworkRecvStatus ServerNetworkGameSocke */ NetworkRecvStatus ServerNetworkGameSocketHandler::SendErrorQuit(ClientID client_id, NetworkErrorCode errorno) { + Debug(net, 9, "client[{}] SendErrorQuit(): client_id={}, errorno={}", this->client_id, client_id, errorno); + Packet *p = new Packet(PACKET_SERVER_ERROR_QUIT); p->Send_uint32(client_id); @@ -720,6 +761,8 @@ NetworkRecvStatus ServerNetworkGameSocke */ NetworkRecvStatus ServerNetworkGameSocketHandler::SendQuit(ClientID client_id) { + Debug(net, 9, "client[{}] SendQuit(): client_id={}", this->client_id, client_id); + Packet *p = new Packet(PACKET_SERVER_QUIT); p->Send_uint32(client_id); @@ -731,6 +774,8 @@ NetworkRecvStatus ServerNetworkGameSocke /** Tell the client we're shutting down. */ NetworkRecvStatus ServerNetworkGameSocketHandler::SendShutdown() { + Debug(net, 9, "client[{}] SendShutdown()", this->client_id); + Packet *p = new Packet(PACKET_SERVER_SHUTDOWN); this->SendPacket(p); return NETWORK_RECV_STATUS_OKAY; @@ -739,6 +784,8 @@ NetworkRecvStatus ServerNetworkGameSocke /** Tell the client we're starting a new game. */ NetworkRecvStatus ServerNetworkGameSocketHandler::SendNewGame() { + Debug(net, 9, "client[{}] SendNewGame()", this->client_id); + Packet *p = new Packet(PACKET_SERVER_NEWGAME); this->SendPacket(p); return NETWORK_RECV_STATUS_OKAY; @@ -751,6 +798,8 @@ NetworkRecvStatus ServerNetworkGameSocke */ NetworkRecvStatus ServerNetworkGameSocketHandler::SendRConResult(uint16_t colour, const std::string &command) { + Debug(net, 9, "client[{}] SendRConResult()", this->client_id); + Packet *p = new Packet(PACKET_SERVER_RCON); p->Send_uint16(colour); @@ -766,6 +815,8 @@ NetworkRecvStatus ServerNetworkGameSocke */ NetworkRecvStatus ServerNetworkGameSocketHandler::SendMove(ClientID client_id, CompanyID company_id) { + Debug(net, 9, "client[{}] SendMove(): client_id={}", this->client_id, client_id); + Packet *p = new Packet(PACKET_SERVER_MOVE); p->Send_uint32(client_id); @@ -777,6 +828,8 @@ NetworkRecvStatus ServerNetworkGameSocke /** Send an update about the company password states. */ NetworkRecvStatus ServerNetworkGameSocketHandler::SendCompanyUpdate() { + Debug(net, 9, "client[{}] SendCompanyUpdate()", this->client_id); + Packet *p = new Packet(PACKET_SERVER_COMPANY_UPDATE); static_assert(sizeof(_network_company_passworded) <= sizeof(uint16_t)); @@ -788,6 +841,8 @@ NetworkRecvStatus ServerNetworkGameSocke /** Send an update about the max company/spectator counts. */ NetworkRecvStatus ServerNetworkGameSocketHandler::SendConfigUpdate() { + Debug(net, 9, "client[{}] SendConfigUpdate()", this->client_id); + Packet *p = new Packet(PACKET_SERVER_CONFIG_UPDATE); p->Send_uint8(_settings_client.network.max_companies); @@ -803,6 +858,8 @@ NetworkRecvStatus ServerNetworkGameSocke NetworkRecvStatus ServerNetworkGameSocketHandler::Receive_CLIENT_GAME_INFO(Packet *) { + Debug(net, 9, "client[{}] Receive_CLIENT_GAME_INFO()", this->client_id); + return this->SendGameInfo(); } @@ -813,6 +870,8 @@ NetworkRecvStatus ServerNetworkGameSocke return this->SendError(NETWORK_ERROR_NOT_EXPECTED); } + Debug(net, 9, "client[{}] Receive_CLIENT_NEWGRFS_CHECKED()", this->client_id); + NetworkClientInfo *ci = this->GetInfo(); /* We now want a password from the client else we do not allow them in! */ @@ -842,6 +901,8 @@ NetworkRecvStatus ServerNetworkGameSocke std::string client_revision = p->Recv_string(NETWORK_REVISION_LENGTH); uint32_t newgrf_version = p->Recv_uint32(); + Debug(net, 9, "client[{}] Receive_CLIENT_JOIN(): client_revision={}, newgrf_version={}", this->client_id, client_revision, newgrf_version); + /* Check if the client has revision control enabled */ if (!IsNetworkCompatibleVersion(client_revision) || _openttd_newgrf_version != newgrf_version) { /* Different revisions!! */ @@ -892,6 +953,7 @@ NetworkRecvStatus ServerNetworkGameSocke /* Make sure companies to which people try to join are not autocleaned */ if (Company::IsValidID(playas)) _network_company_states[playas].months_empty = 0; + Debug(net, 9, "client[{}] status = NEWGRFS_CHECK", this->client_id); this->status = STATUS_NEWGRFS_CHECK; if (_grfconfig == nullptr) { @@ -908,6 +970,8 @@ NetworkRecvStatus ServerNetworkGameSocke return this->SendError(NETWORK_ERROR_NOT_EXPECTED); } + Debug(net, 9, "client[{}] Receive_CLIENT_GAME_PASSWORD()", this->client_id); + std::string password = p->Recv_string(NETWORK_PASSWORD_LENGTH); /* Check game password. Allow joining if we cleared the password meanwhile */ @@ -932,6 +996,8 @@ NetworkRecvStatus ServerNetworkGameSocke return this->SendError(NETWORK_ERROR_NOT_EXPECTED); } + Debug(net, 9, "client[{}] Receive_CLIENT_COMPANY_PASSWORD()", this->client_id); + std::string password = p->Recv_string(NETWORK_PASSWORD_LENGTH); /* Check company password. Allow joining if we cleared the password meanwhile. @@ -955,10 +1021,13 @@ NetworkRecvStatus ServerNetworkGameSocke return this->SendError(NETWORK_ERROR_NOT_AUTHORIZED); } + Debug(net, 9, "client[{}] Receive_CLIENT_GETMAP()", this->client_id); + /* Check if someone else is receiving the map */ for (NetworkClientSocket *new_cs : NetworkClientSocket::Iterate()) { if (new_cs->status == STATUS_MAP) { /* Tell the new client to wait */ + Debug(net, 9, "client[{}] status = MAP_WAIT", this->client_id); this->status = STATUS_MAP_WAIT; return this->SendWait(); } @@ -972,6 +1041,8 @@ NetworkRecvStatus ServerNetworkGameSocke { /* Client has the map, now start syncing */ if (this->status == STATUS_DONE_MAP && !this->HasClientQuit()) { + Debug(net, 9, "client[{}] Receive_CLIENT_MAP_OK()", this->client_id); + std::string client_name = this->GetClientName(); NetworkTextMessage(NETWORK_ACTION_JOIN, CC_DEFAULT, false, client_name, "", this->client_id); @@ -981,6 +1052,7 @@ NetworkRecvStatus ServerNetworkGameSocke /* Mark the client as pre-active, and wait for an ACK * so we know it is done loading and in sync with us */ + Debug(net, 9, "client[{}] status = PRE_ACTIVE", this->client_id); this->status = STATUS_PRE_ACTIVE; NetworkHandleCommandQueue(this); this->SendFrame(); @@ -1027,6 +1099,8 @@ NetworkRecvStatus ServerNetworkGameSocke return this->SendError(NETWORK_ERROR_TOO_MANY_COMMANDS); } + Debug(net, 9, "client[{}] Receive_CLIENT_COMMAND()", this->client_id); + CommandPacket cp; const char *err = this->ReceiveCommand(p, &cp); @@ -1086,6 +1160,8 @@ NetworkRecvStatus ServerNetworkGameSocke * to us. Display the error and report it to the other clients */ NetworkErrorCode errorno = (NetworkErrorCode)p->Recv_uint8(); + Debug(net, 9, "client[{}] Receive_CLIENT_ERROR(): errorno={}", this->client_id, errorno); + /* The client was never joined.. thank the client for the packet, but ignore it */ if (this->status < STATUS_DONE_MAP || this->HasClientQuit()) { return this->CloseConnection(NETWORK_RECV_STATUS_CLIENT_QUIT); @@ -1116,6 +1192,8 @@ NetworkRecvStatus ServerNetworkGameSocke return this->CloseConnection(NETWORK_RECV_STATUS_CLIENT_QUIT); } + Debug(net, 9, "client[{}] Receive_CLIENT_QUIT()", this->client_id); + /* The client wants to leave. Display this and report it to the other clients. */ std::string client_name = this->GetClientName(); NetworkTextMessage(NETWORK_ACTION_LEAVE, CC_DEFAULT, false, client_name, "", STR_NETWORK_MESSAGE_CLIENT_LEAVING); @@ -1140,12 +1218,15 @@ NetworkRecvStatus ServerNetworkGameSocke uint32_t frame = p->Recv_uint32(); + Debug(net, 9, "client[{}] Receive_CLIENT_ACK(): frame={}", this->client_id, frame); + /* The client is trying to catch up with the server */ if (this->status == STATUS_PRE_ACTIVE) { /* The client is not yet caught up? */ if (frame + Ticks::DAY_TICKS < _frame_counter) return NETWORK_RECV_STATUS_OKAY; /* Now it is! Unpause the game */ + Debug(net, 9, "client[{}] status = ACTIVE", this->client_id); this->status = STATUS_ACTIVE; this->last_token_frame = _frame_counter; @@ -1324,6 +1405,8 @@ NetworkRecvStatus ServerNetworkGameSocke DestType desttype = (DestType)p->Recv_uint8(); int dest = p->Recv_uint32(); + Debug(net, 9, "client[{}] Receive_CLIENT_CHAT(): action={}, desttype={}, dest={}", this->client_id, action, desttype, dest); + std::string msg = p->Recv_string(NETWORK_CHAT_LENGTH); int64_t data = p->Recv_uint64(); @@ -1348,6 +1431,8 @@ NetworkRecvStatus ServerNetworkGameSocke return this->SendError(NETWORK_ERROR_NOT_EXPECTED); } + Debug(net, 9, "client[{}] Receive_CLIENT_SET_PASSWORD()", this->client_id); + std::string password = p->Recv_string(NETWORK_PASSWORD_LENGTH); const NetworkClientInfo *ci = this->GetInfo(); @@ -1362,6 +1447,8 @@ NetworkRecvStatus ServerNetworkGameSocke return this->SendError(NETWORK_ERROR_NOT_EXPECTED); } + Debug(net, 9, "client[{}] Receive_CLIENT_SET_NAME()", this->client_id); + NetworkClientInfo *ci; std::string client_name = p->Recv_string(NETWORK_CLIENT_NAME_LENGTH); @@ -1393,6 +1480,8 @@ NetworkRecvStatus ServerNetworkGameSocke if (_settings_client.network.rcon_password.empty()) return NETWORK_RECV_STATUS_OKAY; + Debug(net, 9, "client[{}] Receive_CLIENT_RCON()", this->client_id); + std::string password = p->Recv_string(NETWORK_PASSWORD_LENGTH); std::string command = p->Recv_string(NETWORK_RCONCOMMAND_LENGTH); @@ -1415,6 +1504,8 @@ NetworkRecvStatus ServerNetworkGameSocke CompanyID company_id = (Owner)p->Recv_uint8(); + Debug(net, 9, "client[{}] Receive_CLIENT_MOVE(): company_id={}", this->client_id, company_id); + /* Check if the company is valid, we don't allow moving to AI companies */ if (company_id != COMPANY_SPECTATOR && !Company::IsValidHumanID(company_id)) return NETWORK_RECV_STATUS_OKAY; diff --git a/src/network/network_stun.cpp b/src/network/network_stun.cpp --- a/src/network/network_stun.cpp +++ b/src/network/network_stun.cpp @@ -38,6 +38,8 @@ public: void OnFailure() override { + Debug(net, 9, "Stun::OnFailure(): family={}", this->family); + this->stun_handler->connecter = nullptr; /* Connection to STUN server failed. For example, the client doesn't @@ -48,6 +50,8 @@ public: void OnConnect(SOCKET s) override { + Debug(net, 9, "Stun::OnConnect(): family={}", this->family); + this->stun_handler->connecter = nullptr; assert(this->stun_handler->sock == INVALID_SOCKET); @@ -71,6 +75,8 @@ void ClientNetworkStunSocketHandler::Con this->token = token; this->family = family; + Debug(net, 9, "Stun::Connect(): family={}", this->family); + this->connecter = TCPConnecter::Create(this, NetworkStunConnectionString(), token, family); } diff --git a/src/network/network_turn.cpp b/src/network/network_turn.cpp --- a/src/network/network_turn.cpp +++ b/src/network/network_turn.cpp @@ -32,6 +32,8 @@ public: void OnFailure() override { + Debug(net, 9, "Turn::OnFailure()"); + this->handler->connecter = nullptr; this->handler->ConnectFailure(); @@ -39,6 +41,8 @@ public: void OnConnect(SOCKET s) override { + Debug(net, 9, "Turn::OnConnect()"); + this->handler->connecter = nullptr; this->handler->sock = s; @@ -47,6 +51,8 @@ public: bool ClientNetworkTurnSocketHandler::Receive_TURN_ERROR(Packet *) { + Debug(net, 9, "Receive_TURN_ERROR()"); + this->ConnectFailure(); return false; @@ -54,6 +60,8 @@ bool ClientNetworkTurnSocketHandler::Rec bool ClientNetworkTurnSocketHandler::Receive_TURN_CONNECTED(Packet *p) { + Debug(net, 9, "Receive_TURN_CONNECTED()"); + std::string hostname = p->Recv_string(NETWORK_HOSTNAME_LENGTH); /* Act like we no longer have a socket, as we are handing it over to the @@ -72,6 +80,8 @@ bool ClientNetworkTurnSocketHandler::Rec */ void ClientNetworkTurnSocketHandler::Connect() { + Debug(net, 9, "Turn::Connect()"); + this->connect_started = true; this->connecter = TCPConnecter::Create(this, this->connection_string); }