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

src/genworld.cpp

@@ -91,7 +91,7 @@ static void _GenerateWorld()
 
 	try {
 		_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 */
 		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);
@@ -188,7 +188,7 @@ static void _GenerateWorld()
 
 		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);
 
 		if (_debug_desync_level > 0) {
@@ -204,7 +204,7 @@ static void _GenerateWorld()
 
 		if (_network_dedicated) {
 			/* 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;
 		} else {
 			SwitchToMode(_switch_mode);

src/genworld_gui.cpp

@@ -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% */
 		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;
 
 		return;

src/network/core/address.cpp

@@ -356,7 +356,7 @@ static SOCKET ListenLoopProc(addrinfo *runp)
 		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;
 }
 

src/network/core/core.cpp

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

src/network/core/game_info.cpp

@@ -51,7 +51,7 @@ const char *GetNetworkRevisionString()
 
 		/* Tag names are not mangled further. */
 		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;
 		}
 
@@ -71,7 +71,7 @@ const char *GetNetworkRevisionString()
 		/* Replace the git hash in revision string. */
 		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
-		DEBUG(net, 1, "Network revision name is '%s'", network_revision);
+		DEBUG(net, 3, "Network revision name: %s", network_revision);
 	}
 
 	return network_revision;

src/network/core/host.cpp

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

src/network/core/tcp.cpp

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

src/network/core/tcp_admin.cpp

@@ -93,9 +93,9 @@ NetworkRecvStatus NetworkAdminSocketHandler::HandlePacket(Packet *p)
 
 		default:
 			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 {
-				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();
@@ -129,7 +129,7 @@ NetworkRecvStatus NetworkAdminSocketHandler::ReceivePackets()
  */
 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;
 }
 

src/network/core/tcp_connect.cpp

@@ -72,7 +72,7 @@ void TCPConnecter::Connect(addrinfo *address)
 	}
 
 	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);
 	if (err != 0 && !NetworkError::GetLast().IsConnectInProgress()) {
@@ -149,10 +149,10 @@ void TCPConnecter::OnResolved(addrinfo *ai)
 		}
 	}
 
-	if (_debug_net_level >= 5) {
-		DEBUG(net, 5, "%s resolved in:", this->connection_string.c_str());
+	if (_debug_net_level >= 6) {
+		DEBUG(net, 6, "%s resolved in:", this->connection_string.c_str());
 		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) {
-		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();
 		return;
 	}
@@ -235,7 +235,7 @@ bool TCPConnecter::CheckActivity()
 	/* select() failed; hopefully next try it doesn't. */
 	if (n < 0) {
 		/* 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;
 	}
 
@@ -301,7 +301,7 @@ bool TCPConnecter::CheckActivity()
 	}
 	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) {
 		DEBUG(net, 5, "- using %s", NetworkAddress::GetPeerName(connected_socket).c_str());
 	}

src/network/core/tcp_content.cpp

@@ -167,9 +167,9 @@ bool NetworkContentSocketHandler::HandlePacket(Packet *p)
 
 		default:
 			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 {
-				DEBUG(net, 0, "[tcp/content] received illegal packet");
+				DEBUG(net, 0, "[tcp/content] Received illegal packet");
 			}
 			return false;
 	}
@@ -220,7 +220,7 @@ bool NetworkContentSocketHandler::ReceivePackets()
  */
 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;
 }
 

src/network/core/tcp_game.cpp

@@ -117,9 +117,9 @@ NetworkRecvStatus NetworkGameSocketHandler::HandlePacket(Packet *p)
 			this->CloseConnection();
 
 			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 {
-				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;
 	}
@@ -151,7 +151,7 @@ NetworkRecvStatus NetworkGameSocketHandler::ReceivePackets()
  */
 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;
 }
 

src/network/core/tcp_http.cpp

@@ -45,7 +45,7 @@ NetworkHTTPSocketHandler::NetworkHTTPSocketHandler(SOCKET s,
 	size_t bufferSize = strlen(url) + strlen(host) + strlen(GetNetworkRevisionString()) + (data == nullptr ? 0 : strlen(data)) + 128;
 	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) {
 		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 {
@@ -85,7 +85,7 @@ NetworkRecvStatus NetworkHTTPSocketHandler::CloseConnection(bool error)
  * Helper to simplify the error handling.
  * @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 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 */
 	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) {
-		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);
@@ -121,7 +121,7 @@ int NetworkHTTPSocketHandler::HandleHeader()
 
 		/* Get the length of the document to receive */
 		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 */
 		length += strlen(CONTENT_LENGTH);
@@ -139,9 +139,9 @@ int NetworkHTTPSocketHandler::HandleHeader()
 		/* Make sure we're going to download at least something;
 		 * zero sized files are, for OpenTTD's purposes, always
 		 * 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;
 	}
 
@@ -154,15 +154,15 @@ int NetworkHTTPSocketHandler::HandleHeader()
 		/* Search the end of the line. This is safe because the header will
 		 * always end with two newlines. */
 		*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;
 	}
 
-	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 */
 	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);
 
@@ -171,7 +171,7 @@ int NetworkHTTPSocketHandler::HandleHeader()
 	char *end_of_line = strstr(uri, NEWLINE);
 	*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);
 	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)
 {
 	char *hname = strstr(uri, "://");
-	if (hname == nullptr) return_error("[tcp/http] invalid location");
+	if (hname == nullptr) return_error("[tcp/http] Invalid location");
 
 	hname += 3;
 
 	char *url = strchr(hname, '/');
-	if (url == nullptr) return_error("[tcp/http] invalid location");
+	if (url == nullptr) return_error("[tcp/http] Invalid location");
 
 	*url = '\0';
 
@@ -228,7 +228,7 @@ int NetworkHTTPSocketHandler::Receive()
 			NetworkError err = NetworkError::GetLast();
 			if (!err.WouldBlock()) {
 				/* 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;
 			}
 			/* Connection would block, so stop for now */
@@ -256,7 +256,7 @@ int NetworkHTTPSocketHandler::Receive()
 
 			if (end_of_header == nullptr) {
 				if (read == lengthof(this->recv_buffer)) {
-					DEBUG(net, 0, "[tcp/http] header too big");
+					DEBUG(net, 1, "[tcp/http] Header too big");
 					return -1;
 				}
 				this->recv_pos = read;

src/network/core/tcp_listen.h

@@ -49,7 +49,7 @@ class TCPListenHandler {
 			SetNonBlocking(s); // XXX error handling?
 
 			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?
 
@@ -61,10 +61,10 @@ class TCPListenHandler {
 					Packet p(Tban_packet);
 					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) {
-						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);
 					break;
@@ -81,7 +81,7 @@ class TCPListenHandler {
 				p.PrepareToSend();
 
 				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);
 
@@ -150,7 +150,7 @@ class TCPListenHandler {
 		}
 
 		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);
 			return false;
 		}
@@ -165,7 +165,7 @@ class TCPListenHandler {
 			closesocket(s.second);
 		}
 		sockets.clear();
-		DEBUG(net, 1, "[%s] closed listeners", Tsocket::GetName());
+		DEBUG(net, 5, "[%s] Closed listeners", Tsocket::GetName());
 	}
 };