ACR Lag / CPU use creeping up?

Teric neDhalir · Post by **Teric neDhalir** » Wed Sep 26, 2007 7:44 pm

As I have the OAS and NWNX4/SQL working I guess It'll have to be me. Only problem is I have no idea what it does or how to install it

AcadiusLost · Post by **AcadiusLost** » Fri Sep 28, 2007 5:40 am

Managed to nurse 2 hours of uptime out of my devel rig to get some script profile data on the OAS2 (narrowly) - by the end of 2 hours, the core that was handling nwn2server.exe was about 40% burdened (bouncing between 30 and 55%).

Code: Select all

Current statistics
---------------------------------------------------------------------------
>acf_mod_onmoduleload          15 msec     32 calls *| 
>sjc_fugue_bg                  91 msec    896 calls *| 
acf_mod_onmoduleload            6 msec      1 calls  | 
nw_c2_defaultd                  0 msec      5 calls  | 
sjc_fugue_bg                    2 msec      6 calls  | 
acf_cre_onperception           11 msec     36 calls  | 
acf_mod_onheartbeat            46 msec   1183 calls *| 
acf_area_onenter                0 msec     23 calls  | 
nw_c2_default1                337 msec  19268 calls *| 
acf_cre_onspawnin               9 msec     10 calls  | 
acf_cre_onheartbeat         53761 msec   6059 calls *| 
acf_trg_onheartbeat             0 msec      8 calls  | 
mje_ude_graze                   6 msec      5 calls  | 
acf_mod_onacquireitem           1 msec     67 calls  | 
acf_area_onhbeat              894 msec  29572 calls *| 
nw_c2_default2                 63 msec   3254 calls *| 
nw_c2_default9                 33 msec     18 calls  | 
acf_plc_onheartbeat          6104 msec  99324 calls *| 
---------------------------------------------------------------------------
Elapsed time                : 10045 msec
Runtime delta               : 175 msec
Total cumulative runtime    : 61379 msec
Total number of scriptcalls : 159767

So, it would seem that the creature heartbeat is burdening the system. This was with no players on, no DM clients, etc.

AcadiusLost · Post by **AcadiusLost** » Fri Sep 28, 2007 12:34 pm

I tried commenting out the recent "PC Only" perception code from the heartbeat section of acr_creature_i, didn't seem to help though. Here is the profile after 5.5 hours or so of uptime.

Code: Select all

---------------------------------------------------------------------------
>acf_mod_onmoduleload          16 msec     61 calls *| 
>sjc_fugue_bg                 245 msec   2375 calls *| 
nw_c2_defaulte                  0 msec      3 calls  | 
acf_mod_onmoduleload            7 msec      1 calls  | 
nw_c2_defaultd                  0 msec      5 calls  | 
sjc_fugue_bg                    2 msec      6 calls  | 
acf_cre_onperception            5 msec     36 calls  | 
acf_mod_onheartbeat           125 msec   3187 calls *| 
acf_area_onenter                0 msec     23 calls  | 
nw_c2_default1                668 msec  37870 calls *| 
acf_cre_onspawnin              14 msec     10 calls  | 
acf_cre_onheartbeat        232951 msec  11913 calls *| 
acf_trg_onheartbeat             0 msec      8 calls  | 
mje_ude_graze                   2 msec      5 calls  | 
acf_mod_onacquireitem           1 msec     67 calls  | 
acf_area_onhbeat             2497 msec  79657 calls *| 
nw_c2_default2                157 msec   7958 calls *| 
nw_c2_default9                 43 msec     18 calls  | 
acf_plc_onheartbeat         16518 msec 267628 calls *| 
---------------------------------------------------------------------------
Elapsed time                : 10018 msec
Runtime delta               : 108 msec
Total cumulative runtime    : 253251 msec
Total number of scriptcalls : 410831

At this point the CPU use was 95% or so on the core handling nwn2server.exe. My guess is toolset-placed NPCs wearing acf_cre scripts calling the default AI are to blame, though there really aren't enough to justify the heavy CPU use I'd think. If I get the chance, I'll try either deleting them, or swapping for ALFA Spawn points which should be inactive when no one is logged on.

Also note that this version of NWNx4 profiler does not yet catch pathfinding time- so that may be a contributor as well (and would also be helped by the above).

Oddly, the default script associated with creature heartbeats doesn't burn much of the CPU time, and it's most of what gets called by the acf. Perhaps caching it might help?

AcadiusLost · Post by **AcadiusLost** » Sat Sep 29, 2007 12:26 pm

Pulled all the "placed" NPCs out of the module to see what effect that would have- slightly improved after 6 hours of runtime: the core running nwn2server.exe is 77-90 % burdened. Here is the profile:

Code: Select all

Current statistics
-- -------------------------------------------------------------------------
>acf_mod_onmoduleload          15 msec     66 calls  | 
acf_mod_onmoduleload            6 msec      1 calls  | 
acf_mod_onheartbeat           131 msec   3611 calls *| 
acf_trg_onheartbeat             0 msec      8 calls  | 
acf_area_onhbeat             2625 msec  90266 calls *| 
acf_plc_onheartbeat         17466 msec 303286 calls *| 
---------------------------------------------------------------------------
Elapsed time                : 10013 msec
Runtime delta               : 9 msec
Total cumulative runtime    : 20243 msec
Total number of scriptcalls : 397238

Looks like this still isn't the main "issue" - though it did remove the heavy acf_cre_heartbeat burden. Could corruption in some of the module resources have this sort of creeping effect, perhaps?

Teric neDhalir · Post by **Teric neDhalir** » Sat Sep 29, 2007 4:17 pm

AL,
There really aren't that many placeables in the mod with acr_ scripts.. have you tried removing the morgue cooler?
Teric

AcadiusLost · Post by **AcadiusLost** » Sat Sep 29, 2007 5:02 pm

The acf_placeable_hearbeat() isn't really taking up much runtime, so there's no need to pull placeables out of the module, certainly. That 17,000 is in milliseconds, so when you think about it, 17 seconds of CPU time over 6 hours is a pretty trivial burden.

My suspicion is that we've got some bad resources in the module that are giving us problems. When I tried to create blueprints from some of the creature instances, I got a slew of errors- it may be that these or others are bogging down the CPU over time.

Where possible, I would recommend replacing placed NPCs with spawn points that call blueprints as a general practice - it will likely become more important as time goes on. In the meantime, I'll try pulling resources out of the directory and see if I can narrow down the source.

Teric neDhalir · Post by **Teric neDhalir** » Wed Oct 10, 2007 9:05 pm

I've been trying a few tests here to get around the creeping CPU usage problem;
Have stripped even more blueprints and scripts out - no change.
Have taken the acr_mod_* scripts out of the mod properties - no change.
Am going to try and run one of the OC mods tonight to see if that behaves (Might point up a problem on my machine if it doesn't)

Teric

AcadiusLost · Post by **AcadiusLost** » Wed Oct 10, 2007 9:09 pm

On a more hopeful note, I fired up Wynna's (admittedly very small) Silverymoon University module last night with the ACR running and SQL DB, it had essentially no CPU burden after 8+ hours of idle runtime- so it doesn't seem to be anything endemic to the ACR or nwn2server.exe itself.

Teric, have you tried converting your placed NPCs to ALFA spawned ones yet?

Teric neDhalir · Post by **Teric neDhalir** » Wed Oct 10, 2007 10:22 pm

Well, I've just run one of the OC mods for an hour or so and it has the same inexorable rise in CPU usage: from about 10% to about 50% and rising. Stop nwnserver and it drops back down to nothing. Is this helpful or just some weirdness peculiar to my machine?

AcadiusLost · Post by **AcadiusLost** » Wed Oct 10, 2007 10:51 pm

We'll sort through it eventually- I doubt it's your machine, as I saw it with both my server rig (R.I.P.) and my main development machine- and it seems to be module-specific: Wynna's university module runs fine, as did early versions of the OAS2 I believe- more recent OAS2 builds show the CPU creep.

I wouldn't be concerned about the CPU creep with OC modules as much- since they weren't really meant as multiplayer hosted mods, I doubt they're well optimized for CPU utilization.

There has been some discussion of CPU use creep on the NWN2 forums, we're not the only ones who've been having this issue. Hopefully we or others will have a breakthrough and suss out how to avoid or work around it.

In the worst-case scenario, we could just set the modules to reset every 4 hours or something- though that's nonideal, most of our systems tie into persistency so it'd be much less detrimental than on current NWN1 servers.

I doubt it will come to that, though.

Teric neDhalir · Post by **Teric neDhalir** » Thu Oct 11, 2007 10:52 pm

I've changed the "background" NPCs in Soubar and Boareskyr Bridge to Spawns, and removed the wandering dead and their waypoints from the Fugue Plane entirely. This has made some improvement in that the rate of CPU increase has slowed quite considerably, but I'm willing to bet that if I left it running all night it would be maxed out come the morning. I'll keep tinkering...
Teric

ç i p h é r · Post by **ç i p h é r** » Fri Oct 12, 2007 4:27 pm

Has anyone tried caching scripts? In particular, the scripts that are invoked by acf_cre_onheartbeat (notably AI)? That's consuming 20ms per call according to the profiler, which doesn't seem enough to bog things down to the level you guys are seeing but it's contributing much more than anything else so....

Teric neDhalir · Post by **Teric neDhalir** » Fri Oct 12, 2007 7:07 pm

A browse of the nwn2 forums says not to cache scripts under any circumstances. I thought I'd had a flash of inspiration the other day that the problem must be that I had cached scripts, but that turned out to be another red herring. Rats.

Teric neDhalir · Post by **Teric neDhalir** » Wed Oct 17, 2007 7:45 pm

Got it! Gotitgotitgotit! The cpu madness is being caused by a corrupt area; removed the area from the mod and it ran overnight yesterday and was cycling through 10%-30%-50% in the morning. AL you beat me to posting this with mending your server machine. I've lost track a bit with which mod you are hosting, but if it's the OAS_045 that I uploaded a while ago please remove the area 112 Lyans Hold Underground and you should notice a big difference. (Although on thinking about it that mod doesn't have the locals in Soubar as spawns, but I guess we get to see whether that really is a problem now.) I can now go on holiday with a clear conscience

AcadiusLost · Post by **AcadiusLost** » Wed Oct 17, 2007 7:56 pm

I'll try dropping that area this evening, see if that makes the difference.