8 replies to this topic

[SLuckyD]

[PERFORMANCE TIMING & TESTING USING SCRIPTED MOVEMENT]
*** I separate the Calculation and Movement sequences into two different scripts, then bridge the data between them through global variables (which speeds things up vastly). ***

SYNOPSIS: Using scripts with repetitive and overly-intense timing will affect the entire game's performance. ALSO: any mod that contains something that is expected to happen very rapidly and repetitively enough to cause over-stacking (eg: an extensive onHit event during an intense fire-fight).

Problems this causes includes, but is not limited to: visible lag of scripted movement, loss of responsiveness of User-controls, breakage of quests, Papyrus errors (which are a separate issue, see the thread below), freezing of the script and even the game itself, and certain functions not performing or firing as expected (such as setVehicle or translateTo).

Scripts which are potentially affected by this would contain any kind of repetitive loop; such as registerForUpdate, registerForSingleUpdate, nested functions, and repeating quest-stages. While/endWhile loops are especially problematic because they have no limit as to how fast they actually run, and will do so at TOP speed... which quickly amounts to being TOO fast.


The following data shows in-game frames-per-second rates (fps), while the scripts are running at a certain rate (the second number, eg- .11). The second number, in these tests, indicate how fast the registerForSingleUpdate(MovePerf) is set to; where MovePerf are the second numbers below. This does NOT mean this is how fast the script is actually running, but how quickly the new onUpdate fires AFTER the preceding code has finished. The script will NEVER actually run at that specific interval - even if the onUpdate is empty... simply because it takes time to actually open that event, then run the regForSingle function.

= May cause UserControl-lag, variable/alias non-filling (errors and/or visible lag), and/or misfiring from over-stacking. Over-stacking may cause certain functions or actions to keep performing after a stop/finish-function has been completed; which affects the NEXT time the script is run.
** These results are VERY consistent and reproducible (at least on my machine). **
- These effects are not only manifest during repeat script-starts, but also during real-time, in the form of visible lag or erratic movement.
(The CalcScript actually has its stop-sequence set to end TWO SECONDS after it's done... without this wait, these thresholds would be MUCH higher. The MoveScript ends after 3sec, to allow the CalcScript to finish first.)

25fps at .11 and less (stopped here as 25fps is WAY too slow for anything I want to do, so no need to go further)
30fps at .09 and less
(anything below 30fps will have visible lag/flicker, regardless of script-speed, so is generally undesirable)
35fps at .09 and less
40fps at .08 and less
45fps at .06 and less
50fps at .06 and less
55fps at .03 and less
60fps at .02 and less


= May cause a script to run TOO fast; either causing 'None' errors (because of misfiring/stack-dump) or excessive stack-dumps (which WILL cause ALL scripts to temporarily stop running, freeze the game, or outright CTD).
** These results aren't as consistent as control-lag (yet ALWAYS show those lag-symptoms, except at 45+ fps). **
- CalcScript is almost ALWAYS the one that has errors; presumably because the relative slowness of the MoveScript (translateTo is one of the slowest things goin', at least from what I've seen). [don't forget a regForSingleUp doesn't run at that rate, but however long it takes to finish running PLUS that rate]
- Multiple attempts to reproduce results found a +/- 0.01sec tolerance.
- These effects manifest in real-time, usually as soon as the script is started; and also include visible lag and erratic movements, as well as the movement seeming to freeze (that is.. if you're superLucky).

25fps at .06 and less
30fps at .06 and less
35fps at .06 and less
40fps at .06 and less
45fps at .06 and less
50fps at .06 and less
55fps at .06 and less
60fps at .06 and less

***** Obviously my system cannot reliably run scripts faster than 0.06sec (+/- .01), regardless of fps rate; therefore, in my case, it is presumably a CPU-speed limitation. Real-time logging indicates my CPU only hits 50% total usage during the occasional spike (probably during cell-loads); and only 2 of 4 cores (a known limitation of Skyrim)... presumably systems with 2+ cores running at faster-than-mine speeds would see better times (and/or if more than 2 cores may be safely and effectively used). *****


[DETAILS]
- This tests a dozen and a half global variables, moving one object and Player (the extra variables are for more objects, not used during this test; left in to simulate extra system-load).
- CalcScript includes advanced math functions (square-root, sine, etc), which determine present position and movement offsets based on User-controlled speed and direction; many extras were left in to simulate extra system-load... enough to move 4 objects (each with a unique position/destination), and compensation/limitations for different speeds/etc.
- Player-based controls are done in a hidden quest, which is set to repeat during each iteration to poll Player's movement (based on conditionals); fired from the CalcScript (since it uses that 'raw' data).
- The (pureCK) test-mod is a simple/lowPoly platform which Player is scripted to control and travel on; top speed is 300gu per translateTo (the function used for the actual movement).
- The platform is an activatorObject and has both the Calc and Movement scripts attached to it, both start simultaneously with onActivate events and are set with the same fire-rates.
- RegisterforSingleUpdate drives both scripts, both set to the intervals indicated below; no States or Aliases were used.

Testing Procedure:
(after having created the test-mod in CK v1.524; and using Notepad++ to compile the scripts)
1- set the scripts' fire-rates to the test target
2- adjust detail levels to achieve the target fps rate; primarily with the Low & High detail buttons, then individually changing Shadow Detail level, AA, AnisoFiltering, FXAA, and Blur Radius
3- 'coc' from the Title/Main Screen to the cell in which is pre-placed a Ref of the platform Activator
4- position Player near the platform, then adjust heading (mouseLook-direction) to achieve the target test-rate (look toward the ground = higher fps, look straight/more detail = lower fps)
5- activate the platform; wait until scripted notifications indicate both scripts have started
6- Player moves forward (to increase the 'speed' of the movement) until top-speed is indicated by notif
7- adjust Player's heading to achieve and maintain the target fps (same as above, looking toward more detailed areas if fps is too high, the ground if too low); take note of actual in-game performance/'jumpiness'
8- after a few seconds of maintaining the target fps, Player 'sneaks' to trigger the scripts' stop-sequence
9- still maintaining target fps, User waits until both scripts' notifs indicate they have finished
10- open the console then select the platform, do a 'showvars'
11- find the variable in CalcScript which determines whether it has finished (set to 0 during the stop-sequence)
** If it's not 0 then the scripts have over-stacked and functions continued to run more than 2secs after the stop-sequence was DONE. **
12- do a 'qqq', and check the Papyrus log for actual stack-dumps or 'None' errors
** I intentionally removed any checks which would/should prevent those 'None' errors, so as to see better without elaborate tracing/logging/etc. **


*** The above is only one person's findings and may be subject to change from session to session; possibly affected by circumstance such as GPU & CPU core temps, as well as the specific nature and intensity of any scripts being run (not to mention using a saveGame, as opposed to 'coc' from the Title/Main Screen). Keep in mind that these results were gleaned without ANY other scripts running, certainly not with any full of errors and over-zealous timing.. as many tend to be. ***

- All the above was tested using Skyrim v1.526, without ANY other mods or INI tweaks, and using FRAPS for fps
= Tested with an i5 2.27, 4gig DDR3 sysRAM, nVidia GTS360m with 1gig dedi vidRAM, 7200rpm SATA harddrive, Win7
(with Skyrim, the GPU is ALWAYS the bottleneck in my system, NOTHING else even comes close)

Related Thread:
http://forums.bethso...me-performance/

Edited by SLuckyD, 23 June 2012 - 06:05 PM.

[Chesko]

This is really relevant to what I need to start working on, so thank you very much for the testing. This is very helpful.

[SLuckyD]

Cool... I love seeing at least ONE person helped by this kinda stuff. I do/did it for my own purposes, but as you say, it's quite relevant for others as well - or SHOULD be if they understand the ramefications. How many scripts are there that use .01 regUpdates? Thankfully they're code PROBABLY slows it down enough past most/every Users' thresholds.

I'm considering posting this test-mod and the scripting source to the Nex, as a personal-performance tester. Lemme know if that's something you'd be interested in having - to establish what your system can handle, and how to tailor your script to NOT over-fire unnecessarily. I know this is gunna help my ship mod out; I knew this stuff (fps and timing) affects intense scripts, but until now I never knew what REALLY caused it and at what point it can be alleviated.

[Borgut1337]

Generally I'm quite interested in performance tests and that kind of stuff but.... It might just be me being stupid, but I find this kind of hard to follow It seems like you start mentioning some fps values at <some number> (what is <some number>? is it time? ) and only then you seem to describe what you've been testing.

Is it possible to provide some conclusion or TL;DR describing what the result actually is? Or if noone else has difficulties following this I'll just silently move along and come back later when I'm more awake

[SLuckyD]

Thanks for pointing that out... I added a little description to the top. Originally, my notes had the 'details' and 'procedure' at the top; but in making it presentable I moved it to the bottom so people who don't care to read walls of text wouldn't have to in order to see the 'meaningful' results. I thought it was better explained there, but reading it again, I guess it's more implied than actually stated - it's fixed now though!

I'll have to go back and add a synopsis.. again - having just rearranged my notes (and it being so fresh in my mind), I guess I took the implications as given - sorry!

[EDIT: added the synopsis... lemme know if it's more clear! I wrote and posted this for others to read and contemplate... so it HAS to be readily understandble, or it's a waste of time. Thanks for the feedback!]

Edited by SLuckyD, 23 June 2012 - 01:09 PM.

[kuertee]

Yup. All mods cannot be built to rely on a regular update from the engine anymore.

The event-based processes will eventually lag the game. In my experience, having Event OnHit () in a Script attached to 15 Aliases (not all filled) eventually halted all my active mods "silently": http://forums.bethso...-indefinitely/. The OnHIt () is especially problematic during fights with mages with flame attacks.

The game kept running and I was able to play it. But it was dumping updates to all external ESPs. So none of the external mods were running. That's the upshot of this, I suppose. The game keeps running for a little bit longer. But it will eventually crash.

I had to build my combat mods to not rely on timed updates anymore. Effects from my mods "Battle fatigue and injuries" and "Fight or fly" do not get applied at the exact moment in time that they should (e.g. at the exact time that an NPC takes damage). Instead, they are applied a second or two later, when the game eventually sends an update to the mod. Basically, I had to revert back to a polling-base loop that keeps track of health-changes instead of relying on the new Event-based model possible in Skyrim. It's a a step backward, but I find that my mods keep running.

My only worry now is all these unclean Scripts from the main game. E.g.:

Spoiler

[06/23/2012 - 11:06:44PM] error: Cannot call Stop() on a None object, aborting function call
stack:
    [ (001073E3)].FXCameraAttachScript.OnTriggerLeave() - "FXCameraAttachScript.psc" Line 44
[06/23/2012 - 11:06:47PM] error: Cannot call Stop() on a None object, aborting function call
stack:
    [ (001073E6)].FXCameraAttachScript.OnUnload() - "FXCameraAttachScript.psc" Line 59
[06/23/2012 - 11:07:06PM] error: Cannot call Stop() on a None object, aborting function call
stack:
    [ (001073E5)].FXCameraAttachScript.OnUnload() - "FXCameraAttachScript.psc" Line 59
[06/23/2012 - 11:07:06PM] error: Cannot call Play() on a None object, aborting function call
stack:
    [ (001073E0)].FXCameraAttachScript.OnTriggerEnter() - "FXCameraAttachScript.psc" Line 26
[06/23/2012 - 11:07:15PM] error: Cannot call Stop() on a None object, aborting function call
stack:
    [ (001073E0)].FXCameraAttachScript.OnTriggerLeave() - "FXCameraAttachScript.psc" Line 44
[06/23/2012 - 11:07:18PM] error: Cannot call Play() on a None object, aborting function call
stack:
    [ (001073DE)].FXCameraAttachScript.OnTriggerEnter() - "FXCameraAttachScript.psc" Line 26
[06/23/2012 - 11:07:28PM] error: Cannot call Stop() on a None object, aborting function call
stack:
    [ (001073E2)].FXCameraAttachScript.OnUnload() - "FXCameraAttachScript.psc" Line 59
[06/23/2012 - 11:07:38PM] error: Cannot call IsCleared() on a None object, aborting function call
stack:
    [ (0010F908)].defaultDisableOnResetIfLocWasCleared.OnCellDetach() - "defaultDisableOnResetIfLocWasCleared.psc" Line 8
[06/23/2012 - 11:07:38PM] warning: Assigning None to a non-object variable named "::temp1"
stack:
    [ (0010F908)].defaultDisableOnResetIfLocWasCleared.OnCellDetach() - "defaultDisableOnResetIfLocWasCleared.psc" Line 8
[06/23/2012 - 11:07:38PM] error: Cannot call Stop() on a None object, aborting function call
stack:
    [ (001073DE)].FXCameraAttachScript.OnTriggerLeave() - "FXCameraAttachScript.psc" Line 44
[06/23/2012 - 11:07:45PM] error: Cannot call Stop() on a None object, aborting function call
stack:
    [ (001073E3)].FXCameraAttachScript.OnUnload() - "FXCameraAttachScript.psc" Line 59
[06/23/2012 - 11:07:45PM] error: Cannot call Stop() on a None object, aborting function call
stack:
    [ (001073DF)].FXCameraAttachScript.OnUnload() - "FXCameraAttachScript.psc" Line 59
[06/23/2012 - 11:07:50PM] error: Cannot call Stop() on a None object, aborting function call
stack:
    [ (001073E1)].FXCameraAttachScript.OnUnload() - "FXCameraAttachScript.psc" Line 59

Edited by kuertee, 23 June 2012 - 04:27 PM.

[SLuckyD]

Wellll... I don't think onHit necessarily falls into the category of repetitive; depending on what that event contains and how often something gets hit. If the event has mucho code and you're being bombarded faster than that code completes, then YES - definitely... interesting point.

I guess this can be applied to ANY type of script that fires fast enough - regardless if in a loop... it'd have to be pretty darn fast - as the above data shows, within fractions of a second... and sustained for however long it takes for the individual's system to fall behind. I'll change the above to reflect this aspect... thanks for pointing it out!

About the vanilla errors... there are PLENTY more where THAT came from; depending on what area you're moving across and which quests you've already triggered/completed. It's not really the Vanilla errors I'm worried about, but mods that run at .01 when they could easily get away with something as slow as .1 in many cases. All that adds up quickly. They may not show errors (especially if they have code to eliminate 'None' errors), but that doesn't mean it won't CAUSE errors. If it takes a sec or two for a hit to 'register', then most probably other mods (or other code you have running) are the problem.

For certain instances/uses, I've found aliases to be relatively slow - since they have to be filled and all that drama. I actually try to avoid them whenever possible.. but that may not be the best approach for some things. What does your onHit event do that it doesn't show up for a sec or two?

[kuertee]

Yeah...OnHit is actually quite good. I think it's too good. It only fails for me when it fires during constant flame, ice and spark attacks. Even 3 NPCs getting hit with those attacks caused a bottle neck in my tests. Normal melee or range hits went through the code with out a problem. Also, I have a feeling that OnHIt triggered by a constant flame, ice and spark attacks also triggered the OnMagicEffectStart.

Also, agreed re: mods that are forced to single-update at 0.1. All my mods are at the very slow update of 1 second - sufficient for what I need. And it lets the game "breathe" as I call it.

[SLuckyD]

I forgot to add that part about magicEffects being reeeaallly slow as well.. which you obviously already know heheh. I think some things being done through a magicEffect may be able to be accomplished through scripting (non-magic related). I doubt this applies to what you're doing though, especially without extensive and elaborate code.

Many nilla-functions are coded to be slow on purpose; as shown in the nilla-mannequin script. The comment even states that a certain wait is 'needed' for something to happen, but I found that wait was actually unnecessary.. though this current testing/data shows that in some circumstance it MAY be (eg: expansive areas with tons of refs with onCellAttach/Load code). In that nilla-quin script, there's another wait done for 3D loading (a quarter second, too... which is relatively lengthy), but it was commented out. My point is that there are other nilla scripts that may still have these extraneous waits (or other slow code may be able to be changed/sped up).

I'm not too familiar with onHit and onMagEfStart, but it sounds like a constant effect (or duration, such as burning) might keep triggering one or both... and that would DEFINITELY cause your bottleneck as it would fire the event multiple times - however fast the engine allows should it be the case. That would kinda be the same as an unregulated while-loop.. which runs as fast as possible, causing stack-dumps in the blink of an eye. I haven't messed with magicEffects at all yet really, so I'd have to look into it.

But I for one REALLY appreciate your proactiveness and interest in bettering your mods/code... and I don't evn USE any mods other than the ones I'm working on. I also commend you on discovering this a while back and helping to bring it to the community's attention to prevent the breakdown of the Nirn as we know it.