(svn r16238) -Change: improve/clarify some network related debug "error" messages by adding more information to them. Also give some clues on how to fix certain issues (like failing advertising).

3 files changed, 77 insertions, 18 deletions

diff --git a/src/network/core/address.cpp b/src/network/core/address.cpp
index 54e7bc0d0..ecf7e2e1a 100644
--- a/src/network/core/address.cpp
+++ b/src/network/core/address.cpp
@@ -195,7 +195,8 @@ SOCKET NetworkAddress::Resolve(int family, int socktype, int flags, SocketList *
 
 	if (e != 0) {
 		if (func != ResolveLoopProc) {
-			DEBUG(net, 0, "getaddrinfo(%s, %s) failed: %s", this->hostname, port_name, FS2OTTD(gai_strerror(e)));
+			DEBUG(net, 0, "getaddrinfo for hostname \"%s\", port %s, address family %s and socket type %s failed: %s",
+				this->hostname, port_name, AddressFamilyAsString(family), SocketTypeAsString(socktype), FS2OTTD(gai_strerror(e)));
 		}
 		return INVALID_SOCKET;
 	}
@@ -235,22 +236,28 @@ SOCKET NetworkAddress::Resolve(int family, int socktype, int flags, SocketList *
  */
 static SOCKET ConnectLoopProc(addrinfo *runp)
 {
+	const char *type = NetworkAddress::SocketTypeAsString(runp->ai_socktype);
+	const char *family = NetworkAddress::AddressFamilyAsString(runp->ai_family);
+	const char *address = NetworkAddress(runp->ai_addr, (int)runp->ai_addrlen).GetAddressAsString();
+
 	SOCKET sock = socket(runp->ai_family, runp->ai_socktype, runp->ai_protocol);
 	if (sock == INVALID_SOCKET) {
-		DEBUG(net, 1, "Could not create socket: %s", strerror(errno));
+		DEBUG(net, 1, "[%s] could not create %s socket: %s", type, family, strerror(errno));
 		return INVALID_SOCKET;
 	}
 
-	if (!SetNoDelay(sock)) DEBUG(net, 1, "Setting TCP_NODELAY failed");
+	if (!SetNoDelay(sock)) DEBUG(net, 1, "[%s] setting TCP_NODELAY failed", type);
 
 	if (connect(sock, runp->ai_addr, (int)runp->ai_addrlen) != 0) {
-		DEBUG(net, 1, "Could not connect socket: %s", strerror(errno));
+		DEBUG(net, 1, "[%s] could not connect %s socket: %s", type, family, strerror(errno));
 		closesocket(sock);
 		return INVALID_SOCKET;
 	}
 
 	/* Connection succeeded */
-	if (!SetNonBlocking(sock)) DEBUG(net, 0, "Setting non-blocking mode failed");
+	if (!SetNonBlocking(sock)) DEBUG(net, 0, "[%s] setting non-blocking mode failed", type);
+
+	DEBUG(net, 1, "[%s] connected to %s", type, address);
 
 	return sock;
 }
@@ -259,7 +266,7 @@ SOCKET NetworkAddress::Connect()
 {
 	DEBUG(net, 1, "Connecting to %s", this->GetAddressAsString());
 
-	return this->Resolve(0, SOCK_STREAM, AI_ADDRCONFIG, NULL, ConnectLoopProc);
+	return this->Resolve(AF_UNSPEC, SOCK_STREAM, AI_ADDRCONFIG, NULL, ConnectLoopProc);
 }
 
 /**
@@ -269,46 +276,47 @@ SOCKET NetworkAddress::Connect()
  */
 static SOCKET ListenLoopProc(addrinfo *runp)
 {
-	const char *type = runp->ai_socktype == SOCK_STREAM ? "tcp" : "udp";
+	const char *type = NetworkAddress::SocketTypeAsString(runp->ai_socktype);
+	const char *family = NetworkAddress::AddressFamilyAsString(runp->ai_family);
 	const char *address = NetworkAddress(runp->ai_addr, (int)runp->ai_addrlen).GetAddressAsString();
 
 	SOCKET sock = socket(runp->ai_family, runp->ai_socktype, runp->ai_protocol);
 	if (sock == INVALID_SOCKET) {
-		DEBUG(net, 0, "[%s] Could not create socket on port %s: %s", type, address, strerror(errno));
+		DEBUG(net, 0, "[%s] could not create %s socket on port %s: %s", type, family, address, strerror(errno));
 		return INVALID_SOCKET;
 	}
 
 	if (runp->ai_socktype == SOCK_STREAM && !SetNoDelay(sock)) {
-		DEBUG(net, 3, "[%s] Setting TCP_NODELAY failed for port %s", type, address);
+		DEBUG(net, 3, "[%s] setting TCP_NODELAY failed for port %s", type, address);
 	}
 
 	int on = 1;
 	/* The (const char*) cast is needed for windows!! */
 	if (setsockopt(sock, SOL_SOCKET, SO_REUSEADDR, (const char*)&on, sizeof(on)) == -1) {
-		DEBUG(net, 3, "[%s] Could not set reusable sockets for port %s: %s", type, address, strerror(errno));
+		DEBUG(net, 3, "[%s] could not set reusable %s sockets for port %s: %s", type, family, address, strerror(errno));
 	}
 
 	if (runp->ai_family == AF_INET6 &&
 			setsockopt(sock, IPPROTO_IPV6, IPV6_V6ONLY, (const char*)&on, sizeof(on)) == -1) {
-		DEBUG(net, 3, "[%s] Could not disable IPv4 over IPv6 on port %s: %s", type, address, strerror(errno));
+		DEBUG(net, 3, "[%s] could not disable IPv4 over IPv6 on port %s: %s", type, address, strerror(errno));
 	}
 
 	if (bind(sock, runp->ai_addr, (int)runp->ai_addrlen) != 0) {
-		DEBUG(net, 1, "[%s] Could not bind on port %s: %s", type, address, strerror(errno));
+		DEBUG(net, 1, "[%s] could not bind on %s port %s: %s", type, family, address, strerror(errno));
 		closesocket(sock);
 		return INVALID_SOCKET;
 	}
 
 	if (runp->ai_socktype != SOCK_DGRAM && listen(sock, 1) != 0) {
-		DEBUG(net, 1, "[%s] Could not listen at port %s: %s", type, address, strerror(errno));
+		DEBUG(net, 1, "[%s] could not listen at % port %s: %s", type, family, address, strerror(errno));
 		closesocket(sock);
 		return INVALID_SOCKET;
 	}
 
 	/* Connection succeeded */
-	if (!SetNonBlocking(sock)) DEBUG(net, 0, "[%s] Setting non-blocking mode failed for port %s", type, address);
+	if (!SetNonBlocking(sock)) DEBUG(net, 0, "[%s] setting non-blocking mode failed for %s port %s", type, family, address);
 
-	DEBUG(net, 1, "[%s] Listening on port %s", type, address);
+	DEBUG(net, 1, "[%s] listening on %s port %s", type, family, address);
 	return sock;
 }
 
@@ -328,4 +336,23 @@ void NetworkAddress::Listen(int socktype, SocketList *sockets)
 	}
 }
 
+/* static */ const char *NetworkAddress::SocketTypeAsString(int socktype)
+{
+	switch (socktype) {
+		case SOCK_STREAM: return "tcp";
+		case SOCK_DGRAM:  return "udp";
+		default:          return "unsupported";
+	}
+}
+
+/* static */ const char *NetworkAddress::AddressFamilyAsString(int family)
+{
+	switch (family) {
+		case AF_UNSPEC: return "either IPv4 or IPv6";
+		case AF_INET:   return "IPv4";
+		case AF_INET6:  return "IPv6";
+		default:        return "unsupported";
+	}
+}
+
 #endif /* ENABLE_NETWORK */
diff --git a/src/network/core/address.h b/src/network/core/address.h
index ecf6efa60..7d8d61ba1 100644
--- a/src/network/core/address.h
+++ b/src/network/core/address.h
@@ -238,6 +238,22 @@ public:
 	 * @param sockets the list of sockets to add the sockets to
 	 */
 	void Listen(int socktype, SocketList *sockets);
+
+	/**
+	 * Convert the socket type into a string
+	 * @param socktype the socket type to convert
+	 * @return the string representation
+	 * @note only works for SOCK_STREAM and SOCK_DGRAM
+	 */
+	static const char *SocketTypeAsString(int socktype);
+
+	/**
+	 * Convert the address family into a string
+	 * @param family the family to convert
+	 * @return the string representation
+	 * @note only works for AF_INET, AF_INET6 and AF_UNSPEC
+	 */
+	static const char *AddressFamilyAsString(int family);
 };
 
 #endif /* ENABLE_NETWORK */
diff --git a/src/network/network_udp.cpp b/src/network/network_udp.cpp
index efb8883be..59fbd7dc6 100644
--- a/src/network/network_udp.cpp
+++ b/src/network/network_udp.cpp
@@ -55,7 +55,7 @@ public:
 DEF_UDP_RECEIVE_COMMAND(Master, PACKET_UDP_MASTER_ACK_REGISTER)
 {
 	_network_advertise_retries = 0;
-	DEBUG(net, 2, "[udp] advertising on master server successful");
+	DEBUG(net, 2, "[udp] advertising on master server successful (%s)", NetworkAddress::AddressFamilyAsString(client_addr->GetAddress()->ss_family));
 
 	/* We are advertised, but we don't want to! */
 	if (!_settings_client.network.server_advertise) NetworkUDPRemoveAdvertise(false);
@@ -64,7 +64,7 @@ DEF_UDP_RECEIVE_COMMAND(Master, PACKET_UDP_MASTER_ACK_REGISTER)
 DEF_UDP_RECEIVE_COMMAND(Master, PACKET_UDP_MASTER_SESSION_KEY)
 {
 	_session_key = p->Recv_uint64();
-	DEBUG(net, 2, "[udp] received new session key from master server");
+	DEBUG(net, 2, "[udp] received new session key from master server (%s)", NetworkAddress::AddressFamilyAsString(client_addr->GetAddress()->ss_family));
 }
 
 ///*** Communication with clients (we are server) ***/
@@ -116,7 +116,7 @@ DEF_UDP_RECEIVE_COMMAND(Server, PACKET_UDP_CLIENT_FIND_SERVER)
 	/* Let the client know that we are here */
 	this->SendPacket(&packet, client_addr);
 
-	DEBUG(net, 2, "[udp] queried from '%s'", client_addr->GetHostname());
+	DEBUG(net, 2, "[udp] queried from %s", client_addr->GetHostname());
 }
 
 DEF_UDP_RECEIVE_COMMAND(Server, PACKET_UDP_CLIENT_DETAIL_INFO)
@@ -495,6 +495,22 @@ void NetworkUDPAdvertiseThread(void *pntr)
 
 	DEBUG(net, 1, "[udp] advertising to master server");
 
+	/* Add a bit more messaging when we cannot get a session key */
+	static byte session_key_retries = 0;
+	if (_session_key == 0 && session_key_retries++ == 2) {
+		DEBUG(net, 0, "[udp] advertising to the master server is failing");
+		DEBUG(net, 0, "[udp]   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));
+		DEBUG(net, 0, "[udp]   please allow udp packets from you to %s to be delivered", out_addr.GetAddressAsString(false));
+	}
+	if (_session_key != 0 && _network_advertise_retries == 0) {
+		DEBUG(net, 0, "[udp] advertising to the master server is failing");
+		DEBUG(net, 0, "[udp]   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, "[udp]   please allow udp and tcp packets to port %s to be delivered", _settings_client.network.server_port);
+		DEBUG(net, 0, "[udp]   please allow udp and tcp packets from port %s to be delivered", _settings_client.network.server_port);
+	}
+
 	/* Send the packet */
 	Packet p(PACKET_UDP_SERVER_REGISTER);
 	/* Packet is: WELCOME_MESSAGE, Version, server_port */