more integration tweaks

Application/Main.cs

@@ -311,9 +311,9 @@ namespace IW4MAdmin.Application
             }
 
             // register any script plugins
-            foreach (var func in pluginImporter.DiscoverScriptPlugins())
+            foreach (var plugin in pluginImporter.DiscoverScriptPlugins())
             {
-                serviceCollection.AddSingleton(sp => func(sp));
+                serviceCollection.AddSingleton(plugin);
             }
 
             // register any eventable types

Application/Misc/PluginImporter.cs

@@ -38,13 +38,13 @@ namespace IW4MAdmin.Application.Misc
         /// discovers all the script plugins in the plugins dir
         /// </summary>
         /// <returns></returns>
-        public IEnumerable<Func<IServiceProvider, IPlugin>> DiscoverScriptPlugins()
+        public IEnumerable<IPlugin> DiscoverScriptPlugins()
         {
             var pluginDir = $"{Utilities.OperatingDirectory}{PLUGIN_DIR}{Path.DirectorySeparatorChar}";
 
             if (!Directory.Exists(pluginDir))
             {
-                return Enumerable.Empty<Func<IServiceProvider, IPlugin>>();
+                return Enumerable.Empty<IPlugin>();
             }
 
             var scriptPluginFiles =
@@ -52,11 +52,10 @@ namespace IW4MAdmin.Application.Misc
 
             _logger.LogDebug("Discovered {count} potential script plugins", scriptPluginFiles.Count);
 
-            return scriptPluginFiles.Select<string, Func<IServiceProvider, IPlugin>>(fileName => serviceProvider =>
+            return scriptPluginFiles.Select(fileName =>
             {
                 _logger.LogDebug("Discovered script plugin {fileName}", fileName);
-                return new ScriptPlugin(_logger,
+                return new ScriptPlugin(_logger, fileName);
-                    serviceProvider.GetRequiredService<IScriptPluginTimerHelper>(), fileName);
             }).ToList();
         }
 

Application/Misc/ScriptPlugin.cs

@@ -45,9 +45,8 @@ namespace IW4MAdmin.Application.Misc
         private bool _successfullyLoaded;
         private readonly List<string> _registeredCommandNames;
         private readonly ILogger _logger;
-        private readonly IScriptPluginTimerHelper _timerHelper;
 
-        public ScriptPlugin(ILogger logger, IScriptPluginTimerHelper timerHelper, string filename, string workingDirectory = null)
+        public ScriptPlugin(ILogger logger, string filename, string workingDirectory = null)
         {
             _logger = logger;
             _fileName = filename;
@@ -60,8 +59,6 @@ namespace IW4MAdmin.Application.Misc
 
             Watcher.EnableRaisingEvents = true;
             _registeredCommandNames = new List<string>();
-            _timerHelper = timerHelper;
-            _timerHelper.SetDependency(_onProcessing);
         }
 
         ~ScriptPlugin()
@@ -127,6 +124,7 @@ namespace IW4MAdmin.Application.Misc
                 _scriptEngine.Execute(script);
                 _scriptEngine.SetValue("_localization", Utilities.CurrentLocalization);
                 _scriptEngine.SetValue("_serviceResolver", serviceResolver);
+                _scriptEngine.SetValue("_lock", _onProcessing);
                 dynamic pluginObject = _scriptEngine.Evaluate("plugin").ToObject();
 
                 Author = pluginObject.author;
@@ -276,7 +274,6 @@ namespace IW4MAdmin.Application.Misc
             {
                 _logger.LogDebug("OnLoad executing for {Name}", Name);
                 _scriptEngine.SetValue("_manager", manager);
-                _scriptEngine.SetValue("_timerHelper", _timerHelper);
                 _scriptEngine.Evaluate("plugin.onLoadAsync(_manager)");
 
                 return Task.CompletedTask;

Application/Misc/ScriptPluginTimerHelper.cs

@@ -120,7 +120,7 @@ public class ScriptPluginTimerHelper : IScriptPluginTimerHelper
         {
             if (!_onRunningTick.IsSet)
             {
-                _logger.LogWarning("Previous {OnTick} is still running, so we are skipping this one",
+                _logger.LogDebug("Previous {OnTick} is still running, so we are skipping this one",
                     nameof(OnTick));
                 return;
             }
@@ -129,7 +129,9 @@ public class ScriptPluginTimerHelper : IScriptPluginTimerHelper
 
             // the js engine is not thread safe so we need to ensure we're not executing OnTick and OnEventAsync simultaneously
             _onDependentAction?.WaitAsync().Wait();
+            var start = DateTime.Now;
             _jsAction.DynamicInvoke(JsValue.Undefined, new[] { JsValue.Undefined });
+            _logger.LogDebug("OnTick took {Time}ms", (DateTime.Now - start).TotalMilliseconds);
             ReleaseThreads();
         }
 

GameFiles/IW4x/userraw/scripts/_integration.gsc

@@ -6,11 +6,15 @@
 init()
 {
     // setup default vars
-    level.eventBus          = spawnstruct();
+    level.eventBus              = spawnstruct();
-    level.eventBus.inVar    = "sv_iw4madmin_in";
+    level.eventBus.inVar        = "sv_iw4madmin_in";
-    level.eventBus.outVar   = "sv_iw4madmin_out";
+    level.eventBus.outVar       = "sv_iw4madmin_out";
-    level.clientDataKey     = "clientData";
+    level.eventBus.failKey      = "fail";
+    level.eventBus.timeoutKey   = "timeout";
+    level.eventBus.timeout      = 10;
     
+    level.clientDataKey = "clientData";
+
     level.eventTypes                            = spawnstruct();
     level.eventTypes.clientDataReceived         = "ClientDataReceived";
     level.eventTypes.clientDataRequested        = "ClientDataRequested";
@@ -19,6 +23,7 @@ init()
     SetDvarIfUninitialized( level.eventBus.inVar, "" );
     SetDvarIfUninitialized( level.eventBus.outVar, "" );
     SetDvarIfUninitialized( "sv_iw4madmin_integration_enabled", 1 );
+    SetDvarIfUninitialized( "sv_iw4madmin_integration_debug", 0 );
     
     // map the event type to the handler
     level.eventCallbacks = [];
@@ -42,7 +47,14 @@ OnPlayerConnect()
     for ( ;; )
     {
         level waittill( "connected", player );
-        player.pers[level.clientDataKey] = spawnstruct();
+        
+        level.iw4adminIntegrationDebug = GetDvarInt( "sv_iw4madmin_integration_debug" );
+        
+        if ( !isDefined( player.pers[level.clientDataKey] ) )
+        {
+            player.pers[level.clientDataKey] = spawnstruct();
+        }
+        
         player thread OnPlayerSpawned();
     }
 }
@@ -64,7 +76,10 @@ DisplayWelcomeData()
 
     clientData = self.pers[level.clientDataKey];
     
-    self IPrintLnBold( "Welcome, your level is ^5" + clientData.permissionLevel );
+    if ( clientData.permissionLevel != "User" )
+    { 
+        self IPrintLnBold( "Welcome, your level is ^5" + clientData.permissionLevel );
+    }
     wait (2.0);
     self IPrintLnBold( "You were last seen ^5" + clientData.lastConnection );
 }
@@ -75,11 +90,14 @@ PlayerConnectEvents()
     
     clientData = self.pers[level.clientDataKey];
     
+    // this gives IW4MAdmin some time to register the player before making the request;
+    wait ( 2 );
+
     if ( isDefined( clientData.state ) && clientData.state == "complete" ) 
     {
         return;
     }
-
+    
     self RequestClientBasicData();
     // example of requesting meta from IW4MAdmin
     // self RequestClientMeta( "LastServerPlayed" );
@@ -94,7 +112,10 @@ PlayerWaitEvents()
     {
         level waittill( "client_event", client );
  
-        /#self IPrintLn("Processing Event " + client.event.type + "-" + client.event.subtype );#/
+        if ( level.iw4adminIntegrationDebug == 1 )
+        {
+            self IPrintLn( "Processing Event " + client.event.type + "-" + client.event.subtype );
+        }
         
         eventHandler = level.eventCallbacks[client.event.type];
 
@@ -166,8 +187,10 @@ MonitorBus()
         {
             continue;
         }
-        
+        if ( level.iw4adminIntegrationDebug == 1 )
-        /#IPrintLn( "-> " + eventString );#/
+        {
+            IPrintLn( "-> " + eventString );
+        }
         
         NotifyClientEvent( strtok( eventString, ";" ) );
         
@@ -180,16 +203,19 @@ QueueEvent( request, eventType )
     self endon( "disconnect" );
    
     start = GetTime();
-    maxWait = 15 * 1000; // 15 seconds
+    maxWait = level.eventBus.timeout * 1000; // 10 seconds
     timedOut = "";
    
     while ( GetDvar( level.eventBus.inVar ) != "" && ( GetTime() - start ) < maxWait )
     {
-        level waittill_notify_or_timeout( "bus_ready", 5 );
+        level waittill_notify_or_timeout( "bus_ready", 1 );
         
         if ( GetDvar( level.eventBus.inVar ) != "" )
         {
-            /#self IPrintLn("A request is already in progress...");#/
+            if ( level.iw4adminIntegrationDebug == 1 )
+            {
+                self IPrintLn( "A request is already in progress..." );
+            }
             timedOut = "set";
             continue;
         }
@@ -199,15 +225,21 @@ QueueEvent( request, eventType )
    
     if ( timedOut == "set")
     {
-        /# self IPrintLn("Timed out waiting for response...");#/
+        if ( level.iw4adminIntegrationDebug == 1 )
-        if ( eventType == level.eventTypes.clientDataRequested ) // todo: this is dirty fix
         {
-            self.pers["clientData"].state = "failed";
+            self IPrintLn( "Timed out waiting for response..." );
         }
+        
+        NotifyClientEventTimeout( eventType );
+
         return;
     }
-   
+    
-    /#IPrintLn("<- " + request);#/
+    if ( level.iw4adminIntegrationDebug == 1 )
+    {
+        IPrintLn("<- " + request);
+    }
+    
     SetDvar( level.eventBus.inVar, request );
 }
 
@@ -230,6 +262,15 @@ ParseDataString( data )
     return dict;
 }
 
+NotifyClientEventTimeout( eventType ) 
+{
+    // todo: make this actual eventing
+    if ( eventType == level.eventTypes.clientDataRequested )
+    {
+        self.pers["clientData"].state = level.eventBus.timeoutKey;
+    }
+}
+
 NotifyClientEvent( eventInfo )
 {
     client = getPlayerFromClientNum( int( eventInfo[3] ) );
@@ -239,7 +280,10 @@ NotifyClientEvent( eventInfo )
     event.subtype = eventInfo[2];
     event.data = eventInfo[4];
     
-    /#IPrintLn(event.data);#/
+    if ( level.iw4adminIntegrationDebug == 1 )
+    {
+        IPrintLn(event.data);
+    }
     
     client.event = event;
 
@@ -255,6 +299,16 @@ OnClientDataReceived( event )
     event.data = ParseDataString( event.data );
     clientData = self.pers[level.clientDataKey];
 
+    if ( event.subtype == "Fail" ) 
+    {
+        if ( level.iw4adminIntegrationDebug == 1 )
+        {
+            IPrintLn( "Received fail response" );
+        }
+        clientData.state = level.eventBus.failKey;
+        return;
+    }
+
     if ( event.subtype == "Meta" )
     {
         if ( !isDefined( clientData["meta"] ) )

IW4MAdmin.sln

@@ -6,7 +6,6 @@ Project("{2150E333-8FDC-42A3-9474-1A3956D46DE8}") = "Plugins", "Plugins", "{26E8
 EndProject
 Project("{2150E333-8FDC-42A3-9474-1A3956D46DE8}") = "Solution Items", "Solution Items", "{8C8F3945-0AEF-4949-A1F7-B18E952E50BC}"
 	ProjectSection(SolutionItems) = preProject
-		GameFiles\IW4x\userraw\scripts\_commands.gsc = GameFiles\IW4x\userraw\scripts\_commands.gsc
 		GameFiles\IW4x\userraw\scripts\_customcallbacks.gsc = GameFiles\IW4x\userraw\scripts\_customcallbacks.gsc
 		DeploymentFiles\deployment-pipeline.yml = DeploymentFiles\deployment-pipeline.yml
 		DeploymentFiles\PostPublish.ps1 = DeploymentFiles\PostPublish.ps1

Plugins/ScriptPlugins/GameInterface.js

@@ -8,7 +8,7 @@
 const servers = {};
 const inDvar = 'sv_iw4madmin_in';
 const outDvar = 'sv_iw4madmin_out';
-const pollRate = 1000;
+const pollRate = 750;
 let logger = {};
 
 let plugin = {
@@ -67,7 +67,9 @@ let plugin = {
 
     onUnloadAsync: () => {
         for (let i = 0; i < servers.length; i++) {
-            servers[i].timer.Stop();
+            if (servers[i].enabled) {
+                servers[i].timer.Stop();
+            }
         }
     },
 
@@ -219,9 +221,12 @@ const sendEvent = (server, responseExpected, event, subtype, client, data) => {
 
     let pendingOut = true;
     let pendingCheckCount = 0;
-    while (pendingOut === true && pendingCheckCount <= 10) {
+    const start = new Date();
+    
+    while (pendingOut && pendingCheckCount <= 30) {
         try {
-            pendingOut = server.GetServerDvar(outDvar) !== null;
+            const out = server.GetServerDvar(outDvar);
+            pendingOut =  !(out == null || out === '' || out === 'null');
         } catch (error) {
             logger.WriteError(`Could not check server output dvar for IO status ${error}`);
         }
@@ -233,22 +238,16 @@ const sendEvent = (server, responseExpected, event, subtype, client, data) => {
         pendingCheckCount++;
     }
 
-    if (pendingCheckCount === true) {
+    if (pendingOut) {
         logger.WriteWarning(`Reached maximum attempts waiting for output to be available for ${server.EndPoint}`)
     }
 
-    let clientNumber = '';
+    const output = `${responseExpected ? '1' : '0'};${event};${subtype};${client.ClientNumber};${buildDataString(data)}`;
-    if (client !== undefined) {
-        clientNumber = client.ClientNumber;
-    }
-    if (responseExpected === undefined) {
-        responseExpected = 0;
-    }
-    const output = `${responseExpected ? '1' : '0'};${event};${subtype};${clientNumber};${buildDataString(data)}`;
     logger.WriteDebug(`Sending output to server ${output}`);
 
     try {
         server.SetServerDvar(outDvar, output);
+        logger.WriteDebug(`SendEvent took ${(new Date() - start) / 1000}ms`);
     } catch (error) {
         logger.WriteError(`Could not set server output dvar ${error}`);
     }
@@ -289,8 +288,10 @@ const initialize = (server) => {
 
     logger.WriteDebug(`Setting up bus timer for ${server.EndPoint}`);
 
-    let timer = _timerHelper;
+    let timer = _serviceResolver.ResolveService('IScriptPluginTimerHelper');
-    timer.OnTick(() => pollForEvents(server), `GameEventPoller ${server.ToString()}`)
+    timer.OnTick(() => pollForEvents(server), `GameEventPoller ${server.ToString()}`);
+    // necessary to prevent multi-threaded access to the JS context
+    timer.SetDependency(_lock);
 
     servers[server.EndPoint] = {
         timer: timer,
@@ -323,7 +324,6 @@ const pollForEvents = server => {
     }
 
     if (input.length > 0) {
-
         const event = parseEvent(input)
 
         logger.WriteDebug(`Processing input... ${event.eventType} ${event.subType} ${event.data} ${event.clientNumber}`);
@@ -350,6 +350,7 @@ const pollForEvents = server => {
                 sendEvent(server, false, 'ClientDataReceived', event.subType, client, data);
             } else {
                 logger.WriteWarning(`Could not find client slot ${event.clientNumber} when processing ${event.eventType}`);
+                sendEvent(server, false, 'ClientDataReceived', 'Fail', { ClientNumber: event.clientNumber }, undefined);
             }
         }
 

Plugins/ScriptPlugins/ParserIW4x.js

@@ -22,7 +22,7 @@ var plugin = {
         
         rconParser.Configuration.DefaultRConPort = 28960;
         rconParser.Configuration.DefaultInstallationDirectoryHint = 'HKEY_CURRENT_USER\\Software\\Classes\\iw4x\\shell\\open\\command';
-        rconParser.Configuration.FloodProtectInterval = 50;
+        rconParser.Configuration.FloodProtectInterval = 150;
 
         eventParser.Configuration.GameDirectory = 'userraw';
 

SharedLibraryCore/Interfaces/IPluginImporter.cs

@@ -18,6 +18,6 @@ namespace SharedLibraryCore.Interfaces
         ///     discovers the script plugins
         /// </summary>
         /// <returns>initialized script plugin collection</returns>
-        IEnumerable<Func<IServiceProvider, IPlugin>> DiscoverScriptPlugins();
+        IEnumerable<IPlugin> DiscoverScriptPlugins();
     }
 }