[Patch 268] Unacceptable loadtime increase

_INTER_

Now since we have patch 268 my loadtimes actually have increased dramatically instead of having decreased as promised.
In fact it got so long its unplayable!!
- First 2 times I tried to load a map the loading time went over 10 minutes, I aborted each of them at the Precaching phase that was running for 6 minutes already.
- Dissabled all mod, deleted Appdata => nuked NS2 from orbit, and tried another 2 times. No remedy. Tried p_logall which spammed a lot of errors and crashed the game to desktop.
- I installed a RamDisk. Now the game finally loads but the initial loading takes roughly 5 minutes still. This is unplayably long. I can't accept loading times like these. 5 times longer loading than patch
267, which increased loading times already. Loading between maps are now too long aswell: 2 minutes.

I remember that the p_logall spammed the error before, but now the spam is even greater. I suspect multithreading (error now with [Worker **]), similar to:

[123.769] Worker 03 : Error: ExitNode for ResourceLoader::LoadResource doesn't have matching EnterNode (current node is Thread)

Idk if this is related. Please help with this new issue.

Edit: Attached TechSupport file and p_logall (before patch and after). Also my FPS dropped hard -20 from the start

METROID

How about running the HDD defragmentation?

DC_Darkling

I see big spikes indeed.

* The biggest spikes have many calls for 'Filesystem: Open File' which takes very long.
Rest of that spike was get/create shaders.
- On this regard, check your harddisk and defragment. (unless ssd, dont defrag those).
Also be sure your GPU is working. You may want to consider NOT enabling multithread in ns2 options for the gpu.

GhoulofGSG9

Also test your ram with memtest86+ or something similair. Because that plog is telling me there is something totally off with your system.

IronHorse

Have you ran any hard drive diagnostics?
I realize it was working fine before the patch, but just in case.

I am trying to think how certain hardware/software could yield SLOWER loading times ...
Can you grab another log.txt with -verbose as your launch parameter for NS2?

EDIT: I see you are still running mods, notice how they mount before the main menu is initialized?

Date: 08/23/14
Time: 01:18:54:

---

Build 268
Windows 7 64-bit (build 7601)
[ 0.173] Unbound/Unknown : Error: PhysX: Invalid Cuda context!
Steam initialized
Num displays: 1
Direct3D 9 initialized: NVIDIA Geforce GT 750M (9.18.13.3788)
Sound Device: Lautsprecher (Realtek High Definition Audio) stereo
Record Device: Mikrofon (Realtek High Definition Audio)
Mounting mod from C:/Users/Simon Gwerder/AppData/Roaming/Natural Selection 2/Workshop/mb3f2dcc_1383065171/
Mounting mod from C:/Users/Simon Gwerder/AppData/Roaming/Natural Selection 2/Workshop/mb5e13e6_1406749912/
Mounting mod from C:/Users/Simon Gwerder/AppData/Roaming/Natural Selection 2/Workshop/mc11703b_1386614558/
Mounting mod from C:/Users/Simon Gwerder/AppData/Roaming/Natural Selection 2/Workshop/mcb6e7cb_1408494960/
SetPixels for screens/IntroScreen.jpg [2.4478 mPixels] took 27.19ms, background load 0.00ms
Mounting mod from C:/Users/Simon Gwerder/AppData/Roaming/Natural Selection 2/Workshop/mb3f2dcc_1383065171/
Mounting mod from C:/Users/Simon Gwerder/AppData/Roaming/Natural Selection 2/Workshop/mb5e13e6_1406749912/
Mounting mod from C:/Users/Simon Gwerder/AppData/Roaming/Natural Selection 2/Workshop/mc11703b_1386614558/
Mounting mod from C:/Users/Simon Gwerder/AppData/Roaming/Natural Selection 2/Workshop/mcb6e7cb_1408494960/
Loading config://ConsoleBindings.json
Loading config://FavoriteServers.json
Loading config://HistoryServers.json
Main Menu Initialized at Version: 268

That exit node error is benign, you can ignore it

Turbine

The first time me and my gf tried to play 268, we each gave up and tried again. The second time it was very quick.

Cold load times have slightly increased, map change load times have reduced significantly for me.

IronHorse

Those were exactly our findings, Turbine.
What do you mean you gave up? Did it freeze?

Turbine

By give up, after 5 minutes I decided to retry loading, which worked. Perhaps it's just a first time playing 268 problem. I haven't experienced it since, I've joined at least 20+ matches today.

Crashing (b268) and locking up upon alt-tab (b267+) tends to do that.

_INTER_

Sorry for the wait these steps took a while:
- Performed memtest86+: no problems found
- Run Defragmentation
- Performed HD diag / chkdsk: no problems found
- Verfied NS2 files with Steam
- Deactivated all mods, deleted Workshop folder, restarted NS2 in -verbose
- Made sure NS2 runs on GPU
- Joined empty servers:
-- Multithreading On: Initial Loading: 6min 32s (up from ~1 min patch 267), Map switch: 4min 15s (up from ~30s patch 267)
-- Multithreading Off: Initial Loading: 5min 52s, Map switch: 3 min 40s

I'm very unhappy.

log.txt: http://pastebin.ca/2834927

Edit: I see lots of open / load error. I'm going to nuke NS2 again, reinstall and report back.
Edit2: Nope, no change in loadtimes. Open / Load errors still there (cinematics)

IronHorse

Unbound/Unknown : Error: PhysX: Invalid Cuda context!
Weird that physx isn't activating for you even though you are using an NVidia card.. what drivers are you using?

Can you doubly ensure that no other programs are running on a fresh restart of your PC? I.e. no AV, no browser, nothing that could remotely take up memory... and try testing it again?

The only common element between users with increased loading times is a partitioned HD.
I take it NS2 is installed on your drive? Would you mind installing NS2 on C: just as a test?

_INTER_

IronHorse wrote: »

Unbound/Unknown : Error: PhysX: Invalid Cuda context!
Weird that physx isn't activating for you even though you are using an NVidia card.. what drivers are you using?

Driver 337.88. It's the latest working driver for my graphics card. With the newest 340.52 WHQL no game or stuff like flashplayer run properly. It doesn't
provide anything essential new though. (Lots of other people complainging about it too). I've set PhysiX to CPU, so my GPU is less burdened as r_stats says, that
my GPU is the chokepoint.

Can you doubly ensure that no other programs are running on a fresh restart of your PC? I.e. no AV, no browser, nothing that could remotely take up memory... and try testing it again?

I always run NS2 without any other processes. I even kill explorer.exe.

The only common element between users with increased loading times is a partitioned HD.
I take it NS2 is installed on your drive? Would you mind installing NS2 on C: just as a test?

NS2 is installed on my C:\ drive in SteamApps\common\ as usual. \ just
contains my files for work.

Edit: Attached log.txt of my test without any AV and Physix set to GPU. Apart from having a r_stats with "Waiting for GPU +-5ms" and lower average FPS, loadtime are still tedious at 6-8min.
http://pastebin.com/gehn5Ccq

I was able to "play" a game for like 5mins then crashed. FPS horrendously worse.

DC_Darkling

Another odd thing is it says stuff like:
[ 3.058] Worker 04 : Error: Unable to create low quality version of 'fonts/AgencyFB_tiny_0.png' and [ 3.137] Worker 10 : Unable to compress 'ui/crosshairicons.dds', no low q available

Needless to say if it can not get the low quality version, it MUST use a higher quality when you encounter the file midgame.. That will definitely produce stutters.
I can imagine there is truly something wrong, but it is hard to say what.

Disable any experimental and new feature. Close ns2. Start ns2 and try again.


You may also start ns2 as admin to check if for some reason file system access rights are screwed.

_INTER_

@DC_Darkling‌ I get prompted to run NS2 as admin from the start, it always start in highest priority mode. Graphic settings are the lowest possible or off, experimental settings too.
I've set a lot of Nvidia Graphic settings to off or "use ingame".

DC_Darkling

WUT... you should not NEED to prompt admin for ns2 on windows 7. Thats just... not...needed.
On a update or install yes, but not to run.

Can you see if your user account has read, write and execute access to the ns2 directory and just force it down..

IronHorse

Looking into this @_INTER_‌
We have a PT who experiences the same results, so we'll be working with him and will keep you updated here.
Thanks

_INTER_

DC_Darkling wrote: »

WUT... you should not NEED to prompt admin for ns2 on windows 7. Thats just... not...needed.
On a update or install yes, but not to run.

Can you see if your user account has read, write and execute access to the ns2 directory and just force it down..

I gave all accountsfull access now. I unchecked the "Run as admin" option of my ns2.exe. I'll try and see the effect of those changes tomorrow.

IronHorse wrote: »

Looking into this @_INTER_‌
We have a PT who experiences the same results, so we'll be working with him and will keep you updated here.
Thanks

This is a relieve. If I was the only one with this issue, I wouldn't have known what to do. You can ask me to try anything and I will provide information
if you need.

DC_Darkling

Remember of course you do not want to throw full access around.
Normally games these days only need read/execute.. with write access only needed for updates.. They SHOULD put all changes in your windows profile where you already have access.

Me asking you to check rights was basicly to 'force them down again'.
This incase you should have, for example, read but do not have it. Even when its tagged.

_INTER_

I think it wouldn't harm giving it full access in this situation Unfortunately that was no success. I also cleared my gfx driver with DDU and reinstalled it, including nvidia settings profile reset. Atleast I was able to play one somewhat ok round FPS wise.

DC_Darkling

Humour me and give new logs and plogs please.
Lets see if something changed.


Also check your harddisk queue during / after these spikes.

go to task manager > performance tab > performance monitor
Then go to the disk tab. You should have a column for reaction time in ms. I want to know! (screenshot)
Also below the area of that is one with a column for queuelength. I also want to know that one

_INTER_

@DC_Darkling‌ Could you tell me step by step what I need to do? What spikes do you mean? Perfmon. during playing or while loading a map? Alt-tabbing while Loading usually freezes / crashes the game. p_logall during loading crashes the game too but it still creates (those I sent in my first post)

DC_Darkling

I have a dutch windows, but I circled.
http://imgur.com/ayYn8dL

I want to know the highest ms.. (just order the column by clicking)
Also wanna know highest queuetime. (just orer the column by clicking)

make a screenshot like me and we should have what i wanna check.

Do it when you lag/stutter/warp. Your plog showed loads of waittime on Openfile, so I wanna check your windows disk & file queue.

_INTER_

Now its getting very weird. All of a sudden my loadtimes went down again noticably. All I did was reinstalling Avira Antivirus. Could it be that the AV is checking newly created files, like those low q files and then they are blocked? (I made a test after deinstalling AV completly which didn't change anything however).
My loadtimes are as following now: 2-3 min for first server join (still higher than pre-268), 30s to 1 min for any subsequent server join (same or better than pre-268).
Sometimes it feels like joining an empty server with 0 mods loads faster, but that might be placebo. I meassure after downloading mods ofc

Here the requested logs, I hope I got them usable.
Some logfile 1 Some logfile 2

RessourceMon: Inital Server Join 1
RessourceMon: Inital Server Join 2
RessourceMon: Beeing on an empty server, then crash
RessourceMon: Second Server Join

client-0824-215454.plog => First Server join loading, crashes early
client-0824-205333.plog => Running around on an empty server, then crash on "Disconnect"
client-0824-211856.plog => Joining a 2nd server, cashes early

IronHorse

Whhaaaaaaaattt........*Scratches head*
Just uninstalling the AV should have done it if that was the case.

I'm thinking something else odd is going on..

DC_Darkling

THE WUT.

First: Datentrageraktivitat:

your ns2 has a full 1 second ms on it! (caused by avguard.. see that line?)
The rest has a 600ish latency!
The second pic shows a 1second on ns2 itself. See?
All those are ms values.. EVERY FILE it names takes THAT amount. So the first pic shows a harddisk ms of 4.8 seconds.. ouch.

Speicher:
useless OR insane wrong! you should never have a queue above what, 2... 3.. I can not even phatom a queue of that number.. so I assume its not the queue column but the size column.
I need the one talking about queue length.. its more to the right.. you did not screenshot it.

Your last 2 pictures did STILL not make me happy with latency over 250 but its not as mad as before. You will note my ms reads ZERO. :P

_INTER_

1nb4 more outch:

2-3 is good, that queue size is beeing around 4-8 while loading ns2. I saw a spike to 18 X_X (

Btw I got some Intel "Rapid" Storage Technology process / service running in the background all the time, I don't touch that one as it sounds important.

DC_Darkling

For F sake go check your harddisk!

ns2 needs a full second to load vfx_gradient_03.dds, and the ones below are going for inbetween 800 and 300ms.
Also a queuelength of 8.39 is..... not good. Spikes I can live with, but sustained? nonono.. bad.

Also defragment on a non SSD would not hurt! (I would actually schedule it to do it weekly, so it keeps up with it).



Intel Rapid Storage Technology is basicly to maintain disks. It can be used to setup raid arrays, if motherboard allows.
It also has a status menu!
Wont do much use if s.m.a.r.t. isnt on in the bios though!

_INTER_

Yea well I did diag my hd and forced another defragmentation too, as it already does them every Wednesday. It still doesn't explain the change from one patch to the other.
I go check the hd drivers and update them if needed. I don't know what else I could do to improve my hd.

DC_Darkling

So your harddisk checked out fine with a disk check and s.m.a.r.t. status?
This is a very important detail! Knowing if such queue times exist due to a faulty disk or not is vital for this troubleshoot / bugreport.

Do you have these insane queue times and ms if you DO NOT have ns2 open?

CrystalDiskMark
http://crystalmark.info/?lang=en
If you run this test, do you have these insane queue times?

Mine:
http://imgur.com/PpdbThD
Note the bottom test (4K with queue depth 32) is ment to truly test this far beyond what a normal program should ask.
After the program ended all my spikes 100% deminished to 0 as it should be.
Note while my queuelength is high, due to the non permanent nature the latency is still low!

(also for the doubters about hybrid disks, look its faster!)



EDIT!
It seems more folk who experience this issue have Avira.. I suspect a compatibility issue with avira and ns2 latest patch which worsens the harddisk time.
Note that ns2 still seems to stress the queue length above normal.

Excluding ns2 and the ns2 folder in the windows profile does lower the load times slightly.

_INTER_

- HD tests all pass. Some I did: HDDScan and CrystalMarkInfo
- Another queue spike loading NS2: Loading NS2 then NS2 ingame "spike".
- Loading other games like Dota2 rarely lets the queue length go over 1, most of the time its just a fraction. MS times significantly lower.
- CrystalMarkTests: 4th Test Running, 4th Test Finished, 1st Test Running, 1st Test Finished

It seems more folk who experience this issue have Avira.. I suspect a compatibility issue with avira and ns2 latest patch which worsens the harddisk time.
Note that ns2 still seems to stress the queue length above normal.

Would it be possible to exempt NS2 folder in Avira to solve the issue? Though I also tried without AV and with BitDefender, with no solution. (I just don't see any free alternative to Avira, BitDefender sucked and had to go right away => AV test)

Btw thanks for taking your time with me DC_Darkling and Ironhorse


Edit: Success!! Exempted NS2 folder and ns2.exe in Avira Real TIme Scanner => Initial loadtimes are under 1 minute!! I hope this is not a fluke. I tried 3 times.

Queue can still go to 8 at times, however it seems it more resolves around 3-4 than around 7-8 as before.
Note that Avira is still meddling with Fonts for some reason. Maybe it just thought it needs to check these right then. [-( There is a "Game Modus" in Avira, but I guess you can only activate it with premium edition.

DC_Darkling

yes I confirmed avira can lower the load if excluding the ns2 folder and the ns2 folder in windows user profile. Note you have strong load regardless! AVguard is having a 806ms load on hid.dll? wut?

So avira is definitely screwing around. (this is why I just got me a payed av, for crap like this)
ns2 however is STILL putting much load on the disk.

If its multithreading disk requests, not only does the AV need to check more at once (cause more happen at once), the disk and controller also need to be able to keep up.
You can probably only fix avira.

_INTER_

I didnt exempt the "%APPDATA%/Natural Selection 2" folder with purpose yet. Modders basically could place any file they want in their mod right?