diff --git a/Application/Main.cs b/Application/Main.cs index 4d5f4bd4..43238873 100644 --- a/Application/Main.cs +++ b/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 diff --git a/Application/Misc/PluginImporter.cs b/Application/Misc/PluginImporter.cs index 7bff527a..472f889b 100644 --- a/Application/Misc/PluginImporter.cs +++ b/Application/Misc/PluginImporter.cs @@ -38,13 +38,13 @@ namespace IW4MAdmin.Application.Misc /// discovers all the script plugins in the plugins dir /// /// - public IEnumerable> DiscoverScriptPlugins() + public IEnumerable DiscoverScriptPlugins() { var pluginDir = $"{Utilities.OperatingDirectory}{PLUGIN_DIR}{Path.DirectorySeparatorChar}"; if (!Directory.Exists(pluginDir)) { - return Enumerable.Empty>(); + return Enumerable.Empty(); } var scriptPluginFiles = @@ -52,11 +52,10 @@ namespace IW4MAdmin.Application.Misc _logger.LogDebug("Discovered {count} potential script plugins", scriptPluginFiles.Count); - return scriptPluginFiles.Select>(fileName => serviceProvider => + return scriptPluginFiles.Select(fileName => { _logger.LogDebug("Discovered script plugin {fileName}", fileName); - return new ScriptPlugin(_logger, - serviceProvider.GetRequiredService(), fileName); + return new ScriptPlugin(_logger, fileName); }).ToList(); } diff --git a/Application/Misc/ScriptPlugin.cs b/Application/Misc/ScriptPlugin.cs index 84b82719..d188bd40 100644 --- a/Application/Misc/ScriptPlugin.cs +++ b/Application/Misc/ScriptPlugin.cs @@ -45,9 +45,8 @@ namespace IW4MAdmin.Application.Misc private bool _successfullyLoaded; private readonly List _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(); - _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; diff --git a/Application/Misc/ScriptPluginTimerHelper.cs b/Application/Misc/ScriptPluginTimerHelper.cs index ac33b8d5..cbe928a9 100644 --- a/Application/Misc/ScriptPluginTimerHelper.cs +++ b/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(); } diff --git a/GameFiles/IW4x/userraw/scripts/_integration.gsc b/GameFiles/IW4x/userraw/scripts/_integration.gsc index 64a5ead7..d8e83ad4 100644 --- a/GameFiles/IW4x/userraw/scripts/_integration.gsc +++ b/GameFiles/IW4x/userraw/scripts/_integration.gsc @@ -6,11 +6,15 @@ init() { // setup default vars - level.eventBus = spawnstruct(); - level.eventBus.inVar = "sv_iw4madmin_in"; - level.eventBus.outVar = "sv_iw4madmin_out"; - level.clientDataKey = "clientData"; + level.eventBus = spawnstruct(); + level.eventBus.inVar = "sv_iw4madmin_in"; + level.eventBus.outVar = "sv_iw4madmin_out"; + 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; } - - /#IPrintLn( "-> " + eventString );#/ + if ( level.iw4adminIntegrationDebug == 1 ) + { + 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 ( eventType == level.eventTypes.clientDataRequested ) // todo: this is dirty fix + if ( level.iw4adminIntegrationDebug == 1 ) { - 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"] ) ) diff --git a/IW4MAdmin.sln b/IW4MAdmin.sln index 27263555..00c9714d 100644 --- a/IW4MAdmin.sln +++ b/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 diff --git a/Plugins/ScriptPlugins/GameInterface.js b/Plugins/ScriptPlugins/GameInterface.js index 25e9d4c8..42767eec 100644 --- a/Plugins/ScriptPlugins/GameInterface.js +++ b/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 = ''; - if (client !== undefined) { - clientNumber = client.ClientNumber; - } - if (responseExpected === undefined) { - responseExpected = 0; - } - const output = `${responseExpected ? '1' : '0'};${event};${subtype};${clientNumber};${buildDataString(data)}`; + const output = `${responseExpected ? '1' : '0'};${event};${subtype};${client.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; - timer.OnTick(() => pollForEvents(server), `GameEventPoller ${server.ToString()}`) + let timer = _serviceResolver.ResolveService('IScriptPluginTimerHelper'); + 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); } } diff --git a/Plugins/ScriptPlugins/ParserIW4x.js b/Plugins/ScriptPlugins/ParserIW4x.js index 324f28e6..b35ef0d0 100644 --- a/Plugins/ScriptPlugins/ParserIW4x.js +++ b/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'; diff --git a/SharedLibraryCore/Interfaces/IPluginImporter.cs b/SharedLibraryCore/Interfaces/IPluginImporter.cs index 03dd9d85..3f0fb5cb 100644 --- a/SharedLibraryCore/Interfaces/IPluginImporter.cs +++ b/SharedLibraryCore/Interfaces/IPluginImporter.cs @@ -18,6 +18,6 @@ namespace SharedLibraryCore.Interfaces /// discovers the script plugins /// /// initialized script plugin collection - IEnumerable> DiscoverScriptPlugins(); + IEnumerable DiscoverScriptPlugins(); } }