WL unable to reload a huge saved game it wrote

[Astuur]

This report is for bzr5915 on Windows XP SP3
The machine is a Core I7 with 6GByte of RAM using 3GB inside Windows.

It describes erratic behaviour in conjunction with an extreme game.
The map is 512x512 and has been played for about 18h with one human and 7 AI competitors, all making progress.
Roughly since the 12th hour the game had become almost unplayable. It used one core of my machine totally
and looked like a series of slides. All the same I let it run for some more hours, with only very little user interaction.
The game was up and running as described, I saved it (Maxi_A10.wgf) and exited normally.
I was then unable to load the saved game with the same machine and same version that created the save.

stderr.txt is:
______________________________________________________________
terminate called after throwing an instance of 'std::bad_alloc'
  what(): std::bad_alloc
______________________________________________________________

stdout.txt is attached

[Astuur (wolfsteinmetz)]

Here is the saved game

[Hans Joachim Desserud (hjd)]

When loading the game I get another error:
Game data error
Map objects [.../widelands/src/logic/immovable.cc:791] immovable type [.../widelands/src/logic/immovable.cc:781] world does not define immovable type "boulders5"

I suspect this may be unrelated, if you have added or tweaked the resources Widelands uses. (Seems likely, especially based on your posts on the forum.) If it is only images, I guess it will suffice to copy-paste any existing image, if you can provide where it should be added. But if it requires changes to conf-files, we will probably need those as well to reproduce this.

[Astuur (wolfsteinmetz)]

Ah - yes, of course - I forgot. Sorry about this.
The map was generated using a modified setup, that included some of the new graphic files I have created lately.
(see graphics frum) I do this to test new graphics in game.

To modify your widelands installation, so that you can load the saved game, I have prepared
a rar archive, that will add and replace some of the graphics and change some conf files.
_If_ you want to try, you should extract it in the parent directory above widelands.

I don't have a saved game from an unmodified widelands installation, for such a huge map and long playing time,
but the problem does not seem related to the changed graphics, I think.

again, sorry for this...

[Hans Joachim Desserud (hjd)]

Right. Thanks for reporting this. Very nice and thorough report. By adding additional graphics files to the content of worlds/greenland I was able to reproduce this. (Please consider using .zip-format another time though).

[Hans Joachim Desserud (hjd)]

I have attached a backtrace from gdb. The crash occured after a while where the command line had report only x left of ware y for a while, for different wares, though I don't know if this is related.

[SirVer (sirver)]

bad_alloc means that your computer ran out of memory. What is taking this amount of memory is beyond me.... obviously the memory consumption scales with the map size (more objects, more fields) but widelands should be on the light site with memory consumption.

[SirVer (sirver)]

I was unable to load this savegame or the map it contains even after applying the changes. Could you provide the map only so that it can be launched with current trunk? I am interested in reproducing this by doing a simulation run myself while watching the profiler output, but I lack a 512x512 map that gives the computer a real chance.

[Astuur (wolfsteinmetz)]

Yes, I have still kept the map in question.
It was saved as a directory and I have now zipped it for uploading here.

[SirVer (sirver)]

I cannot load this map, someone the changed RAR archive doesn't do the trick for me. Could you modify the map so that it does not use any of your new immovables? If not, it's cool. I will then use "the Wood", a map which is available for download on the website which is also quite big.

[Astuur (wolfsteinmetz)]

Sirver, taking out those "Boulders" manually would be a long error-prone process with such a huge map.
Rememer, this was auto-generated map, using the random map generator from the editor. (I have modified my setup for it accordingly).
I have played more than one of these maps, and the memory problem was always present.
So I am very confident, it does not matter if you use my map, or generate a 512x512 map with the generator yourself.
For your comfort I have prepared a new map for you that was built and loads in bzr6037.
Very happy, Sirver, you're working on that problem!

[Astuur (wolfsteinmetz)]

Ah.. forgot: I had all tribes participating in that game - in case it matters

[SirVer (sirver)]

thanks a lot astuur, this indeed spares my some cycles :)

Do not get your hope's up too high. I fixed a lot (~4 or so) performance bottlenecks where bad algorithms or wrong asymptotic reasoning was applied; this will help to reduce CPU drain by a bit. However, it does not affect Memory Foodprint. It makes it possible to play a 256x256 map on my system with ~10 times speed on ~20 fps though, which is not too shabby. This should make it possible to play long games and I am looking forward on feedback from your part.

About he memory issue: I am unsure what takes this much memory and I have yet to find a practical way to get a breakdown of memory consumption inside widelands. I might not be able to reduce the memory used while playing.. However, a game that runs should also be loadable, I will investigate this, when I have more time at hand.

[SirVer (sirver)]

Okay, I started a game 8 comps random AI vs each other. I will post some random statistics here, mainly so I can remember them but also because they might be interesting for others.

r6048, sound disabled, OpenGL renderer, 1680x1050 resolution. I had census and statistics disabled (I noticed some i18n functions having a non zero impact on performance. As I do not except this to be the main culprit, i decided to skip those functions in my analysis for now). Optimized build with debug symbols: -O3 -g -DDEBUG

On game start, speed x 10, Memory footprint is ~900MB, 80% of one CPU is taken. The cmdqueue has ~40.000 entries and keeping it a heep makes ~12% of all CPU time.

After ~5 game hours, speed x 7, Memory Footprint is ~800 MB, 84% of one CPU is taken, The cmdqueue has ~73.000 entries and the CPU bottlenecks are with ~10% still the heap adjusting, follwed by the replay_writing (Game::SyncWrapper and RealFsStreamWrite::Data) which comes likely from autosaving. I also noticed that showing the minimap has a very heavy impact on performance.
The game runs into a kind of equilibrium now: the computers are so surrounded by trees that the hardly make any progress.

After ~19 game hours, speed x 7, Memory Footprint is ~900 MB, ~85% of one CPU is taken, the cmdqueue has ~78.800 entries and the CPU bottlenecks is still the heap adjusting, closely followed by a new contender IdleWareSupply::nr_supplies which is to be expected as there are many roads where items are just laying around. The game is pretty much ended: only the pink player is still making some progress, all others gave up on the trees.

Summary: my last few optimizations did improve the situation considerably. My 2.2GHz Box with 4Gigs RAM has no problem simulation at x7, but the edges are showing: x 10 is not possible.

The cmdqueue needs some rethinking. the heap is just not cutting it and I think about replacing it via a hash_map of queue containers. I will try that out.
Also, Economy::find_best_supply needs work: currently it checks every supply (warehouses and idle wares floating around) for every request periodically and tries to find the best. It could be improved by only looking closer to the request for a better supply or by using a heurisitc and settling for a pretty good supply.

Also, the statistics menu is a bottleneck in long games. Obviously the whole statistic data is recalculated for each frame which becomes a lot when the game runs > a few hours. This should be a new bug report.
The same for the minimap: It gets redrawn to often. It should maybe only complety redraw itself every few seconds or always one line at each frame (i remember that S2 did it that way. This gives a cool effect when some area is conquered).
This also should be a new bug report.

Next, I'll try to save and load the game.

[Hans Joachim Desserud (hjd)]

> It should maybe only complety redraw itself every few seconds or always one line at each frame (i remember that S2 did it that way. This gives a cool effect when some area is conquered).

So _that's_ how they did it. I've always wondered about that one.

Otherwise thanks for an informative post. :)

[SirVer (sirver)]

Saving and loading the game was no problem. Memory foodprint while loading was < 1Gig, after loading ~900MB. CPU trace looks comparable after loading. For your testing convenience, I attach a replay.

Some of my optimizations might indeed have reduced memory consuption by a bit while loading, but I do not expect that the problem is completely solved with that. If you are able to reproduce this bug with a savegame that can be loaded with trunk, let me know.

[Astuur (wolfsteinmetz)]

Thanks for your brave work, Sirver and the clues derived from it.!

From my experience I can say that memory consumption does seem
to be depending heavily on all the players' progress in the game.
In contrast to the game you monitored, all players in the original game
made good progress initially, and all but one (yellow) kept on doing so.

Using the r6048 widelands.exe from Tino's package within my usual setup,
I have again been able to load the map in question.
It even is playable with only very little jerkyness!
So I have done a screenshot (from the replay) to show the extent of
all the players' progress. (attached here)
I have also done some screenshots of the statistics to let you better
evaluate all the factors that may play a role in memory consumption.

Unfortunately I had edited the out the random number and map ID
at the time, so I cannot rebuild this particular map with an unmodified system.

[Astuur (wolfsteinmetz)]

On the way out from the replay, I got an error message from
MS Visual C++ Runtime:
Runtime error!
Program D:/Games/Widelands/widelands.exe

The application has requested the Runtime to terminate in an unusual way.
Please contact the application's support team for more information.

I attach the stdout.txt from this
with a lot of line like this:

"TI(166698): destination disappeared or economy mismatch -> fail"

[SirVer (sirver)]

Astuur, about #20: This is likely because you tried to run the replay with an new version of widelands. I do not expect this to be a big new bug.

I assume, the problem with loading the _savegame_ remains, is this correct? Can you try to reproduce the bug with a new trunk revision? I was unable to so far but will continue to try.

[Astuur (wolfsteinmetz)]

No, Sirver -- not correct!
I can load a savegame (my latest from that game - the one that never loaded before) and even play the game
with only very slight jerkyness. Timelapse is of course very limited.
I did this to produce a new replay that I wanted in order to show you the full minimap (without fog of war).
I had not kept the old ones.
I loaded the savegame into r6048 from Tino's yesterday's package.
Or to be precise: The widelands.exe is from that package.
I must keep my modification and additions to some conf files and pngs, because this random map was built
on my system and I have modified the config file for the random game generator to use my new boulder and
some other stuff I am trying to add later.
Because of this it will never load on a standard installation.

Here is another approach:
I have prepared a rar archive for you. It successfully converted my new r6048 installation into my usual test system.
The one, that produced the map and could not load it afterwards. Place it in the /widelands directory and let it
overwrite if you have a mind to.
I could load the __savegame__ into the so changed installation and play.
I hope you can handle a rar archive. My 7z stuff cannot pack/unpack deep directory trees.
Any good?

[SirVer (sirver)]

Well, if the bug is gone, there is no reason to reproduce it then, is there? :P. My changes might have had a stronger impact on memory than I expected. I close this as fixed committed for now, as the original problems have vanished.

Btw, r6051 contains another improvement of the situation. You might want to update and try that. Tino already made a build.

[Astuur (wolfsteinmetz)]

That may have been a bit too optimistic.
I had loaded the savegame and played half an hour, but
after installing r6051 we're back to "won't load" :(.
But that is not the reason. Even the old r6048 will not load the original savegame any more now.
I keep getting C++ runtime error mentioned above.
(not when loading savegames produced with the same version - you were right with this.)

For a moment had the feeling that the option to zip the safegame
may play a role for the question whether it loads the safegame or not, but
I could not verify this. It now stalls both ways.

There is something fishy about it.
I will create a new 512x512 map with an unmodified standard installation and start another
long time game.
I'll come back to report.
Thanks for all your efforts.

Please take a look at the diagramm.
It shows 2 attempts to load the savegame. What strikes me, is that for a long time
memory consumption is at a plateau, before the game finally crashes.

[SirVer (sirver)]

That indeed is fishy... I set this back to confirmed and I'll await your input. For the records, I have now a ~47hours long game with 8 computers where 7 do make process. The game loads fine in a release build of current trunk and plays back without jerk on x4 (~70-80% CPU) taking ~1.2GB of RAM (which is a lot). Minimap screenshot attached. I will let the game run for another day on x4 today.

[Astuur (wolfsteinmetz)]

For bzr6051 (unmodified) on Win XP SP3

I am testing a 512x512 map in the context of this bug.
It runs mostly unattended, but I am a player (singleplayer game) amongst 8.
for the 4th time now WL closed down while I was not watching.
stderr.txt has this one line:
"PANIC: unprotected error in call to Lua API (not enough memory)"

It seems to happen when WL autosaves.
I'm attaching a memory graph from this situation.

Will turn autosave off and try sme more.

I know I have a lot of used memory already without WL, but
still it seems very much what WL expects.
I guess I need to change to a 64 bit OS soon :)

[Astuur (wolfsteinmetz)]

I also have a "wl_autosave2.wgf" (which loads okay)
The "wl_autosave.wgf" exist in the dir, but is not displayed in the game;
it is from the same minute than the autsave2 but seems to be to small and broken (cannot open in 7z)

[SirVer (sirver)]

I assume now that this is an issue with windows and your memory limit. What kind of windows version are you running? Why is there only 3Gigs of Memory available when you have 6 Installed.

This document from microsoft states, that on windows vista starters 1 GB is the limit for Physical Memory Limits; I assume that this is per process. Widelands will need more for such big games. Can this apply here?

http://msdn.microsoft.com/en-gb/library/aa366778.aspx

[SirVer (sirver)]

Sorry, you stated that you are using XP. Sorry to miss that. For XP, the maximum per Process is 2GB. This is for the whole virtual adress space. On my system, widelands only needs 1.5 Gigs, but I am not sure how much it will need on windows.

[Astuur (wolfsteinmetz)]

Yes, it's a 32bit Windows.
There is some add-on for it, which I have installed, that extends that border to 3 GB
I think XP can provide 3 GB of memory, but maybe not for one application.

After some more playing (no problem without autosave), I did a
manual save today and it crashed.
The game had been running for about 2,5 hours.
I should mention, that in contrast to older versions of WL,
there was no jerkyness at all with the r6051, but that usually came
after longer playing times.
The savegame was broken and invalid (much too small)

So the end of the line is most likely the lack of available RAM
with games on a 512x512 map.
I must say, that I am surprised about the huge amount of memory, such maps need.
Playing that has not been too much fun anyhow: Saving the game took almost 1 min!
and during that time I was blocked from all other tasks.
Well, who need maps that big?
I'll create a 256x256 map now and will run that long time.
I think you can finally close this report down, now.

[SirVer (sirver)]

Me too I am a bit confused by the loads of memory used by widelands. I tried checking with valgrind where how much memory was used, but it runs too slow to give a good impression. I will try with google perf tools soon, maybe on the wihack.

This bug report is for the moment somewhere in between

* Fix committed (that's what I set it too, because it looks good) for the massive CPU reduction I introduced in the last few commits. They make a big difference with the playability of big maps and reduces the CPU usage to 10-30% on normal maps (4 players) on my computer
* Won't fix/Invalid: the crash with bad alloc likely occures due to constraints put up by Windows 32. This is not of big concern to me as it will fix itself over time (as 32 bit gets less common and more memory becomes mainstream). In ~2 years using 2 Gigs of RAM will not be an issue for a single program.
* Confirmed. Widelands memory consumption needs some followup investigation. See bug 885579.

[SirVer (sirver)]

Released in build17-rc1.