MantisBT - VCMI
View Issue Details
0002383VCMIAI - Adventure Mappublic2016-01-18 15:142022-04-12 11:04
vmarkovtsev 
SXX 
normalminoralways
closedfixed 
DarwinMacOSX10.11.2
0.98f 
0.99 
0002383: AI infinitely loops with this save - secSkill desync
Map: "The Lord of War" (http://heroesportal.net/maps.php?type=H3AB-XL&sort=r [^])
Save: https://mega.nz/#!YI5hTYYJ!-NSMjIqZXY43slyJ82dSm-BrfdxNFewzDvE0TdJWoQo [^]

Log:

Hero King Unaghor moved from 10 43 0 to 10 43 0. Returning 1.
Hero King Unaghor visited tile (11 42 0)
Striving to goal of type CLEAR WAY TO (1 45 0) (King Unaghor)
Considering goal CLEAR WAY TO (1 45 0) (King Unaghor)
Cannot evaluate goal FIND OBJ 358 (King Unaghor)
Considering goal FIND OBJ 358 (King Unaghor)
Considering goal VISIT TILE (11 42 0) (King Unaghor)
Trying to realize VISIT TILE (11 42 0) (King Unaghor) (value 3.438)
Moving hero King Unaghor to tile 11 42 0
Hero doesn't have any movement points left!
System message: Server encGooutn tfearlesde ai np raopbplleymi:n gH.e.r.o tdhoaets nr'etq uheasvte maunsyt m ohvaevmee nbte epno ifnitssh yle!ft
!
System message: Server encountered a problem: Got false in applying... that request must have been fishy!
Hero King Unaghor moved from 10 43 0 to 10 43 0. Returning 1.
Hero King Unaghor visited tile (11 42 0)
Striving to goal of type CLEAR WAY TO (1 45 0) (King Unaghor)
Considering goal CLEAR WAY TO (1 45 0) (King Unaghor)
Cannot evaluate goal FIND OBJ 358 (King Unaghor)
Considering goal FIND OBJ 358 (King Unaghor)
Considering goal VISIT TILE (11 42 0) (King Unaghor)
Trying to realize VISIT TILE (11 42 0) (King Unaghor) (value 3.438)
Moving hero King Unaghor to tile 11 42 0
Hero doesn't have any movement points left!
System message: Server encountered a problem: Hero doesn't have any movement points leftG!ot
 false in applying... that request must have been fishy!
System message: Server encountered a problem: Got false in applying... that request must have been fishy!
Hero King Unaghor moved from 10 43 0 to 10 43 0. Returning 1.
Hero King Unaghor visited tile (11 42 0)
Striving to goal of type CLEAR WAY TO (1 45 0) (King Unaghor)
Considering goal CLEAR WAY TO (1 45 0) (King Unaghor)
Cannot evaluate goal FIND OBJ 358 (King Unaghor)
Considering goal FIND OBJ 358 (King Unaghor)
Considering goal VISIT TILE (11 42 0) (King Unaghor)
Trying to realize VISIT TILE (11 42 0) (King Unaghor) (value 3.438)
Moving hero King Unaghor to tile 11 42 0
Hero doesn't have any movement points left!
System message: Server encountered a problem: Hero doesn't have any movement pointsG olte ffta!ls
e in applying... that request must have been fishy!
System message: Server encountered a problem: Got false in applying... that request must have been fishy!
Hero King Unaghor moved from 10 43 0 to 10 43 0. Returning 1.
Hero King Unaghor visited tile (11 42 0)
Striving to goal of type CLEAR WAY TO (1 45 0) (King Unaghor)
Considering goal CLEAR WAY TO (1 45 0) (King Unaghor)
Cannot evaluate goal FIND OBJ 358 (King Unaghor)
Considering goal FIND OBJ 358 (King Unaghor)
Considering goal VISIT TILE (11 42 0) (King Unaghor)
Trying to realize VISIT TILE (11 42 0) (King Unaghor) (value 3.438)
Moving hero King Unaghor to tile 11 42 0
Hero doesn't have any movement points left!
Got false in applying... that request must have been fishy!
System message: Server encountered a problem: Hero doesn't have any movement points left!
System message: Server encountered a problem: Got false in applying... that request must have been fishy!
Hero King Unaghor moved from 10 43 0 to 10 43 0. Returning 1.
Hero King Unaghor visited tile (11 42 0)
Striving to goal of type CLEAR WAY TO (1 45 0) (King Unaghor)
Considering goal CLEAR WAY TO (1 45 0) (King Unaghor)
Cannot evaluate goal FIND OBJ 358 (King Unaghor)
Considering goal FIND OBJ 358 (King Unaghor)
Considering goal VISIT TILE (11 42 0) (King Unaghor)
Trying to realize VISIT TILE (11 42 0) (King Unaghor) (value 3.438)
Moving hero King Unaghor to tile 11 42 0
Hero doesn't have any movement points left!
Load save, end turn
No tags attached.
related to 0001590closed SXX border guard - useless expenditure of a turn. 
child of 0002459resolved SXX Desync found! - Work toward full sync of save games 
? The Lord of War.h3m (152,581) 2016-01-18 15:14
https://bugs.vcmi.eu/file_download.php?file_id=2427&type=bug
zip save_lord_of_war.zip (2,394,656) 2016-01-18 15:14
https://bugs.vcmi.eu/file_download.php?file_id=2428&type=bug
Issue History
2016-01-18 15:14vmarkovtsevNew Issue
2016-01-18 15:14vmarkovtsevStatusnew => assigned
2016-01-18 15:14vmarkovtsevAssigned To => Warmonger
2016-01-18 15:14vmarkovtsevFile Added: The Lord of War.h3m
2016-01-18 15:14vmarkovtsevFile Added: save_lord_of_war.zip
2016-01-18 18:46SXXNote Added: 0006303
2016-01-18 18:46SXXAssigned ToWarmonger => SXX
2016-01-18 18:58SXXNote Edited: 0006303bug_revision_view_page.php?bugnote_id=6303#r3145
2016-01-18 20:04vmarkovtsevNote Added: 0006304
2016-01-18 20:35SXXNote Added: 0006305
2016-01-18 20:36SXXNote Edited: 0006305bug_revision_view_page.php?bugnote_id=6305#r3147
2016-01-30 11:33SXXRelationship addedrelated to 0002326
2016-02-25 02:54SXXNote Added: 0006448
2016-02-25 03:17SXXRelationship addedrelated to 0001590
2016-02-25 03:17SXXRelationship deletedrelated to 0002326
2016-02-25 03:22SXXSummaryAI infinitely loops with this save => AI infinitely loops with this save - secSkill desync
2016-02-25 05:59SXXNote Added: 0006452
2016-08-19 20:27SXXRelationship addedrelated to 0002459
2016-08-19 20:29SXXNote Added: 0006572
2016-08-19 20:44SXXRelationship deletedrelated to 0002459
2016-08-19 20:44SXXRelationship addedchild of 0002459
2016-08-19 20:45SXXNote Added: 0006573
2016-08-19 20:45SXXNote Edited: 0006573bug_revision_view_page.php?rev_id=3210
2016-08-20 14:39SXXNote Deleted: 0006573
2016-08-20 15:03SXXNote Added: 0006576
2016-09-11 18:56SXXNote Added: 0006646
2016-09-11 18:56SXXStatusassigned => resolved
2016-09-11 18:56SXXFixed in Version => 0.99
2016-09-11 18:56SXXResolutionopen => fixed
2022-04-12 11:04PovelitelStatusresolved => closed

Notes
(0006303)
SXX   
2016-01-18 18:46   
(edited on: 2016-01-18 18:58)
This one require HotA to be enabled.

PS: Assign to myself, it's pathfinder issue.

(0006304)
vmarkovtsev   
2016-01-18 20:04   
https://github.com/vcmi/vcmi/pull/157 [^]
(0006305)
SXX   
2016-01-18 20:35   
(edited on: 2016-01-18 20:36)
I don't think this is valid fix for anything. Also network code is look correct for me, but condition naming is weird.

There basically two issues:
1 - First of all AI for some reason attempt to visit border guard indefinitely. Likely some bug in VCAI or Quest / border guard.

2 - Second it's pathfinder tell VCAI on client that it's have enough movement points while movement cost on server end up being different. Such situations are possible in complex cases because pathfinder code not yet used on server for movement validation and decade old spaghetti code validate movement instead.

(0006448)
SXX   
2016-02-25 02:54   
So I started working on this one. It's really weird, but looks like there is serious desync going. Green AI hero (King Unaghor) does have basic pathfinding skill in client gamestate, but not on server.

This it's reason why pathfinder pretend that hero can still move while server think it's not possible.
(0006452)
SXX   
2016-02-25 05:59   
Problem that made AI to visit border guard over and over again is fixed in 0001590. Though I have no idea why desync occur so I'll leave this one open.
(0006572)
SXX   
2016-08-19 20:29   
Little update on this one. There is some chance that desync in that save was originally caused by some issue with both heroes initialization and random generator desync.

Check 0002459 for more details.
(0006576)
SXX   
2016-08-20 15:03   
Oops. End up there is actually cuz of that desync.

So it's exactly it: problem with skills caused by fact that HeroRecruited::applyGs use random generator from gamestate and it's desynced after game start.

In the end it's occur only when hero have default expirience, but not type set so it's called from gamestate like that:
HeroRecruited::applyGs -> initObj -> initHero -> levelUpAutomatically
(0006646)
SXX   
2016-09-11 18:56   
Fixed with PR209 merge:
https://github.com/vcmi/vcmi/commit/2543e068acd7e91ad4234ddfd7622c5e4fac664f [^]