fix parsing of certain chat messages

print out the correct exception message when a server is not responding.
prevent log reader from reading before the servers have initialized

Application/EventParsers/IW4EventParser.cs

@@ -10,6 +10,8 @@ namespace IW4MAdmin.Application.EventParsers
 {
     class IW4EventParser : IEventParser
     {
+        private const string SayRegex = @"(say|sayteam);(.{16,32});([0-9]+)(.*);(.*)";
+
         public virtual GameEvent GetEvent(Server server, string logLine)
         {
             logLine = Regex.Replace(logLine, @"([0-9]+:[0-9]+ |^[0-9]+ )", "").Trim();
@@ -45,28 +47,35 @@ namespace IW4MAdmin.Application.EventParsers
 
             if (eventType == "say" || eventType == "sayteam")
             {
-                string message = lineSplit[4].Replace("\x15", "");
+                var matchResult = Regex.Match(logLine, SayRegex);
 
-                if (message[0] == '!' || message[0] == '@')
+                if (matchResult.Success)
                 {
+                    string message = matchResult.Groups[5].ToString()
+                        .Replace("\x15", "")
+                        .Trim();
+
+                    if (message[0] == '!' || message[0] == '@')
+                    {
+                        return new GameEvent()
+                        {
+                            Type = GameEvent.EventType.Command,
+                            Data = message,
+                            Origin = server.GetPlayersAsList().First(c => c.ClientNumber == Utilities.ClientIdFromString(lineSplit, 2)),
+                            Owner = server,
+                            Message = message
+                        };
+                    }
+
                     return new GameEvent()
                     {
-                        Type = GameEvent.EventType.Command,
+                        Type = GameEvent.EventType.Say,
                         Data = message,
                         Origin = server.GetPlayersAsList().First(c => c.ClientNumber == Utilities.ClientIdFromString(lineSplit, 2)),
                         Owner = server,
                         Message = message
                     };
                 }
-
-                return new GameEvent()
-                {
-                    Type = GameEvent.EventType.Say,
-                    Data = message,
-                    Origin = server.GetPlayersAsList().First(c => c.ClientNumber == Utilities.ClientIdFromString(lineSplit, 2)),
-                    Owner = server,
-                    Message = message
-                };
             }
 
             if (eventType == "ScriptKill")

Application/GameEventHandler.cs

@@ -3,9 +3,6 @@ using SharedLibraryCore.Interfaces;
 using System;
 using System.Collections.Concurrent;
 using System.Collections.Generic;
-using System.Linq;
-using System.Text;
-using System.Threading;
 
 namespace IW4MAdmin.Application
 {
@@ -14,8 +11,6 @@ namespace IW4MAdmin.Application
         private ConcurrentQueue<GameEvent> EventQueue;
         private Queue<GameEvent> DelayedEventQueue;
         private IManager Manager;
-        private const int DelayAmount = 5000;
-        private DateTime LastDelayedEvent;
 
         public GameEventHandler(IManager mgr)
         {
@@ -50,25 +45,7 @@ namespace IW4MAdmin.Application
         }
 
         public GameEvent GetNextEvent()
-        {
+        {    
-            if (DelayedEventQueue.Count > 0 &&
-           (DateTime.Now - LastDelayedEvent).TotalMilliseconds > DelayAmount)
-            {
-                LastDelayedEvent = DateTime.Now;
-#if DEBUG
-                Manager.GetLogger().WriteDebug("Getting next delayed event to be processed");
-#endif
-                if (!DelayedEventQueue.TryDequeue(out GameEvent newEvent))
-                {
-                    Manager.GetLogger().WriteWarning("Could not dequeue delayed event for processing");
-                }
-
-                else
-                {
-                    return newEvent;
-                }
-            }
-
             if (EventQueue.Count > 0)
             {
 #if DEBUG
@@ -76,7 +53,7 @@ namespace IW4MAdmin.Application
 #endif
                 if (!EventQueue.TryDequeue(out GameEvent newEvent))
                 {
-                    Manager.GetLogger().WriteWarning("Could not dequeue event for processing");
+                    Manager.GetLogger().WriteError("Could not dequeue event for processing");
                 }
 
                 else

Application/IO/GameLogEvent.cs

@@ -29,11 +29,14 @@ namespace IW4MAdmin.Application.IO
            {
                while (!server.Manager.ShutdownRequested())
                {
-                   OnEvent(new EventState()
+                   if ((server.Manager as ApplicationManager).IsInitialized)
                    {
-                       Log = server.Manager.GetLogger(),
+                       OnEvent(new EventState()
-                       ServerId = server.ToString()
+                       {
-                   });
+                           Log = server.Manager.GetLogger(),
+                           ServerId = server.ToString()
+                       });
+                   }
                    await Task.Delay(100);
                }
            });
@@ -42,7 +45,7 @@ namespace IW4MAdmin.Application.IO
         private void OnEvent(object state)
         {
             long newLength = new FileInfo(GameLogFile).Length;
- 
+
             try
             {
                 UpdateLogEvents(newLength);

Application/Manager.cs

@@ -31,6 +31,7 @@ namespace IW4MAdmin.Application
         public Dictionary<int, Player> PrivilegedClients { get; set; }
         public ILogger Logger { get; private set; }
         public bool Running { get; private set; }
+        public bool IsInitialized { get; private set; }
         public EventHandler<GameEvent> ServerEventOccurred { get; private set; }
         public DateTime StartTime { get; private set; }
 
@@ -92,6 +93,13 @@ namespace IW4MAdmin.Application
                     .Select(ut => ut.Key)
                     .ToList();
 
+                // this is to prevent the log reader from starting before the initial
+               // query of players on the server
+                if (serverTasksToRemove.Count > 0)
+                {
+                    IsInitialized = true;
+                }
+
                 // remove the update tasks as they have completd
                 foreach (int serverId in serverTasksToRemove)
                 {
@@ -122,7 +130,11 @@ namespace IW4MAdmin.Application
                 ThreadPool.GetAvailableThreads(out int availableThreads, out int m);
                 Logger.WriteDebug($"There are {workerThreads - availableThreads} active threading tasks");
 #endif
+#if DEBUG
+                await Task.Delay(30000);
+#else
                 await Task.Delay(ConfigHandler.Configuration().RConPollRate);
+#endif
             }
         }
 
@@ -130,7 +142,7 @@ namespace IW4MAdmin.Application
         {
             Running = true;
 
-            #region DATABASE
+#region DATABASE
             var ipList = (await ClientSvc.Find(c => c.Level > Player.Permission.Trusted))
                 .Select(c => new
                 {
@@ -160,9 +172,9 @@ namespace IW4MAdmin.Application
                     continue;
                 }
             }
-            #endregion
+#endregion
 
-            #region CONFIG
+#region CONFIG
             var config = ConfigHandler.Configuration();
 
             // copy over default config if it doesn't exist
@@ -213,8 +225,8 @@ namespace IW4MAdmin.Application
             Encoding.RegisterProvider(CodePagesEncodingProvider.Instance);
             Utilities.EncodingType = Encoding.GetEncoding(!string.IsNullOrEmpty(config.CustomParserEncoding) ? config.CustomParserEncoding : "windows-1252");
 
-            #endregion
+#endregion
-            #region PLUGINS
+#region PLUGINS
             SharedLibraryCore.Plugins.PluginImporter.Load(this);
 
             foreach (var Plugin in SharedLibraryCore.Plugins.PluginImporter.ActivePlugins)
@@ -231,9 +243,9 @@ namespace IW4MAdmin.Application
                     Logger.WriteDebug($"Stack Trace: {e.StackTrace}");
                 }
             }
-            #endregion
+#endregion
 
-            #region COMMANDS
+#region COMMANDS
             if (ClientSvc.GetOwners().Result.Count == 0)
                 Commands.Add(new COwner());
 
@@ -277,9 +289,9 @@ namespace IW4MAdmin.Application
 
             foreach (Command C in SharedLibraryCore.Plugins.PluginImporter.ActiveCommands)
                 Commands.Add(C);
-            #endregion
+#endregion
 
-            #region INIT
+#region INIT
             async Task Init(ServerConfiguration Conf)
             {
                 // setup the event handler after the class is initialized
@@ -315,7 +327,7 @@ namespace IW4MAdmin.Application
             }
 
             await Task.WhenAll(config.Servers.Select(c => Init(c)).ToArray());
-            #endregion
+#endregion
         }
 
         private async Task SendHeartbeat(object state)
@@ -414,8 +426,7 @@ namespace IW4MAdmin.Application
 
                 catch (NetworkException e)
                 {
-                    Logger.WriteError(Utilities.CurrentLocalization.LocalizationIndex["SERVER_ERROR_COMMUNICATION"]);
+                    Logger.WriteError(e.Message);
-                    Logger.WriteDebug(e.Message);
                 }
 
                 catch (Exception E)
@@ -434,24 +445,21 @@ namespace IW4MAdmin.Application
             {
                 // wait for new event to be added
                 OnEvent.Wait();
-                var taskList = new List<Task>();
+                while((queuedEvent = Handler.GetNextEvent()) != null)
-                // todo: sequencially or parallelize?
-                while ((queuedEvent = Handler.GetNextEvent()) != null)
                 {
-                    if (queuedEvent.Origin != null &&
+                    if (GameEvent.ShouldOriginEventBeDelayed(queuedEvent))
-                        !queuedEvent.Origin.IsAuthenticated &&
-                        // we want to allow join events
-                        queuedEvent.Type != GameEvent.EventType.Join &&
-                        queuedEvent.Type != GameEvent.EventType.Quit &&
-                        // we don't care about unknown events
-                        queuedEvent.Origin.NetworkId != 0)
                     {
-                        Logger.WriteDebug($"Delaying execution of event type {queuedEvent.Type} for {queuedEvent.Origin} because they are not authed");
+                        Logger.WriteDebug($"Delaying origin execution of event type {queuedEvent.Type} for {queuedEvent.Origin} because they are not authed");
-                        // update the event origin for possible authed client
+                        // offload it to the player to keep
-                        queuedEvent.Origin = queuedEvent.Owner.Players.FirstOrDefault(p => p != null && p.NetworkId == queuedEvent.Origin.NetworkId);
+                        queuedEvent.Origin.DelayedEvents.Enqueue(queuedEvent);
-                        queuedEvent.Target = queuedEvent.Target == null ? null : queuedEvent.Owner.Players.FirstOrDefault(p => p != null && p.NetworkId == queuedEvent.Target.NetworkId);
+                        continue;
-                        // add it back to the queue for reprocessing
+                    }
-                        Handler.AddEvent(queuedEvent, true);
+
+                    if (GameEvent.ShouldTargetEventBeDelayed(queuedEvent))
+                    {
+                        Logger.WriteDebug($"Delaying target execution of event type {queuedEvent.Type} for {queuedEvent.Target} because they are not authed");
+                        // offload it to the player to keep
+                        queuedEvent.Target.DelayedEvents.Enqueue(queuedEvent);
                         continue;
                     }
                     await processEvent(queuedEvent);

Application/Server.cs

@@ -79,9 +79,7 @@ namespace IW4MAdmin
 
             if (Players[polledPlayer.ClientNumber] != null &&
                 Players[polledPlayer.ClientNumber].NetworkId == polledPlayer.NetworkId &&
-                // only update if they're unauthenticated
+                 Players[polledPlayer.ClientNumber].State == Player.ClientState.Connected)
-                Players[polledPlayer.ClientNumber].IsAuthenticated &&
-                Players[polledPlayer.ClientNumber].State == Player.ClientState.Connected)
             {
                 // update their ping & score 
                 Players[polledPlayer.ClientNumber].Ping = polledPlayer.Ping;
@@ -89,18 +87,19 @@ namespace IW4MAdmin
                 return true;
             }
 
-            if (Players[polledPlayer.ClientNumber] != null &&
+            if (Players[polledPlayer.ClientNumber] == null)
-                Players[polledPlayer.ClientNumber].State == Player.ClientState.Connected)
+            {
+                Players[polledPlayer.ClientNumber] = polledPlayer;
+            }
+
+            if (!polledPlayer.IsAuthenticated)
             {
                 return true;
             }
+            // if they're authenticated but haven't been added yet
+            // we want to set their delayed events
+            var delayedEventQueue = Players[polledPlayer.ClientNumber].DelayedEvents;
 
-            if (Players[polledPlayer.ClientNumber] == null)
-            {
-                //prevent duplicates from being added
-                polledPlayer.State = Player.ClientState.Connecting;
-                Players[polledPlayer.ClientNumber] = polledPlayer;
-            }
 #if !DEBUG
             if (polledPlayer.Name.Length < 3)
             {
@@ -175,15 +174,20 @@ namespace IW4MAdmin
                         await Manager.GetClientService().Update(client);
                     }
 
-                    else if (existingAlias.Name == polledPlayer.Name)
+                    else if (existingAlias.Name == polledPlayer.Name ||
+                        // fixme: why would this be null?
+                        client.CurrentAlias == null)
                     {
                         client.CurrentAlias = existingAlias;
                         client.CurrentAliasId = existingAlias.AliasId;
                         client = await Manager.GetClientService().Update(client);
                     }
+
                     player = client.AsPlayer();
                 }
 
+                Logger.WriteInfo($"Client {player} connected...");
+
                 // Do the player specific stuff
                 player.ClientNumber = polledPlayer.ClientNumber;
                 player.IsBot = polledPlayer.IsBot;
@@ -230,8 +234,6 @@ namespace IW4MAdmin
                     return true;
                 }
 
-                Logger.WriteInfo($"Client {player} connecting...");
-
                 if (!Manager.GetApplicationSettings().Configuration().EnableClientVPNs &&
                     await VPNCheck.UsingVPN(player.IPAddressString, Manager.GetApplicationSettings().Configuration().IPHubAPIKey))
                 {
@@ -247,12 +249,33 @@ namespace IW4MAdmin
                 };
                 Manager.GetEventHandler().AddEvent(e);
 
+                // add the delayed event to the queue 
+                while (delayedEventQueue?.Count > 0)
+                {
+                    e = delayedEventQueue.Dequeue();
+                    e.Origin = player;
+                    // check if the target was assigned
+                    if (e.Target != null)
+                    {
+                        // update the target incase they left or have newer info
+                        e.Target = GetPlayersAsList().FirstOrDefault(p => p.NetworkId == e.Target.NetworkId);
+                        // we have to throw out the event because they left
+                        if (e.Target == null)
+                        {
+                            Logger.WriteWarning($"Delayed event for {e.Origin} was removed because the target has left");
+                            continue;
+                        }
+                    }
+                    Manager.GetEventHandler().AddEvent(e);
+                }
+
                 return true;
             }
 
             catch (Exception E)
             {
                 Manager.GetLogger().WriteError($"{loc["SERVER_ERROR_ADDPLAYER"]} {polledPlayer.Name}::{polledPlayer.NetworkId}");
+                Manager.GetLogger().WriteDebug(E.Message);
                 Manager.GetLogger().WriteDebug(E.StackTrace);
                 return false;
             }
@@ -381,33 +404,42 @@ namespace IW4MAdmin
 
             else if (E.Type == GameEvent.EventType.Quit)
             {
-                var e = new GameEvent()
+                var origin = Players.FirstOrDefault(p => p != null && p.NetworkId == E.Origin.NetworkId);
-                {
-                    Type = GameEvent.EventType.Disconnect,
-                    Origin = Players.FirstOrDefault(p => p != null && p.NetworkId == E.Origin.NetworkId),
-                    Owner = this
-                };
 
-                if (e.Origin != null)
+                if (origin != null &&
+                    // we only want to forward the event if they are connected. 
+                    origin.State == Player.ClientState.Connected)
                 {
-                    e.Origin.State = Player.ClientState.Disconnecting;
+                    var e = new GameEvent()
+                    {
+                        Type = GameEvent.EventType.Disconnect,
+                        Origin = origin,
+                        Owner = this
+                    };
+
+                    if (e.Origin != null)
+                    {
+                        e.Origin.State = Player.ClientState.Disconnecting;
+                    }
+
+                    Manager.GetEventHandler().AddEvent(e);
                 }
 
-                Manager.GetEventHandler().AddEvent(e);
+                else if (origin != null &&
+                    origin.State == Player.ClientState.Connecting)
+                {
+                    await RemovePlayer(origin.ClientNumber);
+                }
             }
 
             else if (E.Type == GameEvent.EventType.Disconnect)
             {
-                // this may be a fix for a hard to reproduce null exception error
+                ChatHistory.Add(new ChatInfo()
-                lock (ChatHistory)
                 {
-                    ChatHistory.Add(new ChatInfo()
+                    Name = E.Origin.Name,
-                    {
+                    Message = "DISCONNECTED",
-                        Name = E.Origin.Name,
+                    Time = DateTime.UtcNow
-                        Message = "DISCONNECTED",
+                });
-                        Time = DateTime.UtcNow
-                    });
-                }
 
                 await RemovePlayer(E.Origin.ClientNumber);
             }
@@ -498,7 +530,6 @@ namespace IW4MAdmin
                 ChatHistory.Clear();
         }
 
-
         async Task<int> PollPlayersAsync()
         {
             var now = DateTime.Now;
@@ -546,14 +577,14 @@ namespace IW4MAdmin
 
             AuthQueue.AuthenticateClients(CurrentPlayers);
 
+
             // all polled players should be authenticated
-            foreach (var client in AuthQueue.GetAuthenticatedClients())
+            var addPlayerTasks = AuthQueue.GetAuthenticatedClients()
-            {
+                .Where(client => Players[client.ClientNumber] == null ||
-                if (Players[client.ClientNumber] == null || Players[client.ClientNumber].State == Player.ClientState.Connecting)
+                Players[client.ClientNumber].State == Player.ClientState.Connecting)
-                {
+                .Select(client => AddPlayer(client));
-                    await AddPlayer(client);
+
-                }
+            await Task.WhenAll(addPlayerTasks);
-            }
 
             return CurrentPlayers.Count;
         }

SharedLibraryCore/Event.cs

@@ -9,7 +9,7 @@ namespace SharedLibraryCore
         public enum EventType
         {
             Unknown,
-           
+
             // events "generated" by the server
             Start,
             Stop,
@@ -76,5 +76,35 @@ namespace SharedLibraryCore
         public ManualResetEventSlim OnProcessed { get; set; }
         public DateTime Time { get; private set; }
         public long Id { get; private set; }
+
+        /// <summary>
+        /// determine whether an event should be delayed or not
+        /// applies only to the origin entity
+        /// </summary>
+        /// <param name="queuedEvent">event to determine status for</param>
+        /// <returns>true if event should be delayed, false otherwise</returns>
+        public static bool ShouldOriginEventBeDelayed(GameEvent queuedEvent)
+        {
+            return queuedEvent.Origin != null &&
+                                    !queuedEvent.Origin.IsAuthenticated &&
+                                    // we want to allow join and quit events
+                                    queuedEvent.Type != EventType.Join &&
+                                    queuedEvent.Type != EventType.Quit &&
+                                    // we don't care about unknown events
+                                    queuedEvent.Origin.NetworkId != 0;
+        }
+
+        /// <summary>
+        /// determine whether an event should be delayed or not
+        /// applies only to the target entity
+        /// </summary>
+        /// <param name="queuedEvent">event to determine status for</param>
+        /// <returns>true if event should be delayed, false otherwise</returns>
+        public static bool ShouldTargetEventBeDelayed(GameEvent queuedEvent)
+        {
+            return queuedEvent.Target != null &&
+                                    !queuedEvent.Target.IsAuthenticated &&
+                                    queuedEvent.Target.NetworkId != 0;
+        }
     }
 }

SharedLibraryCore/Objects/Player.cs

@@ -33,6 +33,7 @@ namespace SharedLibraryCore.Objects
         {
             ConnectionTime = DateTime.UtcNow;
             ClientNumber = -1;
+            DelayedEvents = new Queue<GameEvent>();
         }
 
         public override string ToString()
@@ -120,6 +121,8 @@ namespace SharedLibraryCore.Objects
         public bool IsAuthenticated { get; set; }
         [NotMapped]
         public ClientState State { get; set; }
+        [NotMapped]
+        public Queue<GameEvent> DelayedEvents { get; set; }
 
         public override bool Equals(object obj)
         {

SharedLibraryCore/Utilities.cs

@@ -327,6 +327,7 @@ namespace SharedLibraryCore
                 LastConnection = client.LastConnection == DateTime.MinValue ? DateTime.UtcNow : client.LastConnection,
                 CurrentAlias = client.CurrentAlias,
                 CurrentAliasId = client.CurrentAlias.AliasId,
+                // todo: make sure this is up to date
                 IsBot = client.NetworkId == -1,
                 Password = client.Password,
                 PasswordSalt = client.PasswordSalt