Measuring how busy SQF is, efficiently

[madrussian 347]

I'm looking for a way to measure how busy the script engine is at any particular moment (for scheduled code).

 

The best I've come up with so far looks something like this:

 

TEST_Count = 0;
TEST_Timer = time + 1;

TEST_EachFrame = {
    if (time > TEST_Timer) then {
        hint format ["TEST_Count: %1", TEST_Count];
        TEST_Count = 0;
        TEST_Timer = time + 1;
    };
};

TEST_MonitorBusyness = {
    while {true} do {
        TEST_Count = TEST_Count + 1;
    };
};

addMissionEventHandler ["EachFrame", { call TEST_EachFrame }];
[] spawn TEST_MonitorBusyness;


sleep 5;
systemChat "Simulating encumbered script engine starting... Now!";
for "_i" from 1 to 10 do {
    [] spawn {
        while {true} do {
            for "_i" from 0 to 1000 do {};
        };
    };
};

 

The TEST_MonitorBusyness script above continuously accumulates TEST_Count.  Every 1 second, TEST_EachFrame hints a readout of TEST_Count and then resets it to zero.

 

• The higher TEST_Count shows, the less busy SQF is (with doing other things).
• The lower TEST_Count shows, the more busy SQF is (with doing other things).

 

^ Which makes sense.  The more SQF works on other things, the less time it has to accumulate TEST_Count.

 

In this test case, after 5 seconds a higher workload is simulated.

 

Note TEST_MonitorBusyness and the simulated workload below run in an scheduled environments, whereas TEST_EachFrame (as with all EH code), runs unscheduled. See here if unfamiliar.

 

Seems I've achieved the desired goal of measuring SQF busyness.  TEST_Count starts out showing ~ 180,000 - 190,000, indicating SQF is not very busy.  The moment the simulated workload starts, TEST_Count drops to ~ 13,000 - 19,000, indicating SQF much busier (and remains there).  The above however is also imperfect because TEST_MonitorBusyness (again which is doing the measuring) itself is using a huge amount of CPU!  The question is thus:

 

How could one go about measuring SQF busyness?  Whilst not using much (if any) CPU?

 

^ Knowing this would greatly help out with some crazy AI I'm working on.  Thanks!

 

Spoiler

Btw - Seems like polling FPS has little (if anything) to do with any solution.  I'm showing a solid 60 FPS throughout the above test, despite registering the huge difference in SQF busyness.

Also btw - My video card bit the dust earlier today, so I'm running off of integrated graphics until I can get a new card ordered / installed.  In case anyone curious why the 60 fps...

 

[pierremgi 4740]

Scheduled code (execVMed sqf or spawned code) has a 3 ms slot to run. That allows several codes running in parallel and avoid freezes like you can have with unscheduled code.

So, not saying there is no impact on scenario or even FPS (depending on what you are doing with your code, for example 3D icons on hundreds units), but what you can really measure is part of code in debug console (small speedometer icon) , so unscheduled, or use advanced tools like the diagnostic branch of Arma.

 

So, the first thing to do is an optimized sqf, or even function (loaded at start and far better for multiple usage during script, rather than execVMing sqf again and again).

See:

https://community.bistudio.com/wiki/Arma_3:_Performance_Optimisation

https://community.bistudio.com/wiki/Mission_Optimisation

 

You can also track endless sqf (loops or else) for nuts. Running preview, watch for diag_activeSQFScripts in debug console, or at least count diag_activeSQFScripts

You'll  probably discover some useless scripts still running as they should be stopped during the scenario.

 

[dreadedentity 278]

To supplement the above post: Functions Library

[madrussian 347]

9 hours ago, pierremgi said:

Scheduled code (execVMed sqf or spawned code) has a 3 ms slot to run. That allows several codes running in parallel and avoid freezes like you can have with unscheduled code.

So, not saying there is no impact on scenario or even FPS (depending on what you are doing with your code, for example 3D icons on hundreds units), but what you can really measure is part of code in debug console (small speedometer icon) , so unscheduled, or use advanced tools like the diagnostic branch of Arma.

 

So, the first thing to do is an optimized sqf, or even function (loaded at start and far better for multiple usage during script, rather than execVMing sqf again and again).

See:

https://community.bistudio.com/wiki/Arma_3:_Performance_Optimisation

https://community.bistudio.com/wiki/Mission_Optimisation

 

You can also track endless sqf (loops or else) for nuts. Running preview, watch for diag_activeSQFScripts in debug console, or at least count diag_activeSQFScripts

You'll  probably discover some useless scripts still running as they should be stopped during the scenario.

 

All of this is good (optimizing, etc), but largely misses the point.  I can optimize until the cows come home, but my AI scripts are hungry and will quickly use all available CPU (at the expense of each other), unless kept in check.

 

So again, I'm basically looking for a script-based solution to determine how much SQF scripting power is in use already (at any given moment).  Something like we ask it:  "SQF system, how busy are you currently?"

 

And it replies: "32% busy!"

 

Btw - I examined all the ~40 diag commands and nothing seems to report this.  Also, I do think the 3ms execution per frame is key to a solution here, just not sure how to harness it yet.

[dreadedentity 278]

7 minutes ago, madrussian said:

SQF system, how busy are you currently?

How do you calculate this? Technically, it is 0% until a script is run, then it is 100% until the script ends, regardless of how many scripts are spawned

 

See Scheduler for some light reading. FPS is part of the equation because of how Arma handles scripts (3ms per frame is reserved for all scripts); at lower FPS scripts take longer to run. Having too many scripts also makes them take longer to run

 

You need to figure out your criteria before anything else. "100% usage" in the context you're describing doesn't exist

[Stormmy1950 41]

Cant you just messure that with Profiler ?

 

[_foley 192]

2 hours ago, madrussian said:

 

So again, I'm basically looking for a script-based solution to determine how much SQF scripting power is in use already (at any given moment).  Something like we ask it:  "SQF system, how busy are you currently?"

 

And it replies: "32% busy!"

 

Btw - I examined all the ~40 diag commands and nothing seems to report this.  Also, I do think the 3ms execution per frame is key to a solution here, just not sure how to harness it yet.

 

As @dreadedentity pointed out, "32% busy" is a vague metric so let's come up with some concrete criteria.
If I'm understanding you correctly, you want to find out how many scheduled scripts are actively competing for that 3ms window so that you can use this information to throttle your scripts accordingly.

Suppose we spawn 10 running scripts that are mostly sleeping - the metric should be low.
Suppose we add 1 script running flat-out - the metric should be still fairly low because this script runs as fast as you would expect it to run on its own, it's hardly ever interrupted.
Suppose we add 10 more scripts running flat-out - now we expect the metric to be high - there are many scripts competing for the 3ms window and as a result each of them is running much slower than it would on its own.

 

I believe that's actually what your test script is probing. I doubt that we can measure this efficiently using commands available currently in the stable build so here's an alternative approach:

 

1. Measure performance of your scripts internally, i.e. measure run time of a loop iteration or a lengthy function.

2. Calculate "business" value based on how the measured run time that compares to the expected / acceptable run time.

3. If you measure "business" value in multiple scripts, aggregate them into one final value.

4. Ensure that your scripts adapt accordingly to the current "business" value.

 

Hope this helps 🙂

[dreadedentity 278]

To supplement the above, here is a BIS function to help identify pain points in your scripts: BIS_fnc_codePerformance

[pierremgi 4740]

8 hours ago, Stormmy1950 said:

Cant you just messure that with Profiler ?

 

 

Sounds great for measuring all unscheduled codes of scripts in a global scenario... or executing a single sqf. Nice graphics... but difficult to do something with that. It's not a coincidence if ACE is shown as example. This mod uses a lot of unscheduled codes (questionable in regard of other mods, imho, for performance share).

 

6 hours ago, dreadedentity said:

To supplement the above, here is a BIS function to help identify pain points in your scripts: BIS_fnc_codePerformance

 

Yes, debug console is the default version of this function.

[madrussian 347]

On 4/6/2022 at 12:46 PM, dreadedentity said:

How do you calculate this?

 

...

 

You need to figure out your criteria before anything else.

 

Agree, in terms of needing to define what we're after here.  Also thanks you all for helping to focus my efforts.

 

20 hours ago, _foley said:

 

As @dreadedentity pointed out, "32% busy" is a vague metric so let's come up with some concrete criteria.
If I'm understanding you correctly, you want to find out how many scheduled scripts are actively competing for that 3ms window so that you can use this information to throttle your scripts accordingly.

Suppose we spawn 10 running scripts that are mostly sleeping - the metric should be low.
Suppose we add 1 script running flat-out - the metric should be still fairly low because this script runs as fast as you would expect it to run on its own, it's hardly ever interrupted.
Suppose we add 10 more scripts running flat-out - now we expect the metric to be high - there are many scripts competing for the 3ms window and as a result each of them is running much slower than it would on its own.

 

I believe that's actually what your test script is probing.

 

 

^ This pretty much sums it up!

 

Lets add one critical detail.  After thinking long and hard about the 3ms window... turns out what we really need to measure is actual work done vs expected work done, over a specified number of frames.  Specifically, we probably want to avoid constantly looping scripts, spinning away measuring this.  Rather we'd like something we can call up on demand, measure quickly (using the absolute least possible amount of CPU), quitting promptly.

 

I whipped up this "SQF load measuring" implementation.  Based on limited testing, it appears to be extremely accurate.  Have a look, & let me know if I'm simply off my rocker, how this can be improved, etc:

 

MRU_MSQF_Frames = 0;
MRU_MSQF_Cycles = 0;
MRU_MSQF_Script = scriptNull;
MRU_MSQF_RunUntilFrame = 0;

MRU_MSQF_EachFrame = {
    MRU_MSQF_Frames = MRU_MSQF_Frames + 1;
    if (MRU_MSQF_Frames >= MRU_MSQF_RunUntilFrame) then {
        terminate MRU_MSQF_Script;
        removeMissionEventHandler ["EachFrame", _thisEventHandler];
    };
};

MRU_MSQF_Monitor = {
    while {true} do {
        MRU_MSQF_Cycles = MRU_MSQF_Cycles + 1;
        sleep 0.001;
    };
};

MRU_MSQF_MeasureLoad = {
    private ["_load","_startFrame","_endFrame","_startCycle","_debug"];
    params [
        ["_overFrames", 21]
    ];
    if (_overFrames < 2) then { _overFrames = 2 };
    _load = -1;
    _startFrame = 0;
    _endFrame = 0;
    _startCycle = 0;
    //_debug = true;
    isNil {
        _startFrame = MRU_MSQF_Frames;
        _endFrame = _startFrame + _overFrames;
        _startCycle = MRU_MSQF_Cycles;
        MRU_MSQF_RunUntilFrame = _endFrame max MRU_MSQF_RunUntilFrame;
        if (scriptDone MRU_MSQF_Script) then {
            MRU_MSQF_Script = [] spawn MRU_MSQF_Monitor;
            addMissionEventHandler ["EachFrame", { call MRU_MSQF_EachFrame }];
        };
    };
    waitUntil {
        isNil {
            if (MRU_MSQF_Frames >= _endFrame) then {
                _load = 1 - ((MRU_MSQF_Cycles - _startCycle) / (MRU_MSQF_Frames - _startFrame - 1));
            };
            //if (_debug and (_load >= 0)) then {
            //	["MRU_MSQF_Cycles - _startCycle","MRU_MSQF_Frames - _startFrame - 1"] call MRU_SystemChat;
            //};
        };
        _load >= 0
    };
    _load
};

 

To test:

Spoiler

MRU_SystemChat = {
    private ["_hint"];
    _hint = "";
    {
        if (_x == "") then {
            _hint = _hint + " | ";
        } else {
            _hint = _hint + (format ["%1: %2", _x, call compile _x]) + " | ";
        };
    } foreach _this;
    systemChat _hint;
    _hint
};

TEST_LoadScripts = [];
[] spawn {
    sleep 5;
    hint "Simulate increased SQF load starting now!";
    for "_i" from 1 to 100 do {
        _script = [] spawn {
            while {true} do {};
        };
        TEST_LoadScripts pushBack _script;
        sleep 3;
    };
};

for "_i" from 1 to 100 do {
    _load = call MRU_MSQF_MeasureLoad;
    ["_load","count TEST_LoadScripts"] call MRU_SystemChat;
    sleep (random 2);
};

 

MRU_MSQF_MeasureLoad returns SQF load between 0 and 1 over last _overFrames # of frames.  With (presumably) quite minimal impact to actual SQF load.

 

Ok, so how does all this works?  Let's see...

I'm counting work done (MRU_MSQF_Cycles accumulating inside a spawned script) over a specified number of frames.  MRU_MSQF_Cycles will accumulate once per frame (and only once), provided it can.  If at the end of the specified frames, performed cycles is equal to the frame span - 1, we have (min) 0% load.  Alternately, if at the end of the specified frames performed cycles equals 0, we have (max) 100% load.  Turns out we must measure over at least 2 frames, because the MRU_MSQF_Cycles won't start counting until the 2nd frame (because script just got spawned).  Measuring over 21 or 11 frames works well, because it provides a nice 5% and 10% load result increments.  This method of course ignores how SQF load impacts frame rate itself, but for my purposes that turns out to be quite irrelevant.

 

Also note for testing this I settled on simulated load scripts running:

while {true} do {};

^ This (presumably) ensures these test scripts are using their full scheduler time-slice.

 

At any point during the test, feel free to call the following (in the debug console) to see the SQF load drop back down to 0%:

{ terminate _x } foreach TEST_LoadScripts; TEST_LoadScripts = [];

 

I do wish there was a way to measure SQF load instantaneously, but seems would likely need a new engine command.  Dedmen?

 

23 hours ago, Stormmy1950 said:

Cant you just messure that with Profiler ?

 

 

This looks pretty amazing!  Definitely on my list of things to check out. 🙂

 

Somehow I doubt it provides instantaneous SQF load check.  Please enlighten if it does.

 

Also btw - Great discussion everyone.  Plenty of good ideas in here.