MantisBT - VCMI
View Issue Details
0001048VCMIOtherpublic2012-08-07 03:442012-08-09 08:12
Tow 
Ivan 
urgentmajoralways
closedfixed 
 
 
0001048: The new filesystem is extremely slow
On my working copy debug mode build needs about 40 seconds to initialize:
- CResourceHandler::initialize() takes 12 s.
- CResourceHandler::loadFileSystem("ALL/config/filesystem.json") takes 28s.
- CResourceHandler::loadModsFilesystems() takes about 0.1 s.

I have about 6400+ files in 340 folders in working location. That's much but loading should not take that long. The extremely check-heavy debug VC implementation of STL surely adds to it (release mode build needs about 4 s.) but it can't be helped. 40 s. startup makes my development efforts very miserable.

On my H3 installation VCMI (release mode) startup time is about triple of what 0.89 needed (~3s instead of ~1s). That's also bad.

Therefore some optimizations are needed ASAP.

Some ideas:
* initialLoader can collect only DIR and ARCHIVE entries
* it seems that same locations are scanned multiple times (LOCAL/Data is the same as LOCAL/Data on Win, right?)
* don't collect entries of type OTHER — they're not used anyway
* get rid of initialLoader altogether — filesystem.json is assumed to be in de-facto hardcoded location anyway and that ALL/LOCAL/GLOBAL substitutions should be easy to handle by hand. We should not scan the whole DATA_DIR, just go for the locations listed in filesystem.json.

If you any further info, let me know. I can try looking for bottlenecks with profiler but I guess some "obvious" optimizations should be done first.
No tags attached.
Issue History
2012-08-07 03:44TowNew Issue
2012-08-07 03:44TowStatusnew => assigned
2012-08-07 03:44TowAssigned To => Ivan
2012-08-07 03:45TowDescription Updatedbug_revision_view_page.php?rev_id=1803#r1803
2012-08-07 06:59IvanNote Added: 0002843
2012-08-07 11:34IvanNote Added: 0002845
2012-08-07 11:34IvanStatusassigned => feedback
2012-08-07 21:05douggie_mNote Added: 0002848
2012-08-07 21:06douggie_mNote Edited: 0002848bug_revision_view_page.php?bugnote_id=2848#r1805
2012-08-07 21:22douggie_mNote Edited: 0002848bug_revision_view_page.php?bugnote_id=2848#r1812
2012-08-08 08:28TowNote Added: 0002855
2012-08-08 08:28TowStatusfeedback => assigned
2012-08-08 09:49IvanNote Added: 0002856
2012-08-08 12:06IvanNote Added: 0002857
2012-08-08 12:18IvanNote Edited: 0002857bug_revision_view_page.php?bugnote_id=2857#r1814
2012-08-09 08:11TowNote Added: 0002866
2012-08-09 08:11TowStatusassigned => closed
2012-08-09 08:12TowResolutionopen => fixed

Notes
(0002843)
Ivan   
2012-08-07 06:59   
12 + 28 seconds? Wow. For me it is just 200 ms.
In my case profiler reported that 50% of time is boost::to_upper conversion - not much can be helped here.
Maybe boost uses some slow WinAPI function that we should avoid to use?

>> don't collect entries of type OTHER
they're used from time to time (e.g. .pal). I'll have to add some types first.

>> get rid of initialLoader altogether
What about such dirs like MP3 and Mp3? Linux case-sensivity causes problems here. It still can be improved by decreasing scanning depth though.
(0002845)
Ivan   
2012-08-07 11:34   
I've made some tweak in rev. 2813
- initial loader checks only several types of data
- same locations shouldn't be scanned multiple times
- decreased amount of data scanned by initial loader

Profiling on my side is almost useless - I don't have any notable bottlenecks.
If loading speed is still an issue I will need to know where the bottleneck is.
(0002848)
douggie_m   
2012-08-07 21:05   
(edited on: 2012-08-07 21:22)
Steps to reproduce? Some strace/gdb/valgring/whatever command?

I don't see any slowdown with starting a new game besides previous versions (like r2799 w/o "new filesystem"). I cannot save and cannot load saved game with current r2813 still though. Loading recovered-from-I-dunno-from game shown that it's not slower than in r2799.

(0002855)
Tow   
2012-08-08 08:28   
Thanks, Ivan, r2813 is a big improvement.

Initial loader time decreased to 0.2 s

Data loading time firstly increased... but eventually I found out that MSVC 10 implementation of std::unordered_map destructor is extremely slow http://webcache.googleusercontent.com/search?q=cache:FjTgGTHZLocJ:connect.microsoft.com/VisualStudio/feedback/details/567859+&cd=1&hl=pl&ct=clnk&client=firefox-a [^] (bug is fixed in VC 11 only)
After replacing with boost::unordered_map this step takes about 9 s.

Mod loading is now only 2 ms.

---

Now (as of r2815) my loading times look as follows:
Creating console and logfile: 0
     Initialization: 177
        Loading resource at ALL/Config took 14 ms.
        Loading resource at ALL/Data/H3ab_bmp.lod took 407 ms.
        Loading resource at ALL/Data/H3bitmap.lod took 847 ms.
        Loading resource at ALL/Data took 989 ms.
        Loading resource at ALL/Maps took 3362 ms.
        Loading resource at ALL/Mp3 took 93 ms.
        Loading resource at LOCAL/Games took 165 ms.
        Loading resource at ALL/Data/H3ab_ahd.snd took 2 ms.
        Loading resource at ALL/Data/Heroes3-cd2.snd took 0 ms.
        Loading resource at ALL/Data/Heroes3.snd took 235 ms.
        Loading resource at ALL/Data took 1624 ms.
        Loading resource at ALL/Data/H3ab_spr.lod took 0 ms.
        Loading resource at ALL/Data/H3sprite.lod took 1102 ms.
        Loading resource at ALL/Sprites took 22 ms.
        Loading resource at ALL/Data/H3ab_ahd.vid took 5 ms.
        Loading resource at ALL/Data/H3ab_ahd.vid took 2 ms.
        Loading resource at ALL/Data/Video took 0 ms.
     Data loading: 8875
     Mod filesystems: 2
File system handler: 9055

---

I ran profiler around LibClasses::loadFilesystem.
Profiler says that 64,4% of time is spent in CFilesystemLoader::listFiles, that splits onto:
- 43,3 pp (percent points) in operator++ for path -> almost everything is spent on internal slow text path operations (VC wstring debug implementation)
- 5 pp in calling filesystem::extension
- 4,3 pp in ResourceID c-tor
- 8pp other

29,5% is in CResourceLoader::addLoader, including:
- 16,5 pp for loader->getEntries (and in that 12 pp for ResourceID ctor)
- 5,7 pp for unordered_map operator[]

4,5% is spent in CLodArchiveLoader::CLodArchiveLoader, of which 3,2 pp goes for unordered_map operator[].


Doesn't look good, the biggest time-eater is dir iterator, that probably can't be helped. I guesss I'll just have to clean my working directory and move away maps (2719 files, over 3s.). Or... build a .lod from them? ;)
(0002856)
Ivan   
2012-08-08 09:49   
at least 1 second improvement is still possible - Data/ is scanned twice - once for "DATA" entry and once for "SOUNDS". I'll remove recursion for second one.

In general loading should be a bit faster after sounds\video are controlled by new FS as well - right now *.snd's and *.vid's are scanned twice.

>> Or... build a .lod from them? ;)
That... should work :)
This trick won't work with music - SDL_Mixer don't have API for loading from memory but everything else should work.
Maybe we can add support for something like .zip at some point? May work as nice container for mods or map packs in future.

BTW - and how fast release mode right now?
(0002857)
Ivan   
2012-08-08 12:06   
(edited on: 2012-08-08 12:18)
And while you're on it - can you update windows video player to new FS? This is last area (along with linux video player) which still uses old archives system.

It should be pretty much similar to sounds (rev 2818)

EDIT: updated Linux player in rev 2819.
SndHandler can be removed after Windows player update.

(0002866)
Tow   
2012-08-09 08:11   
>> BTW - and how fast release mode right now?

On my WoG installation:
Initialization: 2 ms
Data loading: 89 ms
Mod filesystem: 1 ms

When the bloating checks are gone and optimizations kick in, the new filesystem is quite fast. Still slightly slower than it was before (VCMI 0.89 took about 950ms to start, trunk needs 1200 ms) but I think it's acceptable price for gained functionality.


>> Maybe we can add support for something like .zip at some point? May work as nice container for mods or map packs in future.

Yes, sooner or later we'll have to. Alas, some new library dependency will be required. If you find a good library and want to add archive support, let me know. :)


>> And while you're on it - can you update windows video player to new FS?

Done in r2821. :)
Not sure about that but I guess the "save resource to file" functionality could be moved to FS interface.