From f50a5fbdcd2ae5a3d21a3570d67c2b0668aa53af Mon Sep 17 00:00:00 2001 From: Phi Date: Wed, 5 Aug 2020 01:32:41 +0100 Subject: [PATCH] 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. --- Lacewing/Lacewing.h | 4 +- Lacewing/RelayServer.cc | 136 ++++++++++++++++++++++++++-------------- Lacewing/src/error.c | 34 +++++----- 3 files changed, 107 insertions(+), 67 deletions(-) diff --git a/Lacewing/Lacewing.h b/Lacewing/Lacewing.h index 7a37eaa..f543daf 100644 --- a/Lacewing/Lacewing.h +++ b/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> channels; std::string _name, _prevname; diff --git a/Lacewing/RelayServer.cc b/Lacewing/RelayServer.cc index 42abc97..f51dc7c 100644 --- a/Lacewing/RelayServer.cc +++ b/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> channels; bool channellistingenabled; - long pingMS; + long tcpPingMS; long udpKeepAliveMS; long maxInactivityMS; + /// Lacewing timer function for pinging and inactivity tests. + /// 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. void pingtimertick() { - std::vector> todisconnect; - std::vector> inactiveDisconnects; + std::vector> pingUnresponsivesToDisconnect; + std::vector> 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(currentTime - client->lasttcpmessagetime).count(); - long long msElapsedUDP = std::chrono::duration_cast(currentTime - client->lastudpmessagetime).count(); - long long msElapsedNonPing = std::chrono::duration_cast(currentTime - client->lastnonpingmessagetime).count(); + auto msElapsedTCP = std::chrono::duration_cast(currentTime - client->lasttcpmessagetime).count(); + auto msElapsedNonPing = std::chrono::duration_cast(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(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_ptrlasttcpmessagetime = ::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 (); - - 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_ptrlastchannelorpeermessagetime = ::std::chrono::steady_clock::now(); + } + break; } @@ -1743,6 +1775,10 @@ bool relayserverinternal::client_messagehandler(std::shared_ptrclientcount() > 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_ptrlastchannelorpeermessagetime = ::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_ptrlock.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_ptrclientImpl = 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(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); } diff --git a/Lacewing/src/error.c b/Lacewing/src/error.c index b942d5d..836142e 100644 --- a/Lacewing/src/error.c +++ b/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 }