Fix lockup when disconnecting udp connection, simplified some of the …

…DebugCounter/DebugTimer code and added a status message printed every minute to the console.

Source/Server/Server/ServerManager.cpp

@@ -14,6 +14,9 @@
 #include "Shared/Core/Utils/File.h"
 #include "Shared/Core/Utils/Strings.h"
 #include "Shared/Core/Utils/Random.h"
+#include "Shared/Core/Utils/DebugCounter.h"
+#include "Shared/Core/Utils/DebugObjects.h"
+#include "Shared/Core/Utils/DebugTimer.h"
 
 #include <thread>
 #include <chrono>
@@ -93,9 +96,12 @@ void ServerManager::RunUntilQuit()
     {
         std::scoped_lock lock(m_mutex);
 
-        for (auto& Server : ServerInstances)
         {
-            Server->Poll();
+            DebugTimerScope Scope(Debug::AllServerUpdateTime);
+            for (auto& Server : ServerInstances)
+            {
+                Server->Poll();
+            }
         }
 
         if (GetSeconds() > NextServerPruneTime)
@@ -115,7 +121,35 @@ void ServerManager::RunUntilQuit()
             Callbacks.clear();
         }
 
-        std::this_thread::sleep_for(std::chrono::milliseconds(1));
+        // Emit some statistics periodically.
+        double Elapsed = GetSeconds() - LastStatsPrint;
+        if (Elapsed > 30.0f)
+        {
+            size_t PlayerCount = 0;
+            for (auto& Server : ServerInstances)
+            {
+                PlayerCount += Server->GetService<GameService>()->GetClients().size();
+            }
+
+            WriteLog(true, ConsoleColor::Grey, "", "Log", "%zi players | %zi servers | %.2f ms update | connections auth %.2f login %.2f game %.2f p/s | tcp in %.2f out %.2f kb/s | udp in %.2f out %.2f kb/s ",
+                PlayerCount,
+                ServerInstances.size(),
+                Debug::AllServerUpdateTime.GetAverage(),
+                Debug::AuthConnections.GetAverageRate(),
+                Debug::LoginConnections.GetAverageRate(),
+                Debug::GameConnections.GetAverageRate(),
+                (Debug::TcpBytesRecieved.GetAverageRate()) / 1024.0f,
+                (Debug::TcpBytesSent.GetAverageRate()) / 1024.0f,
+                (Debug::UdpBytesRecieved.GetAverageRate()) / 1024.0f,
+                (Debug::UdpBytesSent.GetAverageRate()) / 1024.0f
+            );
+
+            LastStatsPrint = GetSeconds();
+        }
+
+        DebugCounter::PollAll();
+
+        std::this_thread::sleep_for(std::chrono::microseconds(100));
     }
 }
 

Source/Server/Server/ServerManager.h

@@ -64,4 +64,6 @@ class ServerManager
     std::mutex CallbackMutex;
     std::vector<std::function<void()>> Callbacks;
 
+    double LastStatsPrint = GetSeconds();
+
 };

Source/Shared/Core/Network/NetConnectionUDP.cpp

@@ -276,7 +276,12 @@ bool NetConnectionUDP::Disconnect()
 
     if (!bChild)
     {
-        bShuttingDownThreads = true;
+        {
+            std::unique_lock lock(SendQueueMutex);
+            bShuttingDownThreads = true;
+            SendQueueCvar.notify_all();
+        }
+
         if (RecieveThread)
         {
             RecieveThread->join();
@@ -378,6 +383,22 @@ void NetConnectionUDP::RecieveThreadEntry()
         socklen_t SourceAddressSize = sizeof(struct sockaddr);
         sockaddr_in SourceAddress = { 0 };
 
+        timeval Timeout;
+        Timeout.tv_sec = 0;
+        Timeout.tv_usec = 1000 * 10;
+
+        fd_set SocketSet;
+        FD_ZERO(&SocketSet);
+        FD_SET(Socket, &SocketSet);
+
+        // Wait until a message is available, or wakeup after a timeout to check shutdown state 
+        // (this is kinda garbage, we should look at a better way to handle this).
+        if (select(1, &SocketSet, nullptr, nullptr, &Timeout) == 0)
+        {
+            continue;
+        }
+
+        // Recieve the next message on the socket.
         int Flags = 0;
         int Result = recvfrom(Socket, (char*)RecieveBuffer.data(), (int)RecieveBuffer.size(), Flags, (sockaddr*)&SourceAddress, &SourceAddressSize);
         if (Result < 0)
@@ -446,6 +467,11 @@ void NetConnectionUDP::SendThreadEntry()
             std::unique_lock lock(SendQueueMutex);
             while (true)
             {
+                if (bShuttingDownThreads)
+                {
+                    return;
+                }
+
                 if (!SendQueue.empty())
                 {
                     SendPacket = std::move(SendQueue.front());

Source/Shared/Core/Utils/DebugCounter.cpp

@@ -9,10 +9,8 @@
 
 #include "Shared/Core/Utils/DebugCounter.h"
 
-DebugCounter::DebugCounter(const std::string& InName, double InRateWindow, double InRollingWindow)
+DebugCounter::DebugCounter(const std::string& InName)
     : Name(InName)
-    , RollingWindow(InRollingWindow)
-    , RateWindow(InRateWindow)
 {
     Registry.push_back(this);
 }
@@ -37,25 +35,7 @@ std::string DebugCounter::GetName()
 
 double DebugCounter::GetAverageRate()
 {
-    std::scoped_lock lock(DataMutex);
-
-    if (Samples.empty())
-    {
-        return 0.0;
-    }
-
-    double Total = 0.0f;
-
-    for (Sample& Sample : Samples)
-    {
-        Total += Sample.Value;
-    }
-
-    double CurrentTime = GetHighResolutionSeconds();
-    double ElapsedTime = CurrentTime - Samples.front().Time;
-    double Multiplier = RateWindow / ElapsedTime;
-
-    return Total * Multiplier;
+    return Average;
 }
 
 double DebugCounter::GetTotalLifetime()
@@ -65,29 +45,29 @@ double DebugCounter::GetTotalLifetime()
 
 void DebugCounter::Add(double Value)
 {
-    std::scoped_lock lock(DataMutex);
+    AverageSum += Value;
+    LifetimeTotal += Value;
+}
 
+void DebugCounter::Poll()
+{
     double CurrentTime = GetHighResolutionSeconds();
+    double Elapsed = CurrentTime - AverageTimer;
+    if (Elapsed > 1.0f)
+    {
+        float Scale = 1.0f / Elapsed;
+        float Sample = AverageSum * Scale;
 
-    Sample NewSample;
-    NewSample.Time = CurrentTime;
-    NewSample.Value = Value;
-    Samples.push_back(NewSample);
+        Average = (Average * 0.9f) + (Sample * 0.1f);
+        AverageSum = 0.0;
+        AverageTimer = CurrentTime;
+    }
+}
 
-    // Trim old samples from list.
-    double OldestTime = CurrentTime - RollingWindow;
-    while (!Samples.empty())
+void DebugCounter::PollAll()
+{
+    for (DebugCounter* instance : Registry)
     {
-        Sample& FirstSample = Samples.front();
-        if (FirstSample.Time < OldestTime)
-        {
-            Samples.erase(Samples.begin());
-        }
-        else
-        {
-            break;
-        }
+        instance->Poll();
     }
-
-    LifetimeTotal += Value;
 }

Source/Shared/Core/Utils/DebugCounter.h

@@ -18,7 +18,7 @@
 class DebugCounter
 {
 public:
-    DebugCounter(const std::string& name, double RateWindow = 60 * 60, double RollingWindow = 60 * 5);
+    DebugCounter(const std::string& name);
     ~DebugCounter();
 
     std::string GetName();
@@ -27,25 +27,20 @@ class DebugCounter
 
     void Add(double Value);
 
+    void Poll();
+
     static std::vector<DebugCounter*> GetCounters();
+    static void PollAll();
 
 private:
     inline static std::vector<DebugCounter*> Registry;    
 
-    std::mutex DataMutex;
-
-    struct Sample
-    {
-        double Time;
-        double Value;
-    };
-
-    std::list<Sample> Samples;
+    std::string Name;
 
-    double LifetimeTotal = 0.0;
-    double RateWindow = 0.0;
-    double RollingWindow = 0.0;
+    double LifetimeTotal = 0.0f;
 
-    std::string Name;
+    double Average = 0.0;
+    double AverageTimer = 0.0;
+    double AverageSum = 0.0;
 
 };

Source/Shared/Core/Utils/DebugObjects.inc

@@ -7,6 +7,7 @@
  * If not, see <https://opensource.org/licenses/MIT>.
  */
 
+TIMER(AllServerUpdateTime, "All Server Update Time")
 TIMER(UpdateTime, "Update Time")
 TIMER(WebUIService_PollTime, "Web UI Service (Poll Time)")
 TIMER(GameService_PollTime, "Game Service (Poll Time)")

Source/Shared/Core/Utils/DebugTimer.h

@@ -18,7 +18,7 @@
 class DebugTimer 
 {
 public:
-    DebugTimer(const std::string& name, double RollingWindow = 60.0);
+    DebugTimer(const std::string& name, double RollingWindow = 10.0);
     ~DebugTimer();
 
     std::string GetName();