1
0
Fork 0

Change: reworked the debug levels for network facility (#9251)

It now follows very simple rules:
0 - Fatal, user should know about this
1 - Error, but we are recovering
2 - Warning, wrong but okay if you don't know
3 - Info, information you might care about
4 -
5 - Debug #1 - High level debug messages
6 - Debug #2 - Low level debug messages
7 - Trace information
pull/9254/head
Patric Stout 2021-05-12 16:34:02 +02:00 committed by GitHub
parent 56050fc96f
commit b136e65cf9
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
24 changed files with 132 additions and 133 deletions

View File

@ -91,7 +91,7 @@ static void _GenerateWorld()
try { try {
_generating_world = true; _generating_world = true;
if (_network_dedicated) DEBUG(net, 1, "Generating map, please wait..."); if (_network_dedicated) DEBUG(net, 3, "Generating map, please wait...");
/* Set the Random() seed to generation_seed so we produce the same map with the same seed */ /* Set the Random() seed to generation_seed so we produce the same map with the same seed */
if (_settings_game.game_creation.generation_seed == GENERATE_NEW_SEED) _settings_game.game_creation.generation_seed = _settings_newgame.game_creation.generation_seed = InteractiveRandom(); if (_settings_game.game_creation.generation_seed == GENERATE_NEW_SEED) _settings_game.game_creation.generation_seed = _settings_newgame.game_creation.generation_seed = InteractiveRandom();
_random.SetSeed(_settings_game.game_creation.generation_seed); _random.SetSeed(_settings_game.game_creation.generation_seed);
@ -188,7 +188,7 @@ static void _GenerateWorld()
ShowNewGRFError(); ShowNewGRFError();
if (_network_dedicated) DEBUG(net, 1, "Map generated, starting game"); if (_network_dedicated) DEBUG(net, 3, "Map generated, starting game");
DEBUG(desync, 1, "new_map: %08x", _settings_game.game_creation.generation_seed); DEBUG(desync, 1, "new_map: %08x", _settings_game.game_creation.generation_seed);
if (_debug_desync_level > 0) { if (_debug_desync_level > 0) {
@ -204,7 +204,7 @@ static void _GenerateWorld()
if (_network_dedicated) { if (_network_dedicated) {
/* Exit the game to prevent a return to main menu. */ /* Exit the game to prevent a return to main menu. */
DEBUG(net, 0, "Generating map failed, aborting"); DEBUG(net, 0, "Generating map failed; closing server");
_exit_game = true; _exit_game = true;
} else { } else {
SwitchToMode(_switch_mode); SwitchToMode(_switch_mode);

View File

@ -1458,7 +1458,7 @@ static void _SetGeneratingWorldProgress(GenWorldProgress cls, uint progress, uin
/* Never show steps smaller than 2%, even if it is a mod 5% */ /* Never show steps smaller than 2%, even if it is a mod 5% */
if (_gws.percent <= last_percent + 2) return; if (_gws.percent <= last_percent + 2) return;
DEBUG(net, 1, "Map generation percentage complete: %d", _gws.percent); DEBUG(net, 3, "Map generation percentage complete: %d", _gws.percent);
last_percent = _gws.percent; last_percent = _gws.percent;
return; return;

View File

@ -356,7 +356,7 @@ static SOCKET ListenLoopProc(addrinfo *runp)
DEBUG(net, 0, "Setting non-blocking mode failed: %s", NetworkError::GetLast().AsString()); DEBUG(net, 0, "Setting non-blocking mode failed: %s", NetworkError::GetLast().AsString());
} }
DEBUG(net, 1, "Listening on %s", address.c_str()); DEBUG(net, 3, "Listening on %s", address.c_str());
return sock; return sock;
} }

View File

@ -27,9 +27,9 @@ bool NetworkCoreInitialize()
#ifdef _WIN32 #ifdef _WIN32
{ {
WSADATA wsa; WSADATA wsa;
DEBUG(net, 3, "[core] loading windows socket library"); DEBUG(net, 5, "Loading windows socket library");
if (WSAStartup(MAKEWORD(2, 0), &wsa) != 0) { if (WSAStartup(MAKEWORD(2, 0), &wsa) != 0) {
DEBUG(net, 0, "[core] WSAStartup failed, network unavailable"); DEBUG(net, 0, "WSAStartup failed, network unavailable");
return false; return false;
} }
} }

View File

@ -51,7 +51,7 @@ const char *GetNetworkRevisionString()
/* Tag names are not mangled further. */ /* Tag names are not mangled further. */
if (_openttd_revision_tagged) { if (_openttd_revision_tagged) {
DEBUG(net, 1, "Network revision name is '%s'", network_revision); DEBUG(net, 3, "Network revision name: %s", network_revision);
return network_revision; return network_revision;
} }
@ -71,7 +71,7 @@ const char *GetNetworkRevisionString()
/* Replace the git hash in revision string. */ /* Replace the git hash in revision string. */
strecpy(network_revision + hashofs, githash_suffix, network_revision + NETWORK_REVISION_LENGTH); strecpy(network_revision + hashofs, githash_suffix, network_revision + NETWORK_REVISION_LENGTH);
assert(strlen(network_revision) < NETWORK_REVISION_LENGTH); // strlen does not include terminator, constant does, hence strictly less than assert(strlen(network_revision) < NETWORK_REVISION_LENGTH); // strlen does not include terminator, constant does, hence strictly less than
DEBUG(net, 1, "Network revision name is '%s'", network_revision); DEBUG(net, 3, "Network revision name: %s", network_revision);
} }
return network_revision; return network_revision;

View File

@ -39,14 +39,14 @@ static void NetworkFindBroadcastIPsInternal(NetworkAddressList *broadcast) // BE
int sock = socket(AF_INET, SOCK_DGRAM, 0); int sock = socket(AF_INET, SOCK_DGRAM, 0);
if (sock < 0) { if (sock < 0) {
DEBUG(net, 0, "[core] error creating socket"); DEBUG(net, 0, "Could not create socket: %s", NetworkError::GetLast().AsString());
return; return;
} }
char *output_pointer = nullptr; char *output_pointer = nullptr;
int output_length = _netstat(sock, &output_pointer, 1); int output_length = _netstat(sock, &output_pointer, 1);
if (output_length < 0) { if (output_length < 0) {
DEBUG(net, 0, "[core] error running _netstat"); DEBUG(net, 0, "Error running _netstat()");
return; return;
} }

View File

@ -90,7 +90,7 @@ SendPacketsState NetworkTCPSocketHandler::SendPackets(bool closing_down)
if (!err.WouldBlock()) { if (!err.WouldBlock()) {
/* Something went wrong.. close client! */ /* Something went wrong.. close client! */
if (!closing_down) { if (!closing_down) {
DEBUG(net, 0, "send failed with error %s", err.AsString()); DEBUG(net, 0, "Send failed: %s", err.AsString());
this->CloseConnection(); this->CloseConnection();
} }
return SPS_CLOSED; return SPS_CLOSED;
@ -139,7 +139,7 @@ Packet *NetworkTCPSocketHandler::ReceivePacket()
NetworkError err = NetworkError::GetLast(); NetworkError err = NetworkError::GetLast();
if (!err.WouldBlock()) { if (!err.WouldBlock()) {
/* Something went wrong... */ /* Something went wrong... */
if (!err.IsConnectionReset()) DEBUG(net, 0, "recv failed with error %s", err.AsString()); if (!err.IsConnectionReset()) DEBUG(net, 0, "Recv failed: %s", err.AsString());
this->CloseConnection(); this->CloseConnection();
return nullptr; return nullptr;
} }
@ -167,7 +167,7 @@ Packet *NetworkTCPSocketHandler::ReceivePacket()
NetworkError err = NetworkError::GetLast(); NetworkError err = NetworkError::GetLast();
if (!err.WouldBlock()) { if (!err.WouldBlock()) {
/* Something went wrong... */ /* Something went wrong... */
if (!err.IsConnectionReset()) DEBUG(net, 0, "recv failed with error %s", err.AsString()); if (!err.IsConnectionReset()) DEBUG(net, 0, "Recv failed: %s", err.AsString());
this->CloseConnection(); this->CloseConnection();
return nullptr; return nullptr;
} }

View File

@ -93,9 +93,9 @@ NetworkRecvStatus NetworkAdminSocketHandler::HandlePacket(Packet *p)
default: default:
if (this->HasClientQuit()) { if (this->HasClientQuit()) {
DEBUG(net, 0, "[tcp/admin] received invalid packet type %d from '%s' (%s)", type, this->admin_name, this->admin_version); DEBUG(net, 0, "[tcp/admin] Received invalid packet type %d from '%s' (%s)", type, this->admin_name, this->admin_version);
} else { } else {
DEBUG(net, 0, "[tcp/admin] received illegal packet from '%s' (%s)", this->admin_name, this->admin_version); DEBUG(net, 0, "[tcp/admin] Received illegal packet from '%s' (%s)", this->admin_name, this->admin_version);
} }
this->CloseConnection(); this->CloseConnection();
@ -129,7 +129,7 @@ NetworkRecvStatus NetworkAdminSocketHandler::ReceivePackets()
*/ */
NetworkRecvStatus NetworkAdminSocketHandler::ReceiveInvalidPacket(PacketAdminType type) NetworkRecvStatus NetworkAdminSocketHandler::ReceiveInvalidPacket(PacketAdminType type)
{ {
DEBUG(net, 0, "[tcp/admin] received illegal packet type %d from admin %s (%s)", type, this->admin_name, this->admin_version); DEBUG(net, 0, "[tcp/admin] Received illegal packet type %d from admin %s (%s)", type, this->admin_name, this->admin_version);
return NETWORK_RECV_STATUS_MALFORMED_PACKET; return NETWORK_RECV_STATUS_MALFORMED_PACKET;
} }

View File

@ -72,7 +72,7 @@ void TCPConnecter::Connect(addrinfo *address)
} }
NetworkAddress network_address = NetworkAddress(address->ai_addr, (int)address->ai_addrlen); NetworkAddress network_address = NetworkAddress(address->ai_addr, (int)address->ai_addrlen);
DEBUG(net, 4, "Attempting to connect to %s", network_address.GetAddressAsString().c_str()); DEBUG(net, 5, "Attempting to connect to %s", network_address.GetAddressAsString().c_str());
int err = connect(sock, address->ai_addr, (int)address->ai_addrlen); int err = connect(sock, address->ai_addr, (int)address->ai_addrlen);
if (err != 0 && !NetworkError::GetLast().IsConnectInProgress()) { if (err != 0 && !NetworkError::GetLast().IsConnectInProgress()) {
@ -149,10 +149,10 @@ void TCPConnecter::OnResolved(addrinfo *ai)
} }
} }
if (_debug_net_level >= 5) { if (_debug_net_level >= 6) {
DEBUG(net, 5, "%s resolved in:", this->connection_string.c_str()); DEBUG(net, 6, "%s resolved in:", this->connection_string.c_str());
for (const auto &address : this->addresses) { for (const auto &address : this->addresses) {
DEBUG(net, 5, "- %s", NetworkAddress(address->ai_addr, (int)address->ai_addrlen).GetAddressAsString().c_str()); DEBUG(net, 6, "- %s", NetworkAddress(address->ai_addr, (int)address->ai_addrlen).GetAddressAsString().c_str());
} }
} }
@ -188,7 +188,7 @@ void TCPConnecter::Resolve()
} }
if (e != 0) { if (e != 0) {
DEBUG(misc, 0, "Failed to resolve DNS for %s", this->connection_string.c_str()); DEBUG(net, 0, "Failed to resolve DNS for %s", this->connection_string.c_str());
this->OnFailure(); this->OnFailure();
return; return;
} }
@ -235,7 +235,7 @@ bool TCPConnecter::CheckActivity()
/* select() failed; hopefully next try it doesn't. */ /* select() failed; hopefully next try it doesn't. */
if (n < 0) { if (n < 0) {
/* select() normally never fails; so hopefully it works next try! */ /* select() normally never fails; so hopefully it works next try! */
DEBUG(net, 1, "select() failed with %s", NetworkError::GetLast().AsString()); DEBUG(net, 1, "select() failed: %s", NetworkError::GetLast().AsString());
return false; return false;
} }
@ -301,7 +301,7 @@ bool TCPConnecter::CheckActivity()
} }
assert(connected_socket != INVALID_SOCKET); assert(connected_socket != INVALID_SOCKET);
DEBUG(net, 1, "Connected to %s", this->connection_string.c_str()); DEBUG(net, 3, "Connected to %s", this->connection_string.c_str());
if (_debug_net_level >= 5) { if (_debug_net_level >= 5) {
DEBUG(net, 5, "- using %s", NetworkAddress::GetPeerName(connected_socket).c_str()); DEBUG(net, 5, "- using %s", NetworkAddress::GetPeerName(connected_socket).c_str());
} }

View File

@ -167,9 +167,9 @@ bool NetworkContentSocketHandler::HandlePacket(Packet *p)
default: default:
if (this->HasClientQuit()) { if (this->HasClientQuit()) {
DEBUG(net, 0, "[tcp/content] received invalid packet type %d", type); DEBUG(net, 0, "[tcp/content] Received invalid packet type %d", type);
} else { } else {
DEBUG(net, 0, "[tcp/content] received illegal packet"); DEBUG(net, 0, "[tcp/content] Received illegal packet");
} }
return false; return false;
} }
@ -220,7 +220,7 @@ bool NetworkContentSocketHandler::ReceivePackets()
*/ */
bool NetworkContentSocketHandler::ReceiveInvalidPacket(PacketContentType type) bool NetworkContentSocketHandler::ReceiveInvalidPacket(PacketContentType type)
{ {
DEBUG(net, 0, "[tcp/content] received illegal packet type %d", type); DEBUG(net, 0, "[tcp/content] Received illegal packet type %d", type);
return false; return false;
} }

View File

@ -117,9 +117,9 @@ NetworkRecvStatus NetworkGameSocketHandler::HandlePacket(Packet *p)
this->CloseConnection(); this->CloseConnection();
if (this->HasClientQuit()) { if (this->HasClientQuit()) {
DEBUG(net, 0, "[tcp/game] received invalid packet type %d from client %d", type, this->client_id); DEBUG(net, 0, "[tcp/game] Received invalid packet type %d from client %d", type, this->client_id);
} else { } else {
DEBUG(net, 0, "[tcp/game] received illegal packet from client %d", this->client_id); DEBUG(net, 0, "[tcp/game] Received illegal packet from client %d", this->client_id);
} }
return NETWORK_RECV_STATUS_MALFORMED_PACKET; return NETWORK_RECV_STATUS_MALFORMED_PACKET;
} }
@ -151,7 +151,7 @@ NetworkRecvStatus NetworkGameSocketHandler::ReceivePackets()
*/ */
NetworkRecvStatus NetworkGameSocketHandler::ReceiveInvalidPacket(PacketGameType type) NetworkRecvStatus NetworkGameSocketHandler::ReceiveInvalidPacket(PacketGameType type)
{ {
DEBUG(net, 0, "[tcp/game] received illegal packet type %d from client %d", type, this->client_id); DEBUG(net, 0, "[tcp/game] Received illegal packet type %d from client %d", type, this->client_id);
return NETWORK_RECV_STATUS_MALFORMED_PACKET; return NETWORK_RECV_STATUS_MALFORMED_PACKET;
} }

View File

@ -45,7 +45,7 @@ NetworkHTTPSocketHandler::NetworkHTTPSocketHandler(SOCKET s,
size_t bufferSize = strlen(url) + strlen(host) + strlen(GetNetworkRevisionString()) + (data == nullptr ? 0 : strlen(data)) + 128; size_t bufferSize = strlen(url) + strlen(host) + strlen(GetNetworkRevisionString()) + (data == nullptr ? 0 : strlen(data)) + 128;
char *buffer = AllocaM(char, bufferSize); char *buffer = AllocaM(char, bufferSize);
DEBUG(net, 7, "[tcp/http] requesting %s%s", host, url); DEBUG(net, 5, "[tcp/http] Requesting %s%s", host, url);
if (data != nullptr) { if (data != nullptr) {
seprintf(buffer, buffer + bufferSize - 1, "POST %s HTTP/1.0\r\nHost: %s\r\nUser-Agent: OpenTTD/%s\r\nContent-Type: text/plain\r\nContent-Length: %d\r\n\r\n%s\r\n", url, host, GetNetworkRevisionString(), (int)strlen(data), data); seprintf(buffer, buffer + bufferSize - 1, "POST %s HTTP/1.0\r\nHost: %s\r\nUser-Agent: OpenTTD/%s\r\nContent-Type: text/plain\r\nContent-Length: %d\r\n\r\n%s\r\n", url, host, GetNetworkRevisionString(), (int)strlen(data), data);
} else { } else {
@ -85,7 +85,7 @@ NetworkRecvStatus NetworkHTTPSocketHandler::CloseConnection(bool error)
* Helper to simplify the error handling. * Helper to simplify the error handling.
* @param msg the error message to show. * @param msg the error message to show.
*/ */
#define return_error(msg) { DEBUG(net, 0, msg); return -1; } #define return_error(msg) { DEBUG(net, 1, msg); return -1; }
static const char * const NEWLINE = "\r\n"; ///< End of line marker static const char * const NEWLINE = "\r\n"; ///< End of line marker
static const char * const END_OF_HEADER = "\r\n\r\n"; ///< End of header marker static const char * const END_OF_HEADER = "\r\n\r\n"; ///< End of header marker
@ -112,7 +112,7 @@ int NetworkHTTPSocketHandler::HandleHeader()
/* We expect a HTTP/1.[01] reply */ /* We expect a HTTP/1.[01] reply */
if (strncmp(this->recv_buffer, HTTP_1_0, strlen(HTTP_1_0)) != 0 && if (strncmp(this->recv_buffer, HTTP_1_0, strlen(HTTP_1_0)) != 0 &&
strncmp(this->recv_buffer, HTTP_1_1, strlen(HTTP_1_1)) != 0) { strncmp(this->recv_buffer, HTTP_1_1, strlen(HTTP_1_1)) != 0) {
return_error("[tcp/http] received invalid HTTP reply"); return_error("[tcp/http] Received invalid HTTP reply");
} }
char *status = this->recv_buffer + strlen(HTTP_1_0); char *status = this->recv_buffer + strlen(HTTP_1_0);
@ -121,7 +121,7 @@ int NetworkHTTPSocketHandler::HandleHeader()
/* Get the length of the document to receive */ /* Get the length of the document to receive */
char *length = strcasestr(this->recv_buffer, CONTENT_LENGTH); char *length = strcasestr(this->recv_buffer, CONTENT_LENGTH);
if (length == nullptr) return_error("[tcp/http] missing 'content-length' header"); if (length == nullptr) return_error("[tcp/http] Missing 'content-length' header");
/* Skip the header */ /* Skip the header */
length += strlen(CONTENT_LENGTH); length += strlen(CONTENT_LENGTH);
@ -139,9 +139,9 @@ int NetworkHTTPSocketHandler::HandleHeader()
/* Make sure we're going to download at least something; /* Make sure we're going to download at least something;
* zero sized files are, for OpenTTD's purposes, always * zero sized files are, for OpenTTD's purposes, always
* wrong. You can't have gzips of 0 bytes! */ * wrong. You can't have gzips of 0 bytes! */
if (len == 0) return_error("[tcp/http] refusing to download 0 bytes"); if (len == 0) return_error("[tcp/http] Refusing to download 0 bytes");
DEBUG(net, 7, "[tcp/http] downloading %i bytes", len); DEBUG(net, 7, "[tcp/http] Downloading %i bytes", len);
return len; return len;
} }
@ -154,15 +154,15 @@ int NetworkHTTPSocketHandler::HandleHeader()
/* Search the end of the line. This is safe because the header will /* Search the end of the line. This is safe because the header will
* always end with two newlines. */ * always end with two newlines. */
*strstr(status, NEWLINE) = '\0'; *strstr(status, NEWLINE) = '\0';
DEBUG(net, 0, "[tcp/http] unhandled status reply %s", status); DEBUG(net, 1, "[tcp/http] Unhandled status reply %s", status);
return -1; return -1;
} }
if (this->redirect_depth == 5) return_error("[tcp/http] too many redirects, looping redirects?"); if (this->redirect_depth == 5) return_error("[tcp/http] Too many redirects, looping redirects?");
/* Redirect to other URL */ /* Redirect to other URL */
char *uri = strcasestr(this->recv_buffer, LOCATION); char *uri = strcasestr(this->recv_buffer, LOCATION);
if (uri == nullptr) return_error("[tcp/http] missing 'location' header for redirect"); if (uri == nullptr) return_error("[tcp/http] Missing 'location' header for redirect");
uri += strlen(LOCATION); uri += strlen(LOCATION);
@ -171,7 +171,7 @@ int NetworkHTTPSocketHandler::HandleHeader()
char *end_of_line = strstr(uri, NEWLINE); char *end_of_line = strstr(uri, NEWLINE);
*end_of_line = '\0'; *end_of_line = '\0';
DEBUG(net, 6, "[tcp/http] redirecting to %s", uri); DEBUG(net, 7, "[tcp/http] Redirecting to %s", uri);
int ret = NetworkHTTPSocketHandler::Connect(uri, this->callback, this->data, this->redirect_depth + 1); int ret = NetworkHTTPSocketHandler::Connect(uri, this->callback, this->data, this->redirect_depth + 1);
if (ret != 0) return ret; if (ret != 0) return ret;
@ -194,12 +194,12 @@ int NetworkHTTPSocketHandler::HandleHeader()
/* static */ int NetworkHTTPSocketHandler::Connect(char *uri, HTTPCallback *callback, const char *data, int depth) /* static */ int NetworkHTTPSocketHandler::Connect(char *uri, HTTPCallback *callback, const char *data, int depth)
{ {
char *hname = strstr(uri, "://"); char *hname = strstr(uri, "://");
if (hname == nullptr) return_error("[tcp/http] invalid location"); if (hname == nullptr) return_error("[tcp/http] Invalid location");
hname += 3; hname += 3;
char *url = strchr(hname, '/'); char *url = strchr(hname, '/');
if (url == nullptr) return_error("[tcp/http] invalid location"); if (url == nullptr) return_error("[tcp/http] Invalid location");
*url = '\0'; *url = '\0';
@ -228,7 +228,7 @@ int NetworkHTTPSocketHandler::Receive()
NetworkError err = NetworkError::GetLast(); NetworkError err = NetworkError::GetLast();
if (!err.WouldBlock()) { if (!err.WouldBlock()) {
/* Something went wrong... */ /* Something went wrong... */
if (!err.IsConnectionReset()) DEBUG(net, 0, "recv failed with error %s", err.AsString()); if (!err.IsConnectionReset()) DEBUG(net, 0, "Recv failed: %s", err.AsString());
return -1; return -1;
} }
/* Connection would block, so stop for now */ /* Connection would block, so stop for now */
@ -256,7 +256,7 @@ int NetworkHTTPSocketHandler::Receive()
if (end_of_header == nullptr) { if (end_of_header == nullptr) {
if (read == lengthof(this->recv_buffer)) { if (read == lengthof(this->recv_buffer)) {
DEBUG(net, 0, "[tcp/http] header too big"); DEBUG(net, 1, "[tcp/http] Header too big");
return -1; return -1;
} }
this->recv_pos = read; this->recv_pos = read;

View File

@ -49,7 +49,7 @@ public:
SetNonBlocking(s); // XXX error handling? SetNonBlocking(s); // XXX error handling?
NetworkAddress address(sin, sin_len); NetworkAddress address(sin, sin_len);
DEBUG(net, 1, "[%s] Client connected from %s on frame %d", Tsocket::GetName(), address.GetHostname(), _frame_counter); DEBUG(net, 3, "[%s] Client connected from %s on frame %d", Tsocket::GetName(), address.GetHostname(), _frame_counter);
SetNoDelay(s); // XXX error handling? SetNoDelay(s); // XXX error handling?
@ -61,10 +61,10 @@ public:
Packet p(Tban_packet); Packet p(Tban_packet);
p.PrepareToSend(); p.PrepareToSend();
DEBUG(net, 1, "[%s] Banned ip tried to join (%s), refused", Tsocket::GetName(), entry.c_str()); DEBUG(net, 2, "[%s] Banned ip tried to join (%s), refused", Tsocket::GetName(), entry.c_str());
if (p.TransferOut<int>(send, s, 0) < 0) { if (p.TransferOut<int>(send, s, 0) < 0) {
DEBUG(net, 0, "send failed with error %s", NetworkError::GetLast().AsString()); DEBUG(net, 0, "[%s] send failed: %s", Tsocket::GetName(), NetworkError::GetLast().AsString());
} }
closesocket(s); closesocket(s);
break; break;
@ -81,7 +81,7 @@ public:
p.PrepareToSend(); p.PrepareToSend();
if (p.TransferOut<int>(send, s, 0) < 0) { if (p.TransferOut<int>(send, s, 0) < 0) {
DEBUG(net, 0, "send failed with error %s", NetworkError::GetLast().AsString()); DEBUG(net, 0, "[%s] send failed: %s", Tsocket::GetName(), NetworkError::GetLast().AsString());
} }
closesocket(s); closesocket(s);
@ -150,7 +150,7 @@ public:
} }
if (sockets.size() == 0) { if (sockets.size() == 0) {
DEBUG(net, 0, "[server] could not start network: could not create listening socket"); DEBUG(net, 0, "Could not start network: could not create listening socket");
ShowNetworkError(STR_NETWORK_ERROR_SERVER_START); ShowNetworkError(STR_NETWORK_ERROR_SERVER_START);
return false; return false;
} }
@ -165,7 +165,7 @@ public:
closesocket(s.second); closesocket(s.second);
} }
sockets.clear(); sockets.clear();
DEBUG(net, 1, "[%s] closed listeners", Tsocket::GetName()); DEBUG(net, 5, "[%s] Closed listeners", Tsocket::GetName());
} }
}; };

View File

@ -95,16 +95,16 @@ void NetworkUDPSocketHandler::SendPacket(Packet *p, NetworkAddress *recv, bool a
/* Enable broadcast */ /* Enable broadcast */
unsigned long val = 1; unsigned long val = 1;
if (setsockopt(s.second, SOL_SOCKET, SO_BROADCAST, (char *) &val, sizeof(val)) < 0) { if (setsockopt(s.second, SOL_SOCKET, SO_BROADCAST, (char *) &val, sizeof(val)) < 0) {
DEBUG(net, 1, "[udp] setting broadcast failed with: %s", NetworkError::GetLast().AsString()); DEBUG(net, 1, "Setting broadcast mode failed: %s", NetworkError::GetLast().AsString());
} }
} }
/* Send the buffer */ /* Send the buffer */
ssize_t res = p->TransferOut<int>(sendto, s.second, 0, (const struct sockaddr *)send.GetAddress(), send.GetAddressLength()); ssize_t res = p->TransferOut<int>(sendto, s.second, 0, (const struct sockaddr *)send.GetAddress(), send.GetAddressLength());
DEBUG(net, 7, "[udp] sendto(%s)", send.GetAddressAsString().c_str()); DEBUG(net, 7, "sendto(%s)", send.GetAddressAsString().c_str());
/* Check for any errors, but ignore it otherwise */ /* Check for any errors, but ignore it otherwise */
if (res == -1) DEBUG(net, 1, "[udp] sendto(%s) failed with: %s", send.GetAddressAsString().c_str(), NetworkError::GetLast().AsString()); if (res == -1) DEBUG(net, 1, "sendto(%s) failed: %s", send.GetAddressAsString().c_str(), NetworkError::GetLast().AsString());
if (!all) break; if (!all) break;
} }
@ -140,7 +140,7 @@ void NetworkUDPSocketHandler::ReceivePackets()
/* If the size does not match the packet must be corrupted. /* If the size does not match the packet must be corrupted.
* Otherwise it will be marked as corrupted later on. */ * Otherwise it will be marked as corrupted later on. */
if (!p.ParsePacketSize() || (size_t)nbytes != p.Size()) { if (!p.ParsePacketSize() || (size_t)nbytes != p.Size()) {
DEBUG(net, 1, "received a packet with mismatching size from %s", address.GetAddressAsString().c_str()); DEBUG(net, 1, "Received a packet with mismatching size from %s", address.GetAddressAsString().c_str());
continue; continue;
} }
p.PrepareToRead(); p.PrepareToRead();
@ -181,9 +181,9 @@ void NetworkUDPSocketHandler::HandleUDPPacket(Packet *p, NetworkAddress *client_
default: default:
if (this->HasClientQuit()) { if (this->HasClientQuit()) {
DEBUG(net, 0, "[udp] received invalid packet type %d from %s", type, client_addr->GetAddressAsString().c_str()); DEBUG(net, 0, "[udp] Received invalid packet type %d from %s", type, client_addr->GetAddressAsString().c_str());
} else { } else {
DEBUG(net, 0, "[udp] received illegal packet from %s", client_addr->GetAddressAsString().c_str()); DEBUG(net, 0, "[udp] Received illegal packet from %s", client_addr->GetAddressAsString().c_str());
} }
break; break;
} }
@ -196,7 +196,7 @@ void NetworkUDPSocketHandler::HandleUDPPacket(Packet *p, NetworkAddress *client_
*/ */
void NetworkUDPSocketHandler::ReceiveInvalidPacket(PacketUDPType type, NetworkAddress *client_addr) void NetworkUDPSocketHandler::ReceiveInvalidPacket(PacketUDPType type, NetworkAddress *client_addr)
{ {
DEBUG(net, 0, "[udp] received packet type %d on wrong port from %s", type, client_addr->GetAddressAsString().c_str()); DEBUG(net, 0, "[udp] Received packet type %d on wrong port from %s", type, client_addr->GetAddressAsString().c_str());
} }
void NetworkUDPSocketHandler::Receive_CLIENT_FIND_SERVER(Packet *p, NetworkAddress *client_addr) { this->ReceiveInvalidPacket(PACKET_UDP_CLIENT_FIND_SERVER, client_addr); } void NetworkUDPSocketHandler::Receive_CLIENT_FIND_SERVER(Packet *p, NetworkAddress *client_addr) { this->ReceiveInvalidPacket(PACKET_UDP_CLIENT_FIND_SERVER, client_addr); }

View File

@ -859,13 +859,13 @@ static void CheckClientAndServerName()
{ {
static const char *fallback_client_name = "Unnamed Client"; static const char *fallback_client_name = "Unnamed Client";
if (StrEmpty(_settings_client.network.client_name) || strcmp(_settings_client.network.client_name, fallback_client_name) == 0) { if (StrEmpty(_settings_client.network.client_name) || strcmp(_settings_client.network.client_name, fallback_client_name) == 0) {
DEBUG(net, 0, "No \"client_name\" has been set, using \"%s\" instead. Please set this now using the \"name <new name>\" command.", fallback_client_name); DEBUG(net, 1, "No \"client_name\" has been set, using \"%s\" instead. Please set this now using the \"name <new name>\" command", fallback_client_name);
strecpy(_settings_client.network.client_name, fallback_client_name, lastof(_settings_client.network.client_name)); strecpy(_settings_client.network.client_name, fallback_client_name, lastof(_settings_client.network.client_name));
} }
static const char *fallback_server_name = "Unnamed Server"; static const char *fallback_server_name = "Unnamed Server";
if (StrEmpty(_settings_client.network.server_name) || strcmp(_settings_client.network.server_name, fallback_server_name) == 0) { if (StrEmpty(_settings_client.network.server_name) || strcmp(_settings_client.network.server_name, fallback_server_name) == 0) {
DEBUG(net, 0, "No \"server_name\" has been set, using \"%s\" instead. Please set this now using the \"server_name <new name>\" command.", fallback_server_name); DEBUG(net, 1, "No \"server_name\" has been set, using \"%s\" instead. Please set this now using the \"server_name <new name>\" command", fallback_server_name);
strecpy(_settings_client.network.server_name, fallback_server_name, lastof(_settings_client.network.server_name)); strecpy(_settings_client.network.server_name, fallback_server_name, lastof(_settings_client.network.server_name));
} }
} }
@ -883,17 +883,17 @@ bool NetworkServerStart()
NetworkDisconnect(false, false); NetworkDisconnect(false, false);
NetworkInitialize(false); NetworkInitialize(false);
DEBUG(net, 1, "starting listeners for clients"); DEBUG(net, 5, "Starting listeners for clients");
if (!ServerNetworkGameSocketHandler::Listen(_settings_client.network.server_port)) return false; if (!ServerNetworkGameSocketHandler::Listen(_settings_client.network.server_port)) return false;
/* Only listen for admins when the password isn't empty. */ /* Only listen for admins when the password isn't empty. */
if (!StrEmpty(_settings_client.network.admin_password)) { if (!StrEmpty(_settings_client.network.admin_password)) {
DEBUG(net, 1, "starting listeners for admins"); DEBUG(net, 5, "Starting listeners for admins");
if (!ServerNetworkAdminSocketHandler::Listen(_settings_client.network.server_admin_port)) return false; if (!ServerNetworkAdminSocketHandler::Listen(_settings_client.network.server_admin_port)) return false;
} }
/* Try to start UDP-server */ /* Try to start UDP-server */
DEBUG(net, 1, "starting listeners for incoming server queries"); DEBUG(net, 5, "Starting listeners for incoming server queries");
NetworkUDPServerListen(); NetworkUDPServerListen();
_network_company_states = CallocT<NetworkCompanyState>(MAX_COMPANIES); _network_company_states = CallocT<NetworkCompanyState>(MAX_COMPANIES);
@ -1044,7 +1044,7 @@ void NetworkGameLoop()
static bool check_sync_state = false; static bool check_sync_state = false;
static uint32 sync_state[2]; static uint32 sync_state[2];
if (f == nullptr && next_date == 0) { if (f == nullptr && next_date == 0) {
DEBUG(net, 0, "Cannot open commands.log"); DEBUG(desync, 0, "Cannot open commands.log");
next_date = 1; next_date = 1;
} }
@ -1052,15 +1052,15 @@ void NetworkGameLoop()
if (_date == next_date && _date_fract == next_date_fract) { if (_date == next_date && _date_fract == next_date_fract) {
if (cp != nullptr) { if (cp != nullptr) {
NetworkSendCommand(cp->tile, cp->p1, cp->p2, cp->cmd & ~CMD_FLAGS_MASK, nullptr, cp->text, cp->company); NetworkSendCommand(cp->tile, cp->p1, cp->p2, cp->cmd & ~CMD_FLAGS_MASK, nullptr, cp->text, cp->company);
DEBUG(net, 0, "injecting: %08x; %02x; %02x; %06x; %08x; %08x; %08x; \"%s\" (%s)", _date, _date_fract, (int)_current_company, cp->tile, cp->p1, cp->p2, cp->cmd, cp->text, GetCommandName(cp->cmd)); DEBUG(desync, 0, "Injecting: %08x; %02x; %02x; %06x; %08x; %08x; %08x; \"%s\" (%s)", _date, _date_fract, (int)_current_company, cp->tile, cp->p1, cp->p2, cp->cmd, cp->text, GetCommandName(cp->cmd));
free(cp); free(cp);
cp = nullptr; cp = nullptr;
} }
if (check_sync_state) { if (check_sync_state) {
if (sync_state[0] == _random.state[0] && sync_state[1] == _random.state[1]) { if (sync_state[0] == _random.state[0] && sync_state[1] == _random.state[1]) {
DEBUG(net, 0, "sync check: %08x; %02x; match", _date, _date_fract); DEBUG(desync, 0, "Sync check: %08x; %02x; match", _date, _date_fract);
} else { } else {
DEBUG(net, 0, "sync check: %08x; %02x; mismatch expected {%08x, %08x}, got {%08x, %08x}", DEBUG(desync, 0, "Sync check: %08x; %02x; mismatch expected {%08x, %08x}, got {%08x, %08x}",
_date, _date_fract, sync_state[0], sync_state[1], _random.state[0], _random.state[1]); _date, _date_fract, sync_state[0], sync_state[1], _random.state[0], _random.state[1]);
NOT_REACHED(); NOT_REACHED();
} }
@ -1101,7 +1101,7 @@ void NetworkGameLoop()
/* Manually insert a pause when joining; this way the client can join at the exact right time. */ /* Manually insert a pause when joining; this way the client can join at the exact right time. */
int ret = sscanf(p + 6, "%x; %x", &next_date, &next_date_fract); int ret = sscanf(p + 6, "%x; %x", &next_date, &next_date_fract);
assert(ret == 2); assert(ret == 2);
DEBUG(net, 0, "injecting pause for join at %08x:%02x; please join when paused", next_date, next_date_fract); DEBUG(desync, 0, "Injecting pause for join at %08x:%02x; please join when paused", next_date, next_date_fract);
cp = CallocT<CommandPacket>(1); cp = CallocT<CommandPacket>(1);
cp->company = COMPANY_SPECTATOR; cp->company = COMPANY_SPECTATOR;
cp->cmd = CMD_PAUSE; cp->cmd = CMD_PAUSE;
@ -1117,16 +1117,16 @@ void NetworkGameLoop()
/* A message that is not very important to the log playback, but part of the log. */ /* A message that is not very important to the log playback, but part of the log. */
#ifndef DEBUG_FAILED_DUMP_COMMANDS #ifndef DEBUG_FAILED_DUMP_COMMANDS
} else if (strncmp(p, "cmdf: ", 6) == 0) { } else if (strncmp(p, "cmdf: ", 6) == 0) {
DEBUG(net, 0, "Skipping replay of failed command: %s", p + 6); DEBUG(desync, 0, "Skipping replay of failed command: %s", p + 6);
#endif #endif
} else { } else {
/* Can't parse a line; what's wrong here? */ /* Can't parse a line; what's wrong here? */
DEBUG(net, 0, "trying to parse: %s", p); DEBUG(desync, 0, "Trying to parse: %s", p);
NOT_REACHED(); NOT_REACHED();
} }
} }
if (f != nullptr && feof(f)) { if (f != nullptr && feof(f)) {
DEBUG(net, 0, "End of commands.log"); DEBUG(desync, 0, "End of commands.log");
fclose(f); fclose(f);
f = nullptr; f = nullptr;
} }
@ -1218,7 +1218,7 @@ public:
void OnConnect(SOCKET s) override void OnConnect(SOCKET s) override
{ {
DEBUG(net, 0, "Redirecting DEBUG() to %s", this->connection_string.c_str()); DEBUG(net, 3, "Redirecting DEBUG() to %s", this->connection_string.c_str());
extern SOCKET _debug_socket; extern SOCKET _debug_socket;
_debug_socket = s; _debug_socket = s;
@ -1233,7 +1233,7 @@ void NetworkStartDebugLog(const std::string &connection_string)
/** This tries to launch the network for a given OS */ /** This tries to launch the network for a given OS */
void NetworkStartUp() void NetworkStartUp()
{ {
DEBUG(net, 3, "[core] starting network..."); DEBUG(net, 3, "Starting network");
/* Network is available */ /* Network is available */
_network_available = NetworkCoreInitialize(); _network_available = NetworkCoreInitialize();
@ -1246,7 +1246,7 @@ void NetworkStartUp()
_network_game_info = {}; _network_game_info = {};
NetworkInitialize(); NetworkInitialize();
DEBUG(net, 3, "[core] network online, multiplayer available"); DEBUG(net, 3, "Network online, multiplayer available");
NetworkFindBroadcastIPs(&_broadcast_list); NetworkFindBroadcastIPs(&_broadcast_list);
} }
@ -1256,7 +1256,7 @@ void NetworkShutDown()
NetworkDisconnect(true); NetworkDisconnect(true);
NetworkUDPClose(); NetworkUDPClose();
DEBUG(net, 3, "[core] shutting down network"); DEBUG(net, 3, "Shutting down network");
_network_available = false; _network_available = false;

View File

@ -74,7 +74,7 @@ ServerNetworkAdminSocketHandler::ServerNetworkAdminSocketHandler(SOCKET s) : Net
ServerNetworkAdminSocketHandler::~ServerNetworkAdminSocketHandler() ServerNetworkAdminSocketHandler::~ServerNetworkAdminSocketHandler()
{ {
_network_admins_connected--; _network_admins_connected--;
DEBUG(net, 1, "[admin] '%s' (%s) has disconnected", this->admin_name, this->admin_version); DEBUG(net, 3, "[admin] '%s' (%s) has disconnected", this->admin_name, this->admin_version);
if (_redirect_console_to_admin == this->index) _redirect_console_to_admin = INVALID_ADMIN_ID; if (_redirect_console_to_admin == this->index) _redirect_console_to_admin = INVALID_ADMIN_ID;
} }
@ -97,7 +97,7 @@ ServerNetworkAdminSocketHandler::~ServerNetworkAdminSocketHandler()
{ {
for (ServerNetworkAdminSocketHandler *as : ServerNetworkAdminSocketHandler::Iterate()) { for (ServerNetworkAdminSocketHandler *as : ServerNetworkAdminSocketHandler::Iterate()) {
if (as->status == ADMIN_STATUS_INACTIVE && std::chrono::steady_clock::now() > as->connect_time + ADMIN_AUTHORISATION_TIMEOUT) { if (as->status == ADMIN_STATUS_INACTIVE && std::chrono::steady_clock::now() > as->connect_time + ADMIN_AUTHORISATION_TIMEOUT) {
DEBUG(net, 1, "[admin] Admin did not send its authorisation within %d seconds", (uint32)std::chrono::duration_cast<std::chrono::seconds>(ADMIN_AUTHORISATION_TIMEOUT).count()); DEBUG(net, 2, "[admin] Admin did not send its authorisation within %d seconds", (uint32)std::chrono::duration_cast<std::chrono::seconds>(ADMIN_AUTHORISATION_TIMEOUT).count());
as->CloseConnection(true); as->CloseConnection(true);
continue; continue;
} }
@ -137,7 +137,7 @@ NetworkRecvStatus ServerNetworkAdminSocketHandler::SendError(NetworkErrorCode er
StringID strid = GetNetworkErrorMsg(error); StringID strid = GetNetworkErrorMsg(error);
GetString(str, strid, lastof(str)); GetString(str, strid, lastof(str));
DEBUG(net, 1, "[admin] the admin '%s' (%s) made an error and has been disconnected. Reason: '%s'", this->admin_name, this->admin_version, str); DEBUG(net, 1, "[admin] The admin '%s' (%s) made an error and has been disconnected: '%s'", this->admin_name, this->admin_version, str);
return this->CloseConnection(true); return this->CloseConnection(true);
} }
@ -518,7 +518,7 @@ NetworkRecvStatus ServerNetworkAdminSocketHandler::Receive_ADMIN_RCON(Packet *p)
p->Recv_string(command, sizeof(command)); p->Recv_string(command, sizeof(command));
DEBUG(net, 2, "[admin] Rcon command from '%s' (%s): '%s'", this->admin_name, this->admin_version, command); DEBUG(net, 3, "[admin] Rcon command from '%s' (%s): %s", this->admin_name, this->admin_version, command);
_redirect_console_to_admin = this->index; _redirect_console_to_admin = this->index;
IConsoleCmdExec(command); IConsoleCmdExec(command);
@ -534,7 +534,7 @@ NetworkRecvStatus ServerNetworkAdminSocketHandler::Receive_ADMIN_GAMESCRIPT(Pack
p->Recv_string(json, sizeof(json)); p->Recv_string(json, sizeof(json));
DEBUG(net, 2, "[admin] GameScript JSON from '%s' (%s): '%s'", this->admin_name, this->admin_version, json); DEBUG(net, 6, "[admin] GameScript JSON from '%s' (%s): %s", this->admin_name, this->admin_version, json);
Game::NewEvent(new ScriptEventAdminPort(json)); Game::NewEvent(new ScriptEventAdminPort(json));
return NETWORK_RECV_STATUS_OKAY; return NETWORK_RECV_STATUS_OKAY;
@ -546,7 +546,7 @@ NetworkRecvStatus ServerNetworkAdminSocketHandler::Receive_ADMIN_PING(Packet *p)
uint32 d1 = p->Recv_uint32(); uint32 d1 = p->Recv_uint32();
DEBUG(net, 2, "[admin] Ping from '%s' (%s): '%d'", this->admin_name, this->admin_version, d1); DEBUG(net, 6, "[admin] Ping from '%s' (%s): %d", this->admin_name, this->admin_version, d1);
return this->SendPong(d1); return this->SendPong(d1);
} }
@ -683,7 +683,7 @@ NetworkRecvStatus ServerNetworkAdminSocketHandler::Receive_ADMIN_JOIN(Packet *p)
this->status = ADMIN_STATUS_ACTIVE; this->status = ADMIN_STATUS_ACTIVE;
DEBUG(net, 1, "[admin] '%s' (%s) has connected", this->admin_name, this->admin_version); DEBUG(net, 3, "[admin] '%s' (%s) has connected", this->admin_name, this->admin_version);
return this->SendProtocol(); return this->SendProtocol();
} }
@ -703,7 +703,7 @@ NetworkRecvStatus ServerNetworkAdminSocketHandler::Receive_ADMIN_UPDATE_FREQUENC
if (type >= ADMIN_UPDATE_END || (_admin_update_type_frequencies[type] & freq) != freq) { if (type >= ADMIN_UPDATE_END || (_admin_update_type_frequencies[type] & freq) != freq) {
/* The server does not know of this UpdateType. */ /* The server does not know of this UpdateType. */
DEBUG(net, 3, "[admin] Not supported update frequency %d (%d) from '%s' (%s).", type, freq, this->admin_name, this->admin_version); DEBUG(net, 1, "[admin] Not supported update frequency %d (%d) from '%s' (%s)", type, freq, this->admin_name, this->admin_version);
return this->SendError(NETWORK_ERROR_ILLEGAL_PACKET); return this->SendError(NETWORK_ERROR_ILLEGAL_PACKET);
} }
@ -771,7 +771,7 @@ NetworkRecvStatus ServerNetworkAdminSocketHandler::Receive_ADMIN_POLL(Packet *p)
default: default:
/* An unsupported "poll" update type. */ /* An unsupported "poll" update type. */
DEBUG(net, 3, "[admin] Not supported poll %d (%d) from '%s' (%s).", type, d1, this->admin_name, this->admin_version); DEBUG(net, 1, "[admin] Not supported poll %d (%d) from '%s' (%s).", type, d1, this->admin_name, this->admin_version);
return this->SendError(NETWORK_ERROR_ILLEGAL_PACKET); return this->SendError(NETWORK_ERROR_ILLEGAL_PACKET);
} }
@ -798,7 +798,7 @@ NetworkRecvStatus ServerNetworkAdminSocketHandler::Receive_ADMIN_CHAT(Packet *p)
break; break;
default: default:
DEBUG(net, 3, "[admin] Invalid chat action %d from admin '%s' (%s).", action, this->admin_name, this->admin_version); DEBUG(net, 1, "[admin] Invalid chat action %d from admin '%s' (%s).", action, this->admin_name, this->admin_version);
return this->SendError(NETWORK_ERROR_ILLEGAL_PACKET); return this->SendError(NETWORK_ERROR_ILLEGAL_PACKET);
} }

View File

@ -136,7 +136,7 @@ void ClientNetworkEmergencySave()
if (!_networking) return; if (!_networking) return;
const char *filename = "netsave.sav"; const char *filename = "netsave.sav";
DEBUG(net, 0, "Client: Performing emergency save (%s)", filename); DEBUG(net, 3, "Performing emergency save: %s", filename);
SaveOrLoad(filename, SLO_SAVE, DFT_GAME_FILE, AUTOSAVE_DIR, false); SaveOrLoad(filename, SLO_SAVE, DFT_GAME_FILE, AUTOSAVE_DIR, false);
} }
@ -172,7 +172,7 @@ NetworkRecvStatus ClientNetworkGameSocketHandler::CloseConnection(NetworkRecvSta
*/ */
if (this->sock == INVALID_SOCKET) return status; if (this->sock == INVALID_SOCKET) return status;
DEBUG(net, 1, "Closed client connection %d", this->client_id); DEBUG(net, 3, "Closed client connection %d", this->client_id);
this->SendPackets(true); this->SendPackets(true);
@ -286,7 +286,7 @@ void ClientNetworkGameSocketHandler::ClientError(NetworkRecvStatus res)
#endif #endif
ShowNetworkError(STR_NETWORK_ERROR_DESYNC); ShowNetworkError(STR_NETWORK_ERROR_DESYNC);
DEBUG(desync, 1, "sync_err: %08x; %02x", _date, _date_fract); DEBUG(desync, 1, "sync_err: %08x; %02x", _date, _date_fract);
DEBUG(net, 0, "Sync error detected!"); DEBUG(net, 0, "Sync error detected");
my_client->ClientError(NETWORK_RECV_STATUS_DESYNC); my_client->ClientError(NETWORK_RECV_STATUS_DESYNC);
return false; return false;
} }
@ -301,7 +301,7 @@ void ClientNetworkGameSocketHandler::ClientError(NetworkRecvStatus res)
_sync_frame = 0; _sync_frame = 0;
} else if (_sync_frame < _frame_counter) { } else if (_sync_frame < _frame_counter) {
DEBUG(net, 1, "Missed frame for sync-test (%d / %d)", _sync_frame, _frame_counter); DEBUG(net, 1, "Missed frame for sync-test: %d / %d", _sync_frame, _frame_counter);
_sync_frame = 0; _sync_frame = 0;
} }
} }
@ -978,13 +978,13 @@ NetworkRecvStatus ClientNetworkGameSocketHandler::Receive_SERVER_FRAME(Packet *p
/* Receive the token. */ /* Receive the token. */
if (p->CanReadFromPacket(sizeof(uint8))) this->token = p->Recv_uint8(); if (p->CanReadFromPacket(sizeof(uint8))) this->token = p->Recv_uint8();
DEBUG(net, 5, "Received FRAME %d", _frame_counter_server); DEBUG(net, 7, "Received FRAME %d", _frame_counter_server);
/* Let the server know that we received this frame correctly /* Let the server know that we received this frame correctly
* We do this only once per day, to save some bandwidth ;) */ * We do this only once per day, to save some bandwidth ;) */
if (!_network_first_time && last_ack_frame < _frame_counter) { if (!_network_first_time && last_ack_frame < _frame_counter) {
last_ack_frame = _frame_counter + DAY_TICKS; last_ack_frame = _frame_counter + DAY_TICKS;
DEBUG(net, 4, "Sent ACK at %d", _frame_counter); DEBUG(net, 7, "Sent ACK at %d", _frame_counter);
SendAck(); SendAck();
} }
@ -1100,7 +1100,7 @@ NetworkRecvStatus ClientNetworkGameSocketHandler::Receive_SERVER_QUIT(Packet *p)
NetworkTextMessage(NETWORK_ACTION_LEAVE, CC_DEFAULT, false, ci->client_name, nullptr, STR_NETWORK_MESSAGE_CLIENT_LEAVING); NetworkTextMessage(NETWORK_ACTION_LEAVE, CC_DEFAULT, false, ci->client_name, nullptr, STR_NETWORK_MESSAGE_CLIENT_LEAVING);
delete ci; delete ci;
} else { } else {
DEBUG(net, 0, "Unknown client (%d) is leaving the game", client_id); DEBUG(net, 1, "Unknown client (%d) is leaving the game", client_id);
} }
InvalidateWindowData(WC_CLIENT_LIST, 0); InvalidateWindowData(WC_CLIENT_LIST, 0);
@ -1180,7 +1180,7 @@ NetworkRecvStatus ClientNetworkGameSocketHandler::Receive_SERVER_MOVE(Packet *p)
if (client_id == 0) { if (client_id == 0) {
/* definitely an invalid client id, debug message and do nothing. */ /* definitely an invalid client id, debug message and do nothing. */
DEBUG(net, 0, "[move] received invalid client index = 0"); DEBUG(net, 1, "Received invalid client index = 0");
return NETWORK_RECV_STATUS_MALFORMED_PACKET; return NETWORK_RECV_STATUS_MALFORMED_PACKET;
} }

View File

@ -333,7 +333,7 @@ void NetworkGameSocketHandler::SendCommand(Packet *p, const CommandPacket *cp)
} }
if (callback == lengthof(_callback_table)) { if (callback == lengthof(_callback_table)) {
DEBUG(net, 0, "Unknown callback. (Pointer: %p) No callback sent", cp->callback); DEBUG(net, 0, "Unknown callback for command; no callback sent (command: %d)", cp->cmd);
callback = 0; // _callback_table[0] == nullptr callback = 0; // _callback_table[0] == nullptr
} }
p->Send_uint8 (callback); p->Send_uint8 (callback);

View File

@ -112,7 +112,6 @@ void NetworkGameListRemoveItem(NetworkGameList *remove)
ClearGRFConfigList(&remove->info.grfconfig); ClearGRFConfigList(&remove->info.grfconfig);
delete remove; delete remove;
DEBUG(net, 4, "[gamelist] removed server from list");
NetworkRebuildHostList(); NetworkRebuildHostList();
UpdateNetworkGameWindow(); UpdateNetworkGameWindow();
return; return;

View File

@ -283,7 +283,7 @@ NetworkRecvStatus ServerNetworkGameSocketHandler::CloseConnection(NetworkRecvSta
} }
NetworkAdminClientError(this->client_id, NETWORK_ERROR_CONNECTION_LOST); NetworkAdminClientError(this->client_id, NETWORK_ERROR_CONNECTION_LOST);
DEBUG(net, 1, "Closed client connection %d", this->client_id); DEBUG(net, 3, "Closed client connection %d", this->client_id);
/* We just lost one client :( */ /* We just lost one client :( */
if (this->status >= STATUS_AUTHORIZED) _network_game_info.clients_on--; if (this->status >= STATUS_AUTHORIZED) _network_game_info.clients_on--;
@ -448,7 +448,7 @@ NetworkRecvStatus ServerNetworkGameSocketHandler::SendError(NetworkErrorCode err
this->GetClientName(client_name, lastof(client_name)); this->GetClientName(client_name, lastof(client_name));
DEBUG(net, 1, "'%s' made an error and has been disconnected. Reason: '%s'", client_name, str); DEBUG(net, 1, "'%s' made an error and has been disconnected: %s", client_name, str);
if (error == NETWORK_ERROR_KICKED && reason != nullptr) { if (error == NETWORK_ERROR_KICKED && reason != nullptr) {
NetworkTextMessage(NETWORK_ACTION_KICKED, CC_DEFAULT, false, client_name, reason, strid); NetworkTextMessage(NETWORK_ACTION_KICKED, CC_DEFAULT, false, client_name, reason, strid);
@ -469,7 +469,7 @@ NetworkRecvStatus ServerNetworkGameSocketHandler::SendError(NetworkErrorCode err
NetworkAdminClientError(this->client_id, error); NetworkAdminClientError(this->client_id, error);
} else { } else {
DEBUG(net, 1, "Client %d made an error and has been disconnected. Reason: '%s'", this->client_id, str); DEBUG(net, 1, "Client %d made an error and has been disconnected: %s", this->client_id, str);
} }
/* The client made a mistake, so drop his connection now! */ /* The client made a mistake, so drop his connection now! */
@ -1144,7 +1144,7 @@ NetworkRecvStatus ServerNetworkGameSocketHandler::Receive_CLIENT_ERROR(Packet *p
StringID strid = GetNetworkErrorMsg(errorno); StringID strid = GetNetworkErrorMsg(errorno);
GetString(str, strid, lastof(str)); GetString(str, strid, lastof(str));
DEBUG(net, 2, "'%s' reported an error and is closing its connection (%s)", client_name, str); DEBUG(net, 1, "'%s' reported an error and is closing its connection: %s", client_name, str);
NetworkTextMessage(NETWORK_ACTION_LEAVE, CC_DEFAULT, false, client_name, nullptr, strid); NetworkTextMessage(NETWORK_ACTION_LEAVE, CC_DEFAULT, false, client_name, nullptr, strid);
@ -1335,7 +1335,7 @@ void NetworkServerSendChat(NetworkAction action, DestType desttype, int dest, co
break; break;
} }
default: default:
DEBUG(net, 0, "[server] received unknown chat destination type %d. Doing broadcast instead", desttype); DEBUG(net, 1, "Received unknown chat destination type %d; doing broadcast instead", desttype);
FALLTHROUGH; FALLTHROUGH;
case DESTTYPE_BROADCAST: case DESTTYPE_BROADCAST:
@ -1445,11 +1445,11 @@ NetworkRecvStatus ServerNetworkGameSocketHandler::Receive_CLIENT_RCON(Packet *p)
p->Recv_string(command, sizeof(command)); p->Recv_string(command, sizeof(command));
if (strcmp(pass, _settings_client.network.rcon_password) != 0) { if (strcmp(pass, _settings_client.network.rcon_password) != 0) {
DEBUG(net, 0, "[rcon] wrong password from client-id %d", this->client_id); DEBUG(net, 1, "[rcon] Wrong password from client-id %d", this->client_id);
return NETWORK_RECV_STATUS_OKAY; return NETWORK_RECV_STATUS_OKAY;
} }
DEBUG(net, 0, "[rcon] client-id %d executed: '%s'", this->client_id, command); DEBUG(net, 3, "[rcon] Client-id %d executed: %s", this->client_id, command);
_redirect_console_to_client = this->client_id; _redirect_console_to_client = this->client_id;
IConsoleCmdExec(command); IConsoleCmdExec(command);
@ -1474,7 +1474,7 @@ NetworkRecvStatus ServerNetworkGameSocketHandler::Receive_CLIENT_MOVE(Packet *p)
/* Incorrect password sent, return! */ /* Incorrect password sent, return! */
if (strcmp(password, _network_company_states[company_id].password) != 0) { if (strcmp(password, _network_company_states[company_id].password) != 0) {
DEBUG(net, 2, "[move] wrong password from client-id #%d for company #%d", this->client_id, company_id + 1); DEBUG(net, 2, "Wrong password from client-id #%d for company #%d", this->client_id, company_id + 1);
return NETWORK_RECV_STATUS_OKAY; return NETWORK_RECV_STATUS_OKAY;
} }
} }
@ -1597,7 +1597,7 @@ void NetworkUpdateClientInfo(ClientID client_id)
static void NetworkCheckRestartMap() static void NetworkCheckRestartMap()
{ {
if (_settings_client.network.restart_game_year != 0 && _cur_year >= _settings_client.network.restart_game_year) { if (_settings_client.network.restart_game_year != 0 && _cur_year >= _settings_client.network.restart_game_year) {
DEBUG(net, 0, "Auto-restarting map. Year %d reached", _cur_year); DEBUG(net, 3, "Auto-restarting map: year %d reached", _cur_year);
_settings_newgame.game_creation.generation_seed = GENERATE_NEW_SEED; _settings_newgame.game_creation.generation_seed = GENERATE_NEW_SEED;
switch(_file_to_saveload.abstract_ftype) { switch(_file_to_saveload.abstract_ftype) {

View File

@ -67,7 +67,7 @@ struct UDPSocket {
std::unique_lock<std::mutex> lock(mutex, std::defer_lock); std::unique_lock<std::mutex> lock(mutex, std::defer_lock);
if (!lock.try_lock()) { if (!lock.try_lock()) {
if (++receive_iterations_locked % 32 == 0) { if (++receive_iterations_locked % 32 == 0) {
DEBUG(net, 0, "[udp] %s background UDP loop processing appears to be blocked. Your OS may be low on UDP send buffers.", name.c_str()); DEBUG(net, 0, "%s background UDP loop processing appears to be blocked. Your OS may be low on UDP send buffers.", name.c_str());
} }
return; return;
} }
@ -133,7 +133,7 @@ public:
void MasterNetworkUDPSocketHandler::Receive_MASTER_ACK_REGISTER(Packet *p, NetworkAddress *client_addr) void MasterNetworkUDPSocketHandler::Receive_MASTER_ACK_REGISTER(Packet *p, NetworkAddress *client_addr)
{ {
_network_advertise_retries = 0; _network_advertise_retries = 0;
DEBUG(net, 2, "[udp] advertising on master server successful (%s)", NetworkAddress::AddressFamilyAsString(client_addr->GetAddress()->ss_family)); DEBUG(net, 3, "Advertising on master server successful (%s)", NetworkAddress::AddressFamilyAsString(client_addr->GetAddress()->ss_family));
/* We are advertised, but we don't want to! */ /* We are advertised, but we don't want to! */
if (!_settings_client.network.server_advertise) NetworkUDPRemoveAdvertise(false); if (!_settings_client.network.server_advertise) NetworkUDPRemoveAdvertise(false);
@ -142,7 +142,7 @@ void MasterNetworkUDPSocketHandler::Receive_MASTER_ACK_REGISTER(Packet *p, Netwo
void MasterNetworkUDPSocketHandler::Receive_MASTER_SESSION_KEY(Packet *p, NetworkAddress *client_addr) void MasterNetworkUDPSocketHandler::Receive_MASTER_SESSION_KEY(Packet *p, NetworkAddress *client_addr)
{ {
_session_key = p->Recv_uint64(); _session_key = p->Recv_uint64();
DEBUG(net, 2, "[udp] received new session key from master server (%s)", NetworkAddress::AddressFamilyAsString(client_addr->GetAddress()->ss_family)); DEBUG(net, 6, "Received new session key from master server (%s)", NetworkAddress::AddressFamilyAsString(client_addr->GetAddress()->ss_family));
} }
///*** Communication with clients (we are server) ***/ ///*** Communication with clients (we are server) ***/
@ -175,7 +175,7 @@ void ServerNetworkUDPSocketHandler::Receive_CLIENT_FIND_SERVER(Packet *p, Networ
/* Let the client know that we are here */ /* Let the client know that we are here */
this->SendPacket(&packet, client_addr); this->SendPacket(&packet, client_addr);
DEBUG(net, 2, "[udp] queried from %s", client_addr->GetHostname()); DEBUG(net, 7, "Queried from %s", client_addr->GetHostname());
} }
void ServerNetworkUDPSocketHandler::Receive_CLIENT_DETAIL_INFO(Packet *p, NetworkAddress *client_addr) void ServerNetworkUDPSocketHandler::Receive_CLIENT_DETAIL_INFO(Packet *p, NetworkAddress *client_addr)
@ -252,7 +252,7 @@ void ServerNetworkUDPSocketHandler::Receive_CLIENT_GET_NEWGRFS(Packet *p, Networ
uint8 in_reply_count = 0; uint8 in_reply_count = 0;
size_t packet_len = 0; size_t packet_len = 0;
DEBUG(net, 6, "[udp] newgrf data request from %s", client_addr->GetAddressAsString().c_str()); DEBUG(net, 7, "NewGRF data request from %s", client_addr->GetAddressAsString().c_str());
num_grfs = p->Recv_uint8 (); num_grfs = p->Recv_uint8 ();
if (num_grfs > NETWORK_MAX_GRF_COUNT) return; if (num_grfs > NETWORK_MAX_GRF_COUNT) return;
@ -314,7 +314,7 @@ void ClientNetworkUDPSocketHandler::Receive_SERVER_RESPONSE(Packet *p, NetworkAd
/* Just a fail-safe.. should never happen */ /* Just a fail-safe.. should never happen */
if (_network_udp_server) return; if (_network_udp_server) return;
DEBUG(net, 4, "[udp] server response from %s", client_addr->GetAddressAsString().c_str()); DEBUG(net, 3, "Server response from %s", client_addr->GetAddressAsString().c_str());
/* Find next item */ /* Find next item */
item = NetworkGameListAddItem(client_addr->GetAddressAsString(false)); item = NetworkGameListAddItem(client_addr->GetAddressAsString(false));
@ -409,7 +409,7 @@ void ClientNetworkUDPSocketHandler::Receive_SERVER_NEWGRFS(Packet *p, NetworkAdd
uint8 num_grfs; uint8 num_grfs;
uint i; uint i;
DEBUG(net, 6, "[udp] newgrf data reply from %s", client_addr->GetAddressAsString().c_str()); DEBUG(net, 7, "NewGRF data reply from %s", client_addr->GetAddressAsString().c_str());
num_grfs = p->Recv_uint8 (); num_grfs = p->Recv_uint8 ();
if (num_grfs > NETWORK_MAX_GRF_COUNT) return; if (num_grfs > NETWORK_MAX_GRF_COUNT) return;
@ -441,7 +441,7 @@ static void NetworkUDPBroadCast(NetworkUDPSocketHandler *socket)
for (NetworkAddress &addr : _broadcast_list) { for (NetworkAddress &addr : _broadcast_list) {
Packet p(PACKET_UDP_CLIENT_FIND_SERVER); Packet p(PACKET_UDP_CLIENT_FIND_SERVER);
DEBUG(net, 4, "[udp] broadcasting to %s", addr.GetHostname()); DEBUG(net, 5, "Broadcasting to %s", addr.GetHostname());
socket->SendPacket(&p, &addr, true, true); socket->SendPacket(&p, &addr, true, true);
} }
@ -461,7 +461,7 @@ void NetworkUDPQueryMasterServer()
std::lock_guard<std::mutex> lock(_udp_client.mutex); std::lock_guard<std::mutex> lock(_udp_client.mutex);
_udp_client.socket->SendPacket(&p, &out_addr, true); _udp_client.socket->SendPacket(&p, &out_addr, true);
DEBUG(net, 2, "[udp] master server queried at %s", out_addr.GetAddressAsString().c_str()); DEBUG(net, 6, "Master server queried at %s", out_addr.GetAddressAsString().c_str());
} }
/** Find all servers */ /** Find all servers */
@ -470,7 +470,7 @@ void NetworkUDPSearchGame()
/* We are still searching.. */ /* We are still searching.. */
if (_network_udp_broadcast > 0) return; if (_network_udp_broadcast > 0) return;
DEBUG(net, 0, "[udp] searching server"); DEBUG(net, 3, "Searching server");
NetworkUDPBroadCast(_udp_client.socket); NetworkUDPBroadCast(_udp_client.socket);
_network_udp_broadcast = 300; // Stay searching for 300 ticks _network_udp_broadcast = 300; // Stay searching for 300 ticks
@ -481,7 +481,7 @@ void NetworkUDPSearchGame()
*/ */
static void NetworkUDPRemoveAdvertiseThread() static void NetworkUDPRemoveAdvertiseThread()
{ {
DEBUG(net, 1, "[udp] removing advertise from master server"); DEBUG(net, 3, "Removing advertise from master server");
/* Find somewhere to send */ /* Find somewhere to send */
NetworkAddress out_addr(NETWORK_MASTER_SERVER_HOST, NETWORK_MASTER_SERVER_PORT); NetworkAddress out_addr(NETWORK_MASTER_SERVER_HOST, NETWORK_MASTER_SERVER_PORT);
@ -518,22 +518,22 @@ static void NetworkUDPAdvertiseThread()
/* Find somewhere to send */ /* Find somewhere to send */
NetworkAddress out_addr(NETWORK_MASTER_SERVER_HOST, NETWORK_MASTER_SERVER_PORT); NetworkAddress out_addr(NETWORK_MASTER_SERVER_HOST, NETWORK_MASTER_SERVER_PORT);
DEBUG(net, 1, "[udp] advertising to master server"); DEBUG(net, 3, "Advertising to master server");
/* Add a bit more messaging when we cannot get a session key */ /* Add a bit more messaging when we cannot get a session key */
static byte session_key_retries = 0; static byte session_key_retries = 0;
if (_session_key == 0 && session_key_retries++ == 2) { if (_session_key == 0 && session_key_retries++ == 2) {
DEBUG(net, 0, "[udp] advertising to the master server is failing"); DEBUG(net, 0, "Advertising to the master server is failing");
DEBUG(net, 0, "[udp] we are not receiving the session key from the server"); DEBUG(net, 0, " we are not receiving the session key from the server");
DEBUG(net, 0, "[udp] please allow udp packets from %s to you to be delivered", out_addr.GetAddressAsString(false).c_str()); DEBUG(net, 0, " please allow udp packets from %s to you to be delivered", out_addr.GetAddressAsString(false).c_str());
DEBUG(net, 0, "[udp] please allow udp packets from you to %s to be delivered", out_addr.GetAddressAsString(false).c_str()); DEBUG(net, 0, " please allow udp packets from you to %s to be delivered", out_addr.GetAddressAsString(false).c_str());
} }
if (_session_key != 0 && _network_advertise_retries == 0) { if (_session_key != 0 && _network_advertise_retries == 0) {
DEBUG(net, 0, "[udp] advertising to the master server is failing"); DEBUG(net, 0, "Advertising to the master server is failing");
DEBUG(net, 0, "[udp] we are not receiving the acknowledgement from the server"); DEBUG(net, 0, " we are not receiving the acknowledgement from the server");
DEBUG(net, 0, "[udp] this usually means that the master server cannot reach us"); DEBUG(net, 0, " this usually means that the master server cannot reach us");
DEBUG(net, 0, "[udp] please allow udp and tcp packets to port %u to be delivered", _settings_client.network.server_port); DEBUG(net, 0, " please allow udp and tcp packets to port %u to be delivered", _settings_client.network.server_port);
DEBUG(net, 0, "[udp] please allow udp and tcp packets from port %u to be delivered", _settings_client.network.server_port); DEBUG(net, 0, " please allow udp and tcp packets from port %u to be delivered", _settings_client.network.server_port);
} }
/* Send the packet */ /* Send the packet */
@ -589,7 +589,7 @@ void NetworkUDPInitialize()
/* If not closed, then do it. */ /* If not closed, then do it. */
if (_udp_server.socket != nullptr) NetworkUDPClose(); if (_udp_server.socket != nullptr) NetworkUDPClose();
DEBUG(net, 1, "[udp] initializing listeners"); DEBUG(net, 3, "Initializing UDP listeners");
assert(_udp_client.socket == nullptr && _udp_server.socket == nullptr && _udp_master.socket == nullptr); assert(_udp_client.socket == nullptr && _udp_server.socket == nullptr && _udp_master.socket == nullptr);
std::scoped_lock lock(_udp_client.mutex, _udp_server.mutex, _udp_master.mutex); std::scoped_lock lock(_udp_client.mutex, _udp_server.mutex, _udp_master.mutex);
@ -625,7 +625,7 @@ void NetworkUDPClose()
_network_udp_server = false; _network_udp_server = false;
_network_udp_broadcast = 0; _network_udp_broadcast = 0;
DEBUG(net, 1, "[udp] closed listeners"); DEBUG(net, 5, "Closed UDP listeners");
} }
/** Receive the UDP packets. */ /** Receive the UDP packets. */

View File

@ -560,7 +560,7 @@ int openttd_main(int argc, char *argv[])
videodriver = "dedicated"; videodriver = "dedicated";
blitter = "null"; blitter = "null";
dedicated = true; dedicated = true;
SetDebugString("net=6"); SetDebugString("net=4");
if (mgo.opt != nullptr) { if (mgo.opt != nullptr) {
scanner->dedicated_host = ParseFullConnectionString(mgo.opt, scanner->dedicated_port); scanner->dedicated_host = ParseFullConnectionString(mgo.opt, scanner->dedicated_port);
} }
@ -666,7 +666,7 @@ int openttd_main(int argc, char *argv[])
DeterminePaths(argv[0]); DeterminePaths(argv[0]);
TarScanner::DoScan(TarScanner::BASESET); TarScanner::DoScan(TarScanner::BASESET);
if (dedicated) DEBUG(net, 0, "Starting dedicated version %s", _openttd_revision); if (dedicated) DEBUG(net, 3, "Starting dedicated server, version %s", _openttd_revision);
if (_dedicated_forks && !dedicated) _dedicated_forks = false; if (_dedicated_forks && !dedicated) _dedicated_forks = false;
#if defined(UNIX) #if defined(UNIX)
@ -945,7 +945,7 @@ bool SafeLoad(const std::string &filename, SaveLoadOperation fop, DetailedFileTy
* special cases which make clients desync immediately. So we fall * special cases which make clients desync immediately. So we fall
* back to just generating a new game with the current settings. * back to just generating a new game with the current settings.
*/ */
DEBUG(net, 0, "Loading game failed, so a new (random) game will be started!"); DEBUG(net, 0, "Loading game failed, so a new (random) game will be started");
MakeNewGame(false, true); MakeNewGame(false, true);
return false; return false;
} }

View File

@ -566,8 +566,8 @@ bool AfterLoadGame()
if (IsSavegameVersionBefore(SLV_119)) { if (IsSavegameVersionBefore(SLV_119)) {
_pause_mode = (_pause_mode == 2) ? PM_PAUSED_NORMAL : PM_UNPAUSED; _pause_mode = (_pause_mode == 2) ? PM_PAUSED_NORMAL : PM_UNPAUSED;
} else if (_network_dedicated && (_pause_mode & PM_PAUSED_ERROR) != 0) { } else if (_network_dedicated && (_pause_mode & PM_PAUSED_ERROR) != 0) {
DEBUG(net, 0, "The loading savegame was paused due to an error state."); DEBUG(net, 0, "The loading savegame was paused due to an error state");
DEBUG(net, 0, " The savegame cannot be used for multiplayer!"); DEBUG(net, 0, " This savegame cannot be used for multiplayer");
/* Restore the signals */ /* Restore the signals */
ResetSignalHandlers(); ResetSignalHandlers();
return false; return false;

View File

@ -256,7 +256,7 @@ void VideoDriver_Dedicated::MainLoop()
* intro game... */ * intro game... */
if (SaveOrLoad(_file_to_saveload.name, _file_to_saveload.file_op, _file_to_saveload.detail_ftype, BASE_DIR) == SL_ERROR) { if (SaveOrLoad(_file_to_saveload.name, _file_to_saveload.file_op, _file_to_saveload.detail_ftype, BASE_DIR) == SL_ERROR) {
/* Loading failed, pop out.. */ /* Loading failed, pop out.. */
DEBUG(net, 0, "Loading requested map failed, aborting"); DEBUG(net, 0, "Loading requested map failed; closing server.");
return; return;
} else { } else {
/* We can load this game, so go ahead */ /* We can load this game, so go ahead */