game interface improvements

Application/IO/GameLogEventDetection.cs

@@ -21,7 +21,7 @@ namespace IW4MAdmin.Application.IO
         {
             _reader = gameLogReaderFactory.CreateGameLogReader(gameLogUris, server.EventParser);
             _server = server;
-            _ignoreBots = server?.Manager.GetApplicationSettings().Configuration().IgnoreBots ?? false;
+            _ignoreBots = server.Manager.GetApplicationSettings().Configuration()?.IgnoreBots ?? false;
             _logger = logger;
         }
 
@@ -69,7 +69,7 @@ namespace IW4MAdmin.Application.IO
                 return;
             }
 
-            var events = await _reader.ReadEventsFromLog(fileDiff, previousFileSize);
+            var events = await _reader.ReadEventsFromLog(fileDiff, previousFileSize, _server);
 
             foreach (var gameEvent in events)
             {

Application/IO/GameLogReader.cs

@@ -28,7 +28,7 @@ namespace IW4MAdmin.Application.IO
             _logger = logger;
         }
 
-        public async Task<IEnumerable<GameEvent>> ReadEventsFromLog(long fileSizeDiff, long startPosition)
+        public async Task<IEnumerable<GameEvent>> ReadEventsFromLog(long fileSizeDiff, long startPosition, Server server = null)
         {
             // allocate the bytes for the new log lines
             List<string> logLines = new List<string>();

Application/IO/GameLogReaderHttp.cs

@@ -34,7 +34,7 @@ namespace IW4MAdmin.Application.IO
 
         public int UpdateInterval => 500;
 
-        public async Task<IEnumerable<GameEvent>> ReadEventsFromLog(long fileSizeDiff, long startPosition)
+        public async Task<IEnumerable<GameEvent>> ReadEventsFromLog(long fileSizeDiff, long startPosition, Server server = null)
         {
             var events = new List<GameEvent>();
             var response = await _logServerApi.Log(_safeLogPath, lastKey);

Application/IO/NetworkGameLogReader.cs

@@ -5,92 +5,153 @@ using System.Collections.Generic;
 using System.Linq;
 using System.Net;
 using System.Net.Sockets;
+using System.Threading;
 using System.Threading.Tasks;
+using Integrations.Cod;
 using Microsoft.Extensions.Logging;
+using Serilog.Context;
 using ILogger = Microsoft.Extensions.Logging.ILogger;
 
 namespace IW4MAdmin.Application.IO
 {
     /// <summary>
-    /// provides capability of reading log files over HTTP
+    /// provides capability of reading log files over udp 
     /// </summary>
     class NetworkGameLogReader : IGameLogReader
     {
         private readonly IEventParser _eventParser;
-        private readonly UdpClient _udpClient;
         private readonly ILogger _logger;
+        private readonly Uri _uri;
+        private static readonly NetworkLogState State = new();
+        private bool _stateRegistered;
+        private CancellationToken _token;
 
-        public NetworkGameLogReader(Uri[] uris, IEventParser parser, ILogger<NetworkGameLogReader> logger)
+        public NetworkGameLogReader(IReadOnlyList<Uri> uris, IEventParser parser, ILogger<NetworkGameLogReader> logger)
         {
             _eventParser = parser;
-            try
-            {
-                var endPoint = new IPEndPoint(Dns.GetHostAddresses(uris[0].Host).First(), uris[0].Port);
-                _udpClient = new UdpClient(endPoint);
-            }
-            catch (Exception ex)
-            {
-                logger.LogError(ex, "Could setup {LogReader}", nameof(NetworkGameLogReader));
-            }
-
+            _uri = uris[0];
             _logger = logger;
         }
 
         public long Length => -1;
 
-        public int UpdateInterval => 500;
+        public int UpdateInterval => 150;
 
-        public async Task<IEnumerable<GameEvent>> ReadEventsFromLog(long fileSizeDiff, long startPosition)
+        public Task<IEnumerable<GameEvent>> ReadEventsFromLog(long fileSizeDiff, long startPosition,
+            Server server = null)
         {
-            if (_udpClient == null)
+            // todo: other games might support this
+            var serverEndpoint = (server?.RemoteConnection as CodRConConnection)?.Endpoint;
+
+            if (serverEndpoint is null)
             {
-                return Enumerable.Empty<GameEvent>();
+                return Task.FromResult(Enumerable.Empty<GameEvent>());
             }
 
-            byte[] buffer;
-            try
-            {
-                buffer = (await _udpClient.ReceiveAsync()).Buffer;
-            }
-            catch (Exception ex)
-            {
-                _logger.LogError(ex, "Could receive lines for {LogReader}", nameof(NetworkGameLogReader));
-                return Enumerable.Empty<GameEvent>();
-            }
-
-            if (!buffer.Any())
-            {
-                return Enumerable.Empty<GameEvent>();
-            }
-
-            var logData = Utilities.EncodingType.GetString(buffer);
-
-            if (string.IsNullOrWhiteSpace(logData))
-            {
-                return Enumerable.Empty<GameEvent>();
-            }
-
-            var lines = logData
-                .Split('\n')
-                .Where(line => line.Length > 0);
-
-            var events = new List<GameEvent>();
-            foreach (var eventLine in lines)
+            if (!_stateRegistered && !State.EndPointExists(serverEndpoint))
             {
                 try
                 {
-                    // this trim end should hopefully fix the nasty runaway regex
-                    var gameEvent = _eventParser.GenerateGameEvent(eventLine.TrimEnd('\r'));
-                    events.Add(gameEvent);
-                }
+                    var client = State.RegisterEndpoint(serverEndpoint, BuildLocalEndpoint()).Client;
 
+                    _stateRegistered = true;
+                    _token = server.Manager.CancellationToken;
+
+                    if (client == null)
+                    {
+                        using (LogContext.PushProperty("Server", server.ToString()))
+                        {
+                            _logger.LogInformation("Not registering {Name} socket because it is already bound",
+                                nameof(NetworkGameLogReader));
+                        }
+                        return Task.FromResult(Enumerable.Empty<GameEvent>());
+                    }
+                    
+                    new Thread(() => ReadNetworkData(client)).Start();
+                }
                 catch (Exception ex)
                 {
-                    _logger.LogError(ex, "Could not properly parse event line from http {eventLine}", eventLine);
+                    _logger.LogError(ex, "Could not register {Name} endpoint {Endpoint}",
+                        nameof(NetworkGameLogReader), _uri);
+                    throw;
                 }
             }
 
-            return events;
+            var events = new List<GameEvent>();
+
+            foreach (var logData in State.GetServerLogData(serverEndpoint)
+                         .Select(log => Utilities.EncodingType.GetString(log)))
+            {
+                if (string.IsNullOrWhiteSpace(logData))
+                {
+                    return Task.FromResult(Enumerable.Empty<GameEvent>());
+                }
+
+                var lines = logData
+                    .Split('\n')
+                    .Where(line => line.Length > 0);
+
+                foreach (var eventLine in lines)
+                {
+                    try
+                    {
+                        // this trim end should hopefully fix the nasty runaway regex
+                        var gameEvent = _eventParser.GenerateGameEvent(eventLine.TrimEnd('\r'));
+                        events.Add(gameEvent);
+                    }
+
+                    catch (Exception ex)
+                    {
+                        _logger.LogError(ex, "Could not properly parse event line from http {EventLine}",
+                            eventLine);
+                    }
+                }
+            }
+
+            return Task.FromResult((IEnumerable<GameEvent>)events);
+        }
+
+        private void ReadNetworkData(UdpClient client)
+        {
+            while (!_token.IsCancellationRequested)
+            {
+                // get more data
+                IPEndPoint remoteEndpoint = null;
+                byte[] bufferedData = null;
+
+                if (client == null)
+                {
+                    // we already have a socket listening on this port for data, so we don't need to run another thread
+                    break;
+                }
+
+                try
+                {
+                    bufferedData = client.Receive(ref remoteEndpoint);
+                }
+                catch (Exception ex)
+                {
+                    _logger.LogError(ex, "Could not receive lines for {LogReader}", nameof(NetworkGameLogReader));
+                }
+
+                if (bufferedData != null)
+                {
+                    State.QueueServerLogData(remoteEndpoint, bufferedData);
+                }
+            }
+        }
+
+        private IPEndPoint BuildLocalEndpoint()
+        {
+            try
+            {
+                return new IPEndPoint(Dns.GetHostAddresses(_uri.Host).First(), _uri.Port);
+            }
+            catch (Exception ex)
+            {
+                _logger.LogError(ex, "Could not setup {LogReader} endpoint", nameof(NetworkGameLogReader));
+                throw;
+            }
         }
     }
 }

Application/IO/NetworkLogState.cs

@@ -0,0 +1,138 @@
+using System.Collections.Generic;
+using System.Linq;
+using System.Net;
+using System.Net.Sockets;
+using System.Threading;
+
+namespace IW4MAdmin.Application.IO;
+
+public class NetworkLogState : Dictionary<IPEndPoint, UdpClientState>
+{
+    public UdpClientState RegisterEndpoint(IPEndPoint serverEndpoint, IPEndPoint localEndpoint)
+    {
+        try
+        {
+            lock (this)
+            {
+                if (!ContainsKey(serverEndpoint))
+                {
+                    Add(serverEndpoint, new UdpClientState { Client = new UdpClient(localEndpoint) });
+                }
+            }
+        }
+        catch (SocketException ex) when (ex.SocketErrorCode == SocketError.AddressAlreadyInUse)
+        {
+            lock (this)
+            {
+                // we don't add the udp client because it already exists (listening to multiple servers from one socket)
+                Add(serverEndpoint,  new UdpClientState());
+            }
+        }
+
+        return this[serverEndpoint];
+    }
+
+
+    public List<byte[]> GetServerLogData(IPEndPoint serverEndpoint)
+    {
+        try
+        {
+            var state = this[serverEndpoint];
+            
+            if (state == null)
+            {
+                return new List<byte[]>();
+            }
+            
+            // it's possible that we could be trying to read and write to the queue simultaneously so we need to wait 
+            this[serverEndpoint].OnAction.Wait();
+
+            var data = new List<byte[]>();
+            
+            while (this[serverEndpoint].AvailableLogData.Count > 0)
+            {
+                data.Add(this[serverEndpoint].AvailableLogData.Dequeue());
+            }
+           
+            return data;
+        }
+        finally
+        {
+            if (this[serverEndpoint].OnAction.CurrentCount == 0)
+            {
+                this[serverEndpoint].OnAction.Release(1);
+            }
+        }
+    }
+
+    public void QueueServerLogData(IPEndPoint serverEndpoint, byte[] data)
+    {
+        var endpoint = Keys.FirstOrDefault(key =>
+            Equals(key.Address, serverEndpoint.Address) && key.Port == serverEndpoint.Port);
+
+        try
+        {
+            if (endpoint == null)
+            {
+                return;
+            }
+
+            // currently our expected start and end characters
+            var startsWithPrefix = StartsWith(data, "ÿÿÿÿprint\n");
+            var endsWithDelimiter = data[^1] == '\n';
+
+            // we have the data we expected
+            if (!startsWithPrefix || !endsWithDelimiter)
+            {
+                return;
+            }
+
+            // it's possible that we could be trying to read and write to the queue simultaneously so we need to wait 
+            this[endpoint].OnAction.Wait();
+            this[endpoint].AvailableLogData.Enqueue(data);
+        }
+        finally
+        {
+            if (endpoint != null && this[endpoint].OnAction.CurrentCount == 0)
+            {
+                this[endpoint].OnAction.Release(1);
+            }
+        }
+    }
+
+    public bool EndPointExists(IPEndPoint serverEndpoint)
+    {
+        lock (this)
+        {
+            return ContainsKey(serverEndpoint);
+        }
+    }
+
+    private static bool StartsWith(byte[] sourceArray, string match)
+    {
+        if (sourceArray is null)
+        {
+            return false;
+        }
+        
+        if (match.Length > sourceArray.Length)
+        {
+            return false;
+        }
+
+        return !match.Where((t, i) => sourceArray[i] != (byte)t).Any();
+    }
+}
+
+public class UdpClientState
+{
+    public UdpClient Client { get; set; }
+    public Queue<byte[]> AvailableLogData { get; } = new();
+    public SemaphoreSlim OnAction { get; } = new(1, 1);
+
+    ~UdpClientState()
+    {
+        OnAction.Dispose();
+        Client?.Dispose();
+    }
+}

Application/IW4MServer.cs

@@ -236,7 +236,7 @@ namespace IW4MAdmin
         private async Task CreatePluginTask(IPlugin plugin, GameEvent gameEvent)
         {
             // we don't want to run the events on parser plugins
-            if (plugin is ScriptPlugin scriptPlugin && scriptPlugin.IsParser)
+            if (plugin is ScriptPlugin { IsParser: true })
             {
                 return;
             }
@@ -248,6 +248,11 @@ namespace IW4MAdmin
             {
                 await plugin.OnEventAsync(gameEvent, this).WithWaitCancellation(tokenSource.Token);
             }
+            catch (OperationCanceledException)
+            {
+                ServerLogger.LogWarning("Timed out executing event {EventType} for {Plugin}", gameEvent.Type,
+                    plugin.Name);
+            }
             catch (Exception ex)
             {
                 Console.WriteLine(loc["SERVER_PLUGIN_ERROR"].FormatExt(plugin.Name, ex.GetType().Name));

Application/Misc/ScriptPlugin.cs

@@ -223,47 +223,49 @@ namespace IW4MAdmin.Application.Misc
 
         public async Task OnEventAsync(GameEvent gameEvent, Server server)
         {
-            if (_successfullyLoaded)
+            if (!_successfullyLoaded)
             {
-                try
-                {
-                    await _onProcessing.WaitAsync();
-                    _scriptEngine.SetValue("_gameEvent", gameEvent);
-                    _scriptEngine.SetValue("_server", server);
-                    _scriptEngine.SetValue("_IW4MAdminClient", Utilities.IW4MAdminClient(server));
-                    _scriptEngine.Evaluate("plugin.onEventAsync(_gameEvent, _server)");
-                }
-                
-                catch (JavaScriptException ex)
-                {
-                    using (LogContext.PushProperty("Server", server.ToString()))
-                    {
-                        _logger.LogError(ex,
-                            "Encountered JavaScript runtime error while executing {MethodName} for script plugin {Plugin} with event type {EventType} {@LocationInfo}",
-                            nameof(OnEventAsync), Path.GetFileName(_fileName), gameEvent.Type, ex.Location);
-                    }
+                return;
+            }
 
-                    throw new PluginException("An error occured while executing action for script plugin");
+            try
+            {
+                await _onProcessing.WaitAsync();
+                _scriptEngine.SetValue("_gameEvent", gameEvent);
+                _scriptEngine.SetValue("_server", server);
+                _scriptEngine.SetValue("_IW4MAdminClient", Utilities.IW4MAdminClient(server));
+                _scriptEngine.Evaluate("plugin.onEventAsync(_gameEvent, _server)");
+            }
+
+            catch (JavaScriptException ex)
+            {
+                using (LogContext.PushProperty("Server", server.ToString()))
+                {
+                    _logger.LogError(ex,
+                        "Encountered JavaScript runtime error while executing {MethodName} for script plugin {Plugin} with event type {EventType} {@LocationInfo}",
+                        nameof(OnEventAsync), Path.GetFileName(_fileName), gameEvent.Type, ex.Location);
                 }
 
-                catch (Exception ex)
-                {
-                    using (LogContext.PushProperty("Server", server.ToString()))
-                    {
-                        _logger.LogError(ex,
-                            "Encountered error while running {MethodName} for script plugin {Plugin} with event type {EventType}",
-                            nameof(OnEventAsync), _fileName, gameEvent.Type);
-                    }
+                throw new PluginException("An error occured while executing action for script plugin");
+            }
 
-                    throw new PluginException("An error occured while executing action for script plugin");
+            catch (Exception ex)
+            {
+                using (LogContext.PushProperty("Server", server.ToString()))
+                {
+                    _logger.LogError(ex,
+                        "Encountered error while running {MethodName} for script plugin {Plugin} with event type {EventType}",
+                        nameof(OnEventAsync), _fileName, gameEvent.Type);
                 }
 
-                finally
+                throw new PluginException("An error occured while executing action for script plugin");
+            }
+
+            finally
+            {
+                if (_onProcessing.CurrentCount == 0)
                 {
-                    if (_onProcessing.CurrentCount == 0)
-                    {
-                        _onProcessing.Release(1);
-                    }
+                    _onProcessing.Release(1);
                 }
             }
         }

GameFiles/IW4x/userraw/scripts/_integration.gsc

@@ -33,7 +33,12 @@ init()
     level.eventCallbacks[level.eventTypes.clientDataReceived]       = ::OnClientDataReceived;
     level.eventCallbacks[level.eventTypes.executeCommandRequested]  = ::OnExecuteCommand; 
     level.eventCallbacks[level.eventTypes.setClientDataCompleted]   = ::OnSetClientDataCompleted;
-
+    
+    if ( GetDvarInt( "sv_iw4madmin_integration_enabled" ) != 1 )
+    {
+        return;
+    }
+    
     // start long running tasks
     level thread MonitorClientEvents();
     level thread MonitorBus();
@@ -233,6 +238,7 @@ SaveTrackingMetrics()
 
     currentShotCount = self getPlayerStat( "mostshotsfired" );
     change = currentShotCount - self.lastShotCount;
+    self.lastShotCount = currentShotCount;
 
     if ( level.iw4adminIntegrationDebug == 1 )
     {
@@ -251,7 +257,6 @@ SaveTrackingMetrics()
 
     IncrementClientMeta( "TotalShotsFired", change, self.persistentClientId );
 
-    self.lastShotCount = currentShotCount;
 }
 
 BuildEventRequest( responseExpected, eventType, eventSubtype, entOrId, data ) 

IW4MAdmin.sln

@@ -13,6 +13,7 @@ Project("{2150E333-8FDC-42A3-9474-1A3956D46DE8}") = "Solution Items", "Solution
 		version.txt = version.txt
 		DeploymentFiles\UpdateIW4MAdmin.ps1 = DeploymentFiles\UpdateIW4MAdmin.ps1
 		DeploymentFiles\UpdateIW4MAdmin.sh = DeploymentFiles\UpdateIW4MAdmin.sh
+		GameFiles\IW4x\userraw\scripts\_integration.gsc = GameFiles\IW4x\userraw\scripts\_integration.gsc
 	EndProjectSection
 EndProject
 Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "SharedLibraryCore", "SharedLibraryCore\SharedLibraryCore.csproj", "{AA0541A2-8D51-4AD9-B0AC-3D1F5B162481}"

Plugins/ScriptPlugins/GameInterface.js

@@ -17,12 +17,16 @@ let plugin = {
     name: 'Game Interface',
 
     onEventAsync: (gameEvent, server) => {
-        const eventType = eventTypes[gameEvent.Type];
-
         if (servers[server.EndPoint] != null && !servers[server.EndPoint].enabled) {
             return;
         }
 
+        const eventType = eventTypes[gameEvent.Type];
+        
+        if (eventType === undefined) {
+            return;
+        }
+        
         switch (eventType) {
             case 'start':
                 const enabled = initialize(server);
@@ -33,7 +37,7 @@ let plugin = {
                 break;
             case 'preconnect':
                 // when the plugin is reloaded after the servers are started
-                if (servers[server.EndPoint] == null) {
+                if (servers[server.EndPoint] === undefined || servers[server.EndPoint] == null) {
                     const enabled = initialize(server);
 
                     if (!enabled) {
@@ -218,7 +222,7 @@ const sendEvent = (server, responseExpected, event, subtype, client, data) => {
     let pendingCheckCount = 0;
     const start = new Date();
 
-    while (pendingOut && pendingCheckCount <= 30) {
+    while (pendingOut && pendingCheckCount <= 10) {
         try {
             const out = server.GetServerDvar(outDvar);
             pendingOut = !(out == null || out === '' || out === 'null');
@@ -265,6 +269,11 @@ const parseEvent = (input) => {
 
 const initialize = (server) => {
     const logger = _serviceResolver.ResolveService('ILogger');
+
+    servers[server.EndPoint] = {
+        enabled: false
+    }
+    
     let enabled = false;
     try {
         enabled = server.GetServerDvar('sv_iw4madmin_integration_enabled') === '1';
@@ -275,9 +284,6 @@ const initialize = (server) => {
     logger.WriteInfo(`GSC Integration enabled = ${enabled}`);
 
     if (!enabled) {
-        servers[server.EndPoint] = {
-            enabled: false
-        }
         return false;
     }
 
@@ -288,10 +294,8 @@ const initialize = (server) => {
     // necessary to prevent multi-threaded access to the JS context
     timer.SetDependency(_lock);
 
-    servers[server.EndPoint] = {
-        timer: timer,
-        enabled: true
-    }
+    servers[server.EndPoint].timer = timer;
+    servers[server.EndPoint].enabled = true;
 
     try {
         server.SetServerDvar(inDvar, '');

SharedLibraryCore/Interfaces/IGameLogReader.cs

@@ -23,7 +23,8 @@ namespace SharedLibraryCore.Interfaces
         /// </summary>
         /// <param name="fileSizeDiff"></param>
         /// <param name="startPosition"></param>
+        /// <param name="server"></param>
         /// <returns></returns>
-        Task<IEnumerable<GameEvent>> ReadEventsFromLog(long fileSizeDiff, long startPosition);
+        Task<IEnumerable<GameEvent>> ReadEventsFromLog(long fileSizeDiff, long startPosition, Server server);
     }
-}
+}

SharedLibraryCore/Server.cs

@@ -390,17 +390,48 @@ namespace SharedLibraryCore
 
         public string[] ExecuteServerCommand(string command)
         {
-            return this.ExecuteCommandAsync(command).GetAwaiter().GetResult();
+            var tokenSource = new CancellationTokenSource();
+            tokenSource.CancelAfter(TimeSpan.FromMilliseconds(400));
+
+            try
+            {
+                return this.ExecuteCommandAsync(command).WithWaitCancellation(tokenSource.Token).GetAwaiter().GetResult();
+            }
+            catch
+            {
+                return null;
+            }
         }
 
         public string GetServerDvar(string dvarName)
         {
-            return this.GetDvarAsync<string>(dvarName).GetAwaiter().GetResult()?.Value;
+            var tokenSource = new CancellationTokenSource();
+            tokenSource.CancelAfter(TimeSpan.FromSeconds(400));
+            try
+            {
+                return this.GetDvarAsync<string>(dvarName).WithWaitCancellation(tokenSource.Token).GetAwaiter()
+                    .GetResult()?.Value;
+            }
+            catch
+            {
+                return null;
+            }
         }
 
-        public void SetServerDvar(string dvarName, string dvarValue)
+        public bool SetServerDvar(string dvarName, string dvarValue)
         {
-            this.SetDvarAsync(dvarName, dvarValue).GetAwaiter().GetResult();
+            var tokenSource = new CancellationTokenSource();
+            tokenSource.CancelAfter(TimeSpan.FromSeconds(400));
+            try
+            {
+                this.SetDvarAsync(dvarName, dvarValue).WithWaitCancellation(tokenSource.Token).GetAwaiter().GetResult();
+                return true;
+
+            }
+            catch
+            {
+                return false;
+            }
         }
 
         public EFClient GetClientByNumber(int clientNumber) =>

SharedLibraryCore/Utilities.cs

@@ -956,6 +956,19 @@ namespace SharedLibraryCore
             }
         }
 
+        public static async Task<T> WithWaitCancellation<T>(this Task<T> task,
+            CancellationToken cancellationToken)
+        {
+            var completedTask = await Task.WhenAny(task, Task.Delay(Timeout.Infinite, cancellationToken));
+            if (completedTask == task)
+            {
+                return await task;
+            }
+
+            cancellationToken.ThrowIfCancellationRequested();
+            throw new InvalidOperationException("Infinite delay task completed.");
+        }
+
         public static async Task<T> WithTimeout<T>(this Task<T> task, TimeSpan timeout)
         {
             await Task.WhenAny(task, Task.Delay(timeout));