Update Bluewing Server to build 19

Build 19 has no major changes, but has a couple rare-case fixes, as well as some increased documentation in the ping function. It's also a rebuild for the steady_clock issue.
Changed the error message created by Lacewing, so there's not an awkward line break.
The error of clients remaining connected constantly turned out to be an error in the standard library provided in Visual Studio 2019, which I've documented more in the ansi-build-18 release.
In preparation for release, now server messages also count as activity - if server has a handler set up for them. No server-message handler = not activity.

Author: SortaCore

Lacewing/Lacewing.h

@@ -1847,7 +1847,7 @@ namespace lacewing {
 struct relayserverinternal;
 struct relayserver
 {
-	static const int buildnum = 18;
+	static const int buildnum = 19;
 
 	void * internaltag, * tag = nullptr;
 
@@ -1985,7 +1985,7 @@ struct relayserver
 		::std::chrono::high_resolution_clock::time_point connectTime;
 		::std::chrono::steady_clock::time_point lasttcpmessagetime;
 		::std::chrono::steady_clock::time_point lastudpmessagetime; // UDP problem where unused connections are dropped by router, so must keep these separate
-		::std::chrono::steady_clock::time_point lastnonpingmessagetime; // For clients that go idle
+		::std::chrono::steady_clock::time_point lastchannelorpeermessagetime; // For clients that go idle
 		framereader reader;
         std::vector<std::shared_ptr<channel>> channels;
 		std::string _name, _prevname;

Lacewing/RelayServer.cc

@@ -58,7 +58,7 @@ struct relayserverinternal
 
 		pingtimer->tag(this);
 		pingtimer->on_tick(serverpingtimertick);
-		pingMS = 5000;
+		tcpPingMS = 5000;
 
 		// Some firewalls/router set to mark UDP connections as over after 30 seconds of inactivity,
 		// but a general consensus is around 60 seconds.
@@ -69,7 +69,7 @@ struct relayserverinternal
 		// It's not perfect, but since the ping timer will keep repeating anyway past the 3 mark, and
 		// activity on either side won't cause the no-new-connections bug to occur, it shouldn't
 		// matter either way.
-		udpKeepAliveMS = 30000 - (pingMS * 3);
+		udpKeepAliveMS = 30000 - (tcpPingMS * 3);
 
 		// Some buggy client versions don't close their connection on end of app, forcing the app to stay
 		// alive. We can't force them to close, but we can disconnect them.
@@ -117,18 +117,32 @@ struct relayserverinternal
 	std::vector<std::shared_ptr<relayserver::channel>> channels;
 
 	bool channellistingenabled;
-	long pingMS;
+	long tcpPingMS;
 	long udpKeepAliveMS;
 	long maxInactivityMS;
 
+	/// <summary> Lacewing timer function for pinging and inactivity tests. </summary>
+	///	<remarks> There are three things this function does:
+	///			  1) If the client has not sent a TCP message within tcpPingMS milliseconds, send a ping request.
+	///			  -> If client still hasn't responded after another tcpPingMS, notify server via error handler,
+	///				 and disconnect client.
+	///			  2) If the client has not sent a UDP message within udpKeepAliveMS milliseconds, send a ping request.
+	///			  -> UDP ping response is not checked for by this function; one-way UDP activity is enough to keep the
+	///				 UDP psuedo-connection alive in routers.
+	///			     Note using default timing, three UDP messages will be sent before routers are likely to close connection.
+	///			  3) If the client has only replied to pings, and not sent any channel, peer, or server messages besides,
+	///				 within a period of maxInactivityMS, then the client will be messaged and disconnected, and the server notified
+	///				 via error handler.
+	///				 Worth noting channel messages when there is no other peers, and serve messages when there is no server message
+	///				 handler, and channel join/leave requests as well as other messages, do not qualify as activity. </remarks>
 	void pingtimertick()
 	{
-		std::vector<std::shared_ptr<relayserver::client>> todisconnect;
-		std::vector<std::shared_ptr<relayserver::client>> inactiveDisconnects;
+		std::vector<std::shared_ptr<relayserver::client>> pingUnresponsivesToDisconnect;
+		std::vector<std::shared_ptr<relayserver::client>> inactivesToDisconnects;
 
-		framebuilder builderPingTCP(false), builderPingUDP(true);
-		builderPingTCP.addheader(11, 0);		/* ping */
-		builderPingUDP.addheader(11, 0, true);	/* ping with UDP */
+		framebuilder msgBuilderTCP(false), msgBuilderUDP(true);
+		msgBuilderTCP.addheader(11, 0);			/* ping header */
+		msgBuilderUDP.addheader(11, 0, true);	/* ping header, true for UDP */
 
 		std::chrono::steady_clock::time_point currentTime = std::chrono::steady_clock::now();
 		auto serverReadLock = server.lock.createReadLock();
@@ -137,32 +151,42 @@ struct relayserverinternal
 			if (client->_readonly)
 				continue;
 
-			long long msElapsedTCP = std::chrono::duration_cast<std::chrono::milliseconds>(currentTime - client->lasttcpmessagetime).count();
-			long long msElapsedUDP = std::chrono::duration_cast<std::chrono::milliseconds>(currentTime - client->lastudpmessagetime).count();
-			long long msElapsedNonPing = std::chrono::duration_cast<std::chrono::milliseconds>(currentTime - client->lastnonpingmessagetime).count();
+			auto msElapsedTCP = std::chrono::duration_cast<std::chrono::milliseconds>(currentTime - client->lasttcpmessagetime).count();
+			auto msElapsedNonPing = std::chrono::duration_cast<std::chrono::milliseconds>(currentTime - client->lastchannelorpeermessagetime).count();
 
-			// less than 5 seconds passed, skip the TCP ping
-			if (msElapsedTCP < pingMS)
+			// Psuedo UDP is true unless a UDPHello packet is received, i.e. the client connect handshake UDP packet.
+			decltype(msElapsedTCP) msElapsedUDP = 0;
+			if (!client->pseudoUDP)
+				msElapsedUDP = std::chrono::duration_cast<std::chrono::milliseconds>(currentTime - client->lastudpmessagetime).count();
+			
+			// detect a buggy version of std::chrono::steady_clock (was in a VS 2019 preview)
+			if (msElapsedTCP < 0 || msElapsedUDP < 0 || msElapsedNonPing < 0)
+				DebugBreak();
+
+			// less than 5 seconds (or tcpPingMS) passed since last TCP message, skip the TCP ping
+			if (msElapsedTCP < tcpPingMS)
 			{
 				client->pongedOnTCP = true;
 
-				// Also no UDP ping needed, skip both pings
+				// No UDP keep-alive message needed either, skip both pings
 				if (msElapsedUDP < udpKeepAliveMS)
 					continue;
 			}
+
+			// More than 10 minutes passed, prep to kick for inactivity
 			if (msElapsedNonPing > maxInactivityMS)
 			{
-				inactiveDisconnects.push_back(client);
+				inactivesToDisconnects.push_back(client);
 				continue;
 			}
 
 			// pongedOnTCP is true until client hasn't sent a message within PingMS period.
-			// Then it's set to false and a ping message sent, which happens AFTER this if().
-			// The ping timer ticks again pingMS ms later, and if pongedOnTCP is still false (this if() ),
-			// then client hasn't responded to ping, and so should be disconnected.
+			// Then it's set to false and a ping message sent, which happens AFTER this if block.
+			// The ping timer ticks again tcpPingMS ms later, and if pongedOnTCP is still false
+			// (in this if condition), then client hasn't responded to ping, and so should be disconnected.
 			if (!client->pongedOnTCP)
 			{
-				todisconnect.push_back(client);
+				pingUnresponsivesToDisconnect.push_back(client);
 				continue;
 			}
 
@@ -171,29 +195,39 @@ struct relayserverinternal
 			if (client->_readonly)
 				continue;
 
-			if (msElapsedTCP >= pingMS)
+			if (msElapsedTCP >= tcpPingMS)
 			{
 				client->pongedOnTCP = false;
-				builderPingTCP.send(client->socket, false);
+				msgBuilderTCP.send(client->socket, false);
 			}
+
+			// Keep UDP alive by sending a UDP message.
+			// Worth noting Relay clients and Blue client b82 and below don't have UDP ping responses; they will
+			// ignore the message entirely.
+			// Fortunately, we don't actually *need* a ping responses from the client; one-way activity ought to be
+			// enough to keep the UDP psuedo-connections open in routers... assuming, of course, that the UDP packet
+			// goes all the way to the client and thus through all the routers.
 			if (msElapsedUDP >= udpKeepAliveMS)
-				builderPingUDP.send(server.udp, client->udpaddress, false);
+				msgBuilderUDP.send(server.udp, client->udpaddress, false);
 		}
 
-		builderPingTCP.framereset();
-
-		if (todisconnect.empty() && inactiveDisconnects.empty())
+		if (pingUnresponsivesToDisconnect.empty() && inactivesToDisconnects.empty())
 			return;
 
 		serverReadLock.lw_unlock();
 
-		for (auto& client : todisconnect)
+		// Loop all pending ping disconnects
+		for (auto& client : pingUnresponsivesToDisconnect)
 		{
+			// One final disconnect check
 			if (client->_readonly)
 				continue;
 
+			// To allow client disconnect handlers to run without clashes, we keep the lock open
+			// as frequently as possible.
 			if (!serverReadLock.isEnabled())
 				serverReadLock.lw_relock();
+
 			if (std::find(clients.begin(), clients.end(), client) != clients.end())
 			{
 				serverReadLock.lw_unlock();
@@ -226,7 +260,8 @@ struct relayserverinternal
 			}
 		}
 
-		for (auto& client : inactiveDisconnects)
+		// Loop all pending inactivity disconnects
+		for (auto& client : inactivesToDisconnects)
 		{
 			if (client->_readonly)
 				continue;
@@ -245,11 +280,11 @@ struct relayserverinternal
 					impl.erase(impl.cend());
 
 				auto error = lacewing::error_new();
-				error->add("Disconnecting client ID %i due to 10 min inactivity timeout; client impl \"%s\".", client->_id, impl.c_str());
+				error->add("Disconnecting client ID %i due to inactivity timeout; client impl \"%s\".", client->_id, impl.c_str());
 				handlererror(this->server, error);
 				lacewing::error_delete(error);
 
-				client->send(0, "You're being kicked for 10 minutes of inactivity.", 0);
+				client->send(0, "You're being kicked for inactivity.", 0);
 				// Close nicely
 				client->socket->close(lw_false);
 			}
@@ -936,7 +971,7 @@ void relayserver::host(lacewing::filter &_filter)
 	lacewing::filter_delete(filter);
 
 	relayserverinternal * serverInternal = (relayserverinternal *)internaltag;
-	serverInternal->pingtimer->start(serverInternal->pingMS);
+	serverInternal->pingtimer->start(serverInternal->tcpPingMS);
 }
 
 void relayserver::unhost()
@@ -1369,9 +1404,6 @@ bool relayserverinternal::client_messagehandler(std::shared_ptr<relayserver::cli
 	else
 		client->lasttcpmessagetime = ::std::chrono::steady_clock::now();
 
-	if (messagetypeid != 9)
-		client->lastnonpingmessagetime = ::std::chrono::steady_clock::now();
-
 	std::stringstream errStr;
 	bool trustedClient = true;
 
@@ -1683,12 +1715,7 @@ bool relayserverinternal::client_messagehandler(std::shared_ptr<relayserver::cli
 			cliReadLock.lw_unlock();
 
 			const lw_ui8 subchannel = reader.get <lw_ui8> ();
-
-			const char * message2;
-			size_t size2;
-
-			reader.getremaining(message2, size2);
-			std::string_view message3(message2, size2);
+			std::string_view message3 = reader.getremaining(false);
 
 			if (reader.failed)
 			{
@@ -1698,8 +1725,13 @@ bool relayserverinternal::client_messagehandler(std::shared_ptr<relayserver::cli
 			}
 
 			if (handlermessage_server)
+			{
 				handlermessage_server(server, client, blasted, subchannel, message3, variant);
 
+				// Server messages, we'll assume it is activity.
+				client->lastchannelorpeermessagetime = ::std::chrono::steady_clock::now();
+			}
+
 			break;
 		}
 
@@ -1743,6 +1775,10 @@ bool relayserverinternal::client_messagehandler(std::shared_ptr<relayserver::cli
 			}
 			cliReadLock.lw_unlock();
 
+			// Channel messages not sent to anyone is not activity.
+			if (channel->clientcount() > 1)
+				client->lastchannelorpeermessagetime = ::std::chrono::steady_clock::now();
+
 			if (handlermessage_channel)
 				handlermessage_channel(server, client, channel,
 					blasted, subchannel, message2, variant);
@@ -1780,6 +1816,8 @@ bool relayserverinternal::client_messagehandler(std::shared_ptr<relayserver::cli
 				break;
 			}
 
+			client->lastchannelorpeermessagetime = ::std::chrono::steady_clock::now();
+
 			if (handlermessage_peer)
 				handlermessage_peer(server, client, channel,
 					peer, blasted, subchannel, message3, variant);
@@ -1845,18 +1883,21 @@ bool relayserverinternal::client_messagehandler(std::shared_ptr<relayserver::cli
 		case 10: /* implementation response */
 		{
 			std::string_view impl = reader.get(reader.bytesleft());
-			if (reader.failed)
+			if (reader.failed || impl.empty())
 			{
 				errStr << "Failed to read implementation response";
 				trustedClient = false;
 				break;
 			}
 
+			// LW_ESCALATION_NOTE
 			cliReadLock.lw_unlock();
 			auto cliWriteLock = client->lock.createWriteLock();
 			if (client->_readonly)
 				break;
 
+			// Implementation responses were added in Bluewing Client build 70.
+
 			if (impl.find("Windows") != std::string_view::npos)
 			{
 				if (impl.find("Unicode") != std::string_view::npos)
@@ -1876,7 +1917,8 @@ bool relayserverinternal::client_messagehandler(std::shared_ptr<relayserver::cli
 				client->clientImpl = relayserver::client::clientimpl::HTML5;
 			else
 			{
-				errStr << "Failed to recognise implementation \"" << impl << "\". Leaving it as Unknown.";
+				errStr << "Failed to recognise platform of implementation \"" << impl << "\". Leaving it as Unknown.";
+				reader.failed = true;
 			}
 
 			client->clientImplStr = impl;
@@ -1919,7 +1961,6 @@ bool relayserverinternal::client_messagehandler(std::shared_ptr<relayserver::cli
 		// only return false if socket is emergency closing and
 		// you cannot trust further message content is readable
 		return trustedClient;
-		/* socket.disconnect(); */
 	}
 
 	return true;
@@ -2034,8 +2075,7 @@ relayserver::client::client(relayserverinternal &internal, lacewing::server_clie
 
 	// connectTime not started until handshake is done
 	// last message can be considered the connect time
-	lastnonpingmessagetime = lasttcpmessagetime = ::std::chrono::steady_clock::now();
-	lastudpmessagetime = ::std::chrono::steady_clock::time_point::time_point();
+	lastudpmessagetime = lastchannelorpeermessagetime = lasttcpmessagetime = ::std::chrono::steady_clock::now();
 }
 
 ::lacewing::relayserver::channel::channel(relayserverinternal &_server, std::string_view _name) :
@@ -2219,8 +2259,8 @@ using namespace ::std::chrono;
 lw_i64 relayserver::client::getconnecttime() const
 {
 	// No need for read lock: connect time is set in ctor
-	high_resolution_clock::time_point end = high_resolution_clock::now();
-	nanoseconds time = end - connectTime;
+	steady_clock::time_point end = steady_clock::now();
+	auto time = end - connectTime;
 	return duration_cast<seconds>(time).count();
 }
 
@@ -2318,7 +2358,7 @@ void relayserver::connect_response(
 
 	lw_trace("Connect request accepted in relayserver::connectresponse");
 	client->connectRequestApproved = true;
-	client->connectTime = std::chrono::high_resolution_clock::now();
+	client->connectTime = std::chrono::steady_clock::now();
 	client->clientImpl = relayserver::client::clientimpl::Unknown;
 
 	builder.addheader(0, 0);  /* response */
@@ -2338,7 +2378,7 @@ void relayserver::connect_response(
 	// Send request implementation: this is the best time to send it
 
 	builder.addheader(12, 0);  /* request implementation */
-	// response on 10, only responded to by Bluewing, Relay just ignores it
+	// response on 10, only responded to by Bluewing b70+, Relay just ignores it
 
 	builder.send(client->socket);
 }

Lacewing/src/error.c

@@ -118,26 +118,26 @@ void lw_error_add (lw_error ctx, long error)
 {
 	#ifdef _WIN32
 
-	  char * message;
-
-	  if (FormatMessageA
-			(FORMAT_MESSAGE_FROM_SYSTEM | FORMAT_MESSAGE_ALLOCATE_BUFFER,
-			 0,
-			 error,
-			 MAKELANGID (LANG_NEUTRAL, SUBLANG_DEFAULT),
-			 (char *) &message,
-			 1,
-			 0))
-	  {
-		 lw_error_addf (ctx, error < 0 ? "%s (%08X)" : "%s (%d)",
-				message, error);
-	  }
-
-	  LocalFree (message);
+		char message[512];
+
+		if (FormatMessageA
+			(FORMAT_MESSAGE_FROM_SYSTEM,
+				0,
+				error,
+				MAKELANGID (LANG_NEUTRAL, SUBLANG_DEFAULT),
+				message,
+				sizeof(message) / sizeof(*message),
+				0))
+		{
+			lw_error_addf (ctx, error < 0 ? "%.*s (%08X)" : "%.*s (%d)",
+				strlen(message) - 3, message, error);
+		}
+
+		LocalFree (message);
 
 	#else
 
-	  lw_error_addf (ctx, "%s", strerror (error));
+		lw_error_addf (ctx, "%s (%ld)", strerror (error), error);
 
 	#endif
 }