Long loading times with mods (some machines)

[filippe999]

Hello Everyone

Again I'm opening to talk about this that has plagued my experience in Rimworld for long.
In Alpha11D the issue appeared fixed, 50+ mods, normal loading times, both to load the game, the mod list and a colony.
Now I downloaded and installed Alpha12D to relive the good old days of Rimworld, so as always I went here to harvest A12 mods, it yielded about 40 mods or more, the time to start the game was the same as it was back in A9, maybe not so bad, now i'm waiting 10m+ instead of 35m+ but it's still annoying to troubleshoot the compatibility while waiting 10m everytime you enable a mod setup.

Since now thanks, Filippe999

[Fluffy (l2032)]

mods pretty much exponentially increase loading times. That's just a fact of life I'm afraid. I certainly don't think it's a bug, but maybe a suggestion to further look into speeding up loading times?

[skullywag]

no it takes me < 1 min to load about 50+ mods of varying sizes, however i dont use a lot of the mainstream mods as i mainly use my own plus a smattering of others (mainly fluffys), to me anything over 10 mins seems like there is a problem. Post your mod list and ill try it out and see if I get it tonight.

[Fluffy (l2032)]

I kindof assumed the 35min+ was a gross over-exaggeration, if actually takes that long, there is something wrong indeed.

When I test my mods with the modpacks out there (My philosophy is that if it works with MVP & HCSK, it probably works with pretty much everything out there), I do get load times that are significantly longer (never timed them, but HCSK might well take over a minute, MVP isn't as bad, but for quick mod testing I tend to have a clean vanilla install which boots in about 15 secs or so.)

[Alistaire]

For me, starting the game takes about 2 minutes (120,000 ms) and appears to take this long regardless of modsconfig:

Code Select Expand

121954ms LoadAllPlayData
- 107154ms Load all active mods.
- - 10962ms Loading [Core|Core]
- - - 10958ms Loading defs from all def sets
- - 14625ms Loading [all other mods]
- 1553ms Load language metadata.
- 38ms Copy all Defs from mods to global databases.
- 67ms Resolve cross-references between non-implied Defs.
- 11ms Rebind defs (early).
- 1788ms Generate implied Defs (pre-resolve).
- - 1269ms Loading language data: English
- 0ms Resolve cross-references between Defs made by the implied defs.
- 4ms Rebind DefOfs (final).
- 191ms Other def binding and short hash giving.
- 10661ms Resolve references.
- 2ms Generate implied Defs (post-resolve).
- 47ms Error check all defs.
- 29ms Load keyboard preferences.
- 402ms Load backstories and bios.
- 1ms Inject selected language data into defs.

Everything in "LoadAllPlayData" adds up. Not everything in "Load all active mods" adds up. The only explanation I have is that all textures,
sounds and everything in inactive mods is loaded as well - this might be necessary for Unity or something. This means having any
non-active mod folders in Mods will severely increase loading times.

To be fair I have five copies of Rimfire (1.7, 1.7 CR, 1.8, 1.8 alt, Dev) in my mods folder and each gun has A9/A10/A12 textures, a sound file
and pretty crowded SoundDef library which adds up to each gun in the mod adding ~1,000 ms to the loading time.

I am also reluctant to believe your load order and mods folder adds up to a loading time of 35 minutes (2,100,000 ms) though very large
ResolveReferences and GenerateImpliedDefs, and of course many high resolution textures and high quality sounds with many filters might
possibly cause such crazy loading times.

If you got the time I'd love to see your output_log.txt with <logVerbose>True</logVerbose>:

Code Select Expand

-> start Windows start menu
-> type "%appdata%" in search box, press enter
-> go up one folder from Roaming to AppData
-> enter LocalLow/Ludeon Studios/RimWorld/Config
-> open Prefs.xml
-> search logVerbose
-> replace <logVerbose>False</logVerbose> with <logVerbose>True</logVerbose>
-> run game, wait until main menu is shown, exit
-> go to your RimWorld install folder, not in LocalLow
-> enter RimWorld******_Data
-> attach output_log.txt to forum post

[Britnoth]

it yielded about 40 mods or more,

I don't think a complaint about bad mods is helpful as a bug report? 

[Tynan]

This does seem to be an unfortunate issue that's resurfacing. Ugh, Unity!

[Alistaire]

I assume Skullywag has notified you about a possible fix for this bug related to the faulty loading of audio clips through the use of a while loop. Otherwise I'd be glad to explain what the problem could be slash almost certainly is along with a Unity forums thread detailing hints as to how to fix it.



I've recently (some weeks ago) attempted to start the game with Hardcore SK modpack and I swear this is no exaggeration it took fifty minutes to load the game. Upon inspection of the output_log it appeared every single sounddef took 3150ms to load along with a deviation of about 1-10 ms depending on the size of the source audio file. Adding up all loading times for all mods still netted an unlogged fraction of loading time.

I would post the output log but I restarted the game since I forgot to activate PrepareCarefully and could not be bothered to wait another fifty minutes.

[ison]

Could you please see if the problem is still there in A13? After it's released obviously.

[Alistaire]

I'll post a nice output log now.

Loading vanilla game (previous boot):

Code Select Expand

- 2732ms Load all active mods.

- - 2723ms Loading [Core|Core]

- - - 2720ms Loading all defs

Closing mod menu MAIN THREAD:

Code Select Expand

12539ms LoadAllPlayData

- 11786ms Load all active mods.

- - 11133ms Loading [Core|Core]

- - - 11133ms Loading all defs

- - 653ms Loading [Rimfire 1.9|Rimfire 1.9]

- - - 322ms Loading all defs

Closing mod menu MOD THREAD:

Code Select Expand

109927ms Loading assets of type UnityEngine.AudioClip for mod Rimfire 1.9

- 3146ms Loading file Things/93R

- 3138ms Loading file Things/AA12

- 3129ms Loading file Things/AK47

- 3140ms Loading file Things/ArmaliteAR50

- 3139ms Loading file Things/Cannon+Mortar

- 3143ms Loading file Things/Cannon

- 3129ms Loading file Things/CX4

- 3137ms Loading file Things/Deringer

- 3140ms Loading file Things/Galil

- 3138ms Loading file Things/GreaseGun

- 3138ms Loading file Things/GreaseGunTick

- 3136ms Loading file Things/HKUSC

- 3163ms Loading file Things/M134

- 3135ms Loading file Things/MadsenLAR

- 3137ms Loading file Things/MD50

- 3138ms Loading file Things/MilkorMGL

- 3137ms Loading file Things/Mortar

- 3127ms Loading file Things/Mosin

- 3135ms Loading file Things/ParaOrdnanceP1445

- 3152ms Loading file Things/RPG7

- 3140ms Loading file Things/RugerPC9

- 3143ms Loading file Things/Scout

- 3134ms Loading file Things/Skorpion

- 3130ms Loading file Things/SphinxAT2000

- 3139ms Loading file Things/Striker

- 3134ms Loading file Things/TaurusJudge

- 3140ms Loading file Things/Tec9

- 3129ms Loading file Things/TMP

- 3140ms Loading file Things/TokarevTT

- 3131ms Loading file Things/Type96LMG

- 3151ms Loading file Things/UltimaRatioHecateII

- 3153ms Loading file Things/Vector

- 3140ms Loading file Things/VektorCP1

- 3151ms Loading file Things/WA2K

- 3136ms Loading file Things/XM8

It appears the problem was moved to another thread. There was a change in CPU usage while audio was loading from 1% in A12 to 0% in A13, and the loading times have increased by 10ms overall for each audio file. Now the bottleneck is the same but it's taking up another core.

The threaded approach would have to be used for each audio file being loaded so that overall you would have each core loading audio files in tandem and each taking 3100ms max. I doubt this would be much more efficient though, and I think the current multithreading approach would break on single core computers (though I don't have one of those handy - testing it would require creating a single mod with SoundDef).

Reading up on some of this I found that the ridiculous loading times could have something to do with audio file decompression, and pausing the thread actually does not help.

[attachment deleted by admin - too old]

[skullywag]

so why does this only occur for some systems, i still load sound files in < 1ms. I have been dealing with the other thread on the forums trying to figure this out and theres nothing on the effected system that seems out of place. If it was a code issue it would effect everyone, no?

Al can you send me a zip of your mods dir (slack direct or pm if youd rather not post it here) and ill retry the test.

[Alistaire]

Another update;

All audio files were exported as OGG Vorbis with the exact properties of vanilla audio files and again the loading times did not drop in the slightest.



Forcing affinity to a single core did not change audio loading times.

CPU drops to 0% with occasional 1% spikes and increases RAM by the size of each audio file with intervals of 3 seconds between increases. The
final RAM usage is proportional to what one might expect of a modded base game (base game 380 MB RAM, modded 390 MB RAM). Assuming
the problem is not in something weird with decompression/extraction/unpacking of audio into RAM.

[Alistaire]

Next update;

Firewall nor anti virus change loading times. I also found this interesting stackexchange answer: Why do my .wav sound effects delay before playing
the first time on iOS? which demonstrates that the problem may lie in something completely different from the audio loading. Anyways I don't
think it's possible for me to check the profiler or otherwise help with bug fixing by e.g attempting to change Load type/Compression on audio files
or whatever since I don't have access to the source.

Another source state similar problems with a nice comparison between an empty application and a complicated one such as a game:
WWW.GetAudioClip() Freeze Bug And Possible Solutions Thread. The loading times in this case are also very similar to the ones achieved in RimWorld
(3100ms consistently). All in all I would assume the problem must be similar to the ones described above.

[ison]

Thanks Alistaire!

The fact that on some computers it takes 3 seconds to load an audio clip, and on others only 1ms clearly shows that there's something wrong here and it seems that it's a Unity's bug and we can't do much about it other than not using WWW class at all.

I guess we could try loading all audio clips in parallel.

For now, I've changed WWWs thread priority to "High". I doubt it will change anything, but we'll see.

//edit

Mantis'd: https://ludeon.com/mantis/view.php?id=2380. Please continue discussion there.