Widelands crashes when loading a multiplayer game

[Oliver Maier]

I play Revision bzr7237[trunk].
I play Together we're strong. On reloading the game crashes. The core dump ends with

 #0 0x0000000000c2fa20 in Widelands::Player::player_number (this=0x0) at ../src/logic/player.h:112
112 PlayerNumber player_number() const {return m_plnum;}

(The earlier parts refer to external libraries that don't have debug information).

The saved game is appended.

[GunChleoc (gunchleoc)]

The problem is connected to the player number not being set correctly somewhere. The error messages keep changing, but this is what I'm getting after a few checks and assertions:

=======================

Replay writer has started
[sync] Reset
widelands: /home/bratzbert/sources/widelands/bug-1388255/src/logic/field.h:184: bool Widelands::Field::is_interior(Widelands::PlayerNumber) const: Assertion `0 < player_number' failed.
Aborted (core dumped)

=======================

ObjectManager: ouch! remaining objects
lastserial: 2605

Game data error
buildings: [/home/bratzbert/sources/widelands/bug-1388255/src/ai/defaultai.cc:2850] Help: I do not know what to do with a constructionsite

=======================

ObjectManager: ouch! remaining objects
lastserial: 2606

Game data error
buildings: [/home/bratzbert/sources/widelands/bug-1388255/src/ai/defaultai.cc:2851] Help: I do not know what to do with a quarry

=======================

widelands: /home/bratzbert/sources/widelands/bug-1388255/src/logic/field.h:171: Widelands::PlayerNumber Widelands::Field::get_owned_by() const: Assertion `(owner_info_and_selections & Player_Number_Bitmask) <= 8' failed.
Aborted (core dumped)

[GunChleoc (gunchleoc)]

For http://bazaar.launchpad.net/~widelands-dev/widelands/bug-1388255/revision/7242, one of the crashes is:

GameSaver::save() took 1141ms
SaveHandler::save_game() took 1141ms
Reloading the game from replay
#gunchleoc: *********** init player 1
#gunchleoc: *********** found player 1
ComputerPlayer(1): initializing (0)
#gunchleoc: *********** end init barbarians -- 1 -- 1
TI(2229): destination disappeared or economy mismatch -> fail
TI(2186): destination disappeared or economy mismatch -> fail
TI(2179): destination appears to have become split from current location -> fail
TI(2228): destination disappeared or economy mismatch -> fail
TI(2199): destination appears to have become split from current location -> fail
TI(2215): destination disappeared or economy mismatch -> fail
Game: Reading Preload Data ... took 2ms
Game: Reading Game Class Data ... took 0ms
Game: Reading Map Data ... Game: Reading Map Data took 1ms
Game: Reading Player Info ... Game: Reading Player Info took 250ms
Game: Calling read_complete()
<snip>
 Reading Players View Data ... Vision check successful for player 1
Vision check successful for player 2
took 31ms
 Reading Player Message Data ... took 1ms
 Reading Objective Data ... took 1ms
 Reading Scripting Data ... took 4ms
 WidelandsMapLoader::load_map_complete() took 563ms
Game: read_complete took: 563ms
Game: Reading Player Economies Info ... took 1ms
Game: Reading Command Queue Data ... took 6ms
Game: Parsing messages ... took 1ms
Game: Reading Interactive Player Data ... took 1ms
GameLoader::load() took 825ms
Done reloading the game from replay
#gunchleoc: replay 4
Replay writer has started
#gunchleoc: replay 5
#gunchleoc: replay 6
#gunchleoc: run 4
[sync] Reset
#gunchleoc: run 5
#gunchleoc: run 6
#gunchleoc: run 7
#gunchleoc: run 8
#gunchleoc: run 9
#gunchleoc: *********** post init tribes/barbarians/helmsmith/walk_ne_00_pc.png -- 1 -- 0
widelands: /home/bratzbert/sources/widelands/bug-1388255/src/ai/defaultai.cc:182: virtual void DefaultAI::think(): Assertion `player_->player_number() > 0' failed.
Aborted (core dumped)

The #gunchleoc: *********** post line contains random stuff, so we definitely are having some Fun With Pointers here. My intuition is that the AI gets initialized before the game finished loading.

[GunChleoc (gunchleoc)]

After some more digging, the heart of the problem is that the point in time that DefaultAI::think() is called for the first time is not fixed in relation to game loading. I don't know where exactly in the code these things get triggered though.

I won't have time for a week to work on this, so if somebody else wants to have a go, be my guest. There are 2 NOCOM comments in the code and a bunch of #gunchleoc log statements.

[TiborB (tiborb95)]

I would say that late_initialization() in defaultai is not run - and only when restoring network game, in other situations (single game start+load, networkgame start) it is run. There is a test: 'if (tribe_ == nullptr) ' that runs late_initialization, but it seems that tribe_ is set on that stage

[GunChleoc (gunchleoc)]

14/11/2014 14:32, sgrìobh TiborB:
> I would say that late_initialization() in defaultai is not run - and
> only when restoring network game, in other situations (single game
> start+load, networkgame start) it is run. There is a test: 'if (tribe_
> == nullptr) ' that runs late_initialization, but it seems that tribe_ is
> set on that stage
>

There is a problem with that anyway - I am currently trying to fix it in

https://bugs.launchpad.net/widelands/+bug/1388255

When loading a network savegame, AI can start thinking before the game
finished loading. Testing for game->is_loaded() seems to help, but the
savegame I'm testing then comes up with a new segfault, so I have to do
some more hunting.

[GunChleoc (gunchleoc)]

Oops, I thought I was in the other bug.

[GunChleoc (gunchleoc)]

I am stuck with this bug - if somebody else want to take this on, be my guest.

[TiborB (tiborb95)]

I will look at it.

But I think the bug has been there for very very long time, so it is not that badly critical :)

[TiborB (tiborb95)]

@GunChleoc

On second look I am bit confused, because the bug description does not say what I mean is the core of problem. This is: 'loading of saved network game crashes.' The description implies this is single player game.

[GunChleoc (gunchleoc)]

The attached savegeme is a multiplayer game. I could also get a crash with a different multiplayer game, so this seems to be a general problem. I set it to critical, because I think we should definitely fix this before build19.

[TiborB (tiborb95)]

I changed the bug name, if you dont mind :)

[TiborB (tiborb95)]

terrible, my current idea is that AI receives notifications before DefaultAI:think() is first time run (when it is first time run it runs late_initialization).

That initialization code is huge mess, I must say

[GunChleoc (gunchleoc)]

Yes, something is wrong with the whole control flow somewhere, and I have trouble tracking everything down. I manages to squash a bug by making sure that the game is running before the AI starts thinking, but then I get a second bug which is just a segfault again.

[Hans Joachim Desserud (hjd)]

Just marked bug 1407081 as a duplicate which also noted team information and game type doesn't seem to be shown. If this is unrelated we should probably look more into it once this crasher has been fixed.

[SirVer (sirver)]

Can somebody attach a crashing savegame with current trunk?

[SirVer (sirver)]

Reason I am asking: the attached savegame loads cleanly for me at r7237 - where it is saved. And it is not compatible with current trunk anymore so it does not load.

[TiborB (tiborb95)]

Sirver, it is 100% reproducible, just few minutes of game, save, load -> crash

[SirVer (sirver)]

Tibor: the game you attached in #18 loads and plays for me without any issues - no crashes, nothing. This indicates an invalid memory write - probably an early delete.

[SirVer (sirver)]

Just to clarify: it loads and runs on Mac OS X, bzr r7343 build in debug mode with clang-3.5.

[TiborB (tiborb95)]

Is it expected that this should be loadable in #18 at all?
And does this mean a problem is with loading not saving?

[TiborB (tiborb95)]

re: "Just to clarify ..." - I did not see that comment - interesting...

[SirVer (sirver)]

> Is it expected that this should be loadable in #18 at all?

Could be. If memory is freed, but not immediately overwritten on my system, the program will still work. On your system the memory might be immediately overwritten and so it crashes.

> And does this mean a problem is with loading not saving?

Yes, that is very likely the case I'd say.

[TiborB (tiborb95)]

I recompiled with clang and no difference... (save,load -> crash)

Can you too try the save-load cycle?

[SirVer (sirver)]

I was finally able to reproduce this. It only happens when there is an AI player in the loaded game, right? I think that was the missing point.

The problem was that the AI was consuming NoteImmovables even though it's player_ variable was not set yet.

[SirVer (sirver)]

Fixed in r7360.

[TiborB (tiborb95)]

I am really glad this is fixed. Thanks!!!

"It only happens when there is an AI player in the loaded game, right?" funny, I never play real internet games, only use it for AI testing...

[TiborB (tiborb95)]

SirVer, I just run into same problem in my branch - with shipnote_subscriber -, used the same fix and it loads now...

but are you sure that this fix is proper? Will the AI be subscribed to the notifications once it is properly loaded?

[SirVer (sirver)]

> but are you sure that this fix is proper? Will the AI be subscribed to the notifications once it is properly loaded?

I am sure that the AI gets all notifications. I am not sure if it's internal book keeping is all correct then. But before the player is set, the AI could not have processed these informations in any meaningful way, so I do not believe that this fix makes the behavior of the AI in any way less reliable or more buggy then before. So use it until we find issues with it.

[GunChleoc (gunchleoc)]

Fixed in build19-rc1.