"UPDATE_WALKABOUT_POS: missing sprite component"

[rversteegen]

Just received a surprising crash report while playing wandering-hamster.rpg; an NPC walkabout slice (which does exist) with no sprite component. Should be impossible. There are no errors in g_debug.txt. From the file timestamps, it happened immediately after entering map 16.

It looks like the user opened wandering-hamster.rpg in Custom and saved it:
0.7 Last edited by: [[OHRRPGCE gorgonzola 20200502.11799 gfx_directx+sdl+fb/music_sdl FreeBASIC 1.05.0 (01-31-2016) GCC 5.3.0 x86 pdb Built on vampirecell -g -gen gcc Win32 32-bit]] branch_rev 11797
(Maybe we should have some better way of identifying a game, like hashing the .rpg every time it's saved, or every time it's distributed, saving the history of hashes in general.reld, and including that in crash reports.)

Unless we find something odd with map 16, I have no idea how to narrow down this bug, since the minidumps don't include any of the heap. Maybe we should include a dump of the slice tree in crash reports.

######### Report 1851c8e2-5c0c-41f3-9cc5-28dcfea6c351 #########
           Upload time 2020-07-16 03:08:48 UTC
            Crash time 2020-07-14 18:20:20 UTC
               AppName OHRRPGCE-Game
       ExceptionModule C:\OHRRPGCE\support\CrashRpt1403.dll
      ExceptionAddress 0x73e047fc
     MemoryUsageKbytes 34996
       OperatingSystem Windows 10 Home Build 18363
           GeoLocation en-us
            Crash Time 5627.4845610
         Recent File 0 opened=5627.4636635 size=1926  path=C:\Users\thald\AppData\Local\Temp\ohrrpgce20200714124633.145.tmp\playing.tmp\\wander.z16
         Recent File 1 opened=5627.4646809 size=9461  path=C:\Users\thald\AppData\Local\Temp\ohrrpgce20200714124633.145.tmp\playing.tmp\\wander.e16
         Recent File 2 opened=5627.4840571 size=14400  path=C:\Users\thald\AppData\Local\Temp\ohrrpgce20200714124633.145.tmp\playing.tmp\\wander.dox
         Recent File 3 opened=5627.4657373 size=3807  path=C:\Users\thald\AppData\Local\Temp\ohrrpgce20200714124633.145.tmp\playing.tmp\\wander.n16
         Recent File 4 opened=5627.4823934 size=324493 omitting=toobig path=C:\Users\thald\AppData\Local\Temp\ohrrpgce20200714124633.145.tmp\playing.tmp\\walkabouts.rgfx
         Recent File 5 opened=5627.4790972 size=3007  path=C:\Users\thald\AppData\Local\Temp\ohrrpgce20200714124633.145.tmp\playing.tmp\\wander.l16
                 Build OHRRPGCE gorgonzola 20200502.11799 gfx_directx+sdl+fb/music_sdl FreeBASIC 1.05.0 (01-31-2016) GCC 5.3.0 x86 pdb  Built on vampirecell -g -gen gcc Win32 32-bit
                 Error UPDATE_WALKABOUT_POS: missing sprite component
           Extra files g_debug.txt g_debug_archive.txt wander.dox wander.e16 wander.l16 wander.n16 wander.z16
     Backend init info gfx_directx
          Playing game C:\OHRRPGCE\wandering-hamster.rpg
              Username thald
             Game name Wandering Hamster
            Git commit 8f5f78e36
               Symbols ohrrpgce-symbols-win-music_sdl-r11799-2020-05-02-gorgonzola.7z
                   CPU x86 GenuineIntel family 6 model 142 stepping 12, 4 cores
             Exception 0x00000000 / 0x00000000
Minidump crash address 0x73e047fc
        Crashed thread 0

@ UPDATE_WALKABOUT_POS 	(walkabouts.bas:176 + 0x15)
    174  DIM sprsl as Slice Ptr
    175  sprsl = LookupSlice(SL_WALKABOUT_SPRITE_COMPONENT, walkabout_cont)
 -> 176  BUG_IF(sprsl = NULL, "missing sprite component")
    177  sprsl->Y = gmap(11) - z
@ UPDATE_WALKABOUT_NPC_SLICES 	(walkabouts.bas:298 + 0x1c)
    296     END IF
    297    END IF
 -> 298    update_walkabout_pos npc(i).sl, npc(i).x, npc(i).y, npc(i).z
    299    IF npc(i).sl <> 0 THEN
@ DISPLAYALL           	(game.bas:1076 + 0x5)
   1074  ' is to only update a single slice as required from setmapxy,
   1075  ' or to stop using walkabout slices there.
 ->1076  update_walkabout_slices()
   1077 

[rversteegen]

I have very similar crash report (8c92ceac) from RMZ. This time, it's a missing walkabout sprite component on a hero slice, and it happened after loading map 55 due to a quick load in Vikings of Midgard - Complete, running the 20200530.11864 Windows nightly.

@ SET_WALKABOUT_SPRITE 	(walkabouts.bas:139 + 0x15)
    137  ELSE
    138   sprsl = LookupSlice(SL_WALKABOUT_SPRITE_COMPONENT, cont)
 -> 139   BUG_IF(sprsl = NULL, "missing sprite component")
    140   ChangeSpriteSlice sprsl, sprTypeWalkabout, pic, pal
@ VISHERO              	(walkabouts.bas:336 + 0x22)
    334   WITH gam.hero(slot)
    335    IF .id >= 0 THEN
 -> 336     set_walkabout_sprite .sl, .pic, .pal
    337    END IF
@ PARTY_CHANGE_UPDATES 	(moresubs.rbas:511 + 0x5)
    509  evalherotags
    510  evalitemtags  'Because of items with 'actively equipped' tags
 -> 511  vishero
    512  tag_updates
@ DOLOADGAME           	(game.bas:1066 + 0x5)
   1064  END IF
   1065 
 ->1066  party_change_updates
   1067  refresh_purchases()

[rversteegen]

Marking this a release-blocker because people are running into it a lot. This was probably introduced by the hero slice lifespan changes in gorgonzola.

RMZ encountered it when swapping out and locking a hero right before changing maps without a wait. Adding a wait worked around it.

Wobbler ran into it in KBB and emailed us a testcase. It crashed at the end of the Dr. Cube RPG. Again, his script did add hero and swap out hero immediately before a use door, and moving them after the use door or commenting out the add hero fixed it.

We have a mountain crash reports for this, which come in a quite a variety, including:

__________________________________________________________________________________________
8c92ce  20200720  wip 20200530.11864             ...debugc <- SET_WALKABOUT_SPRITE(walkabouts.bas:139) <- VISHERO <- PARTY_CHANGE_UPDATES <- DOLOADGAME
Game    col***    Win/32/gfx_directx             SET_WALKABOUT_SPRITE: missing sprite component
                  viking.rpg Vikings of Midgard 
__________________________________________________________________________________________
394866  20200801  wip 20200731.11936             ...debugc <- SET_WALKABOUT_SPRITE(walkabouts.bas:139) <- VISHERO <- PARTY_CHANGE_UPDATES <- ADDHERO <- ADD_REM_SWAP_LOCK_HERO
Game    pau***    Win/32/gfx_directx             SET_WALKABOUT_SPRITE: missing sprite component
                  kaiju.rpg Kaiju Big Battel Fi 
__________________________________________________________________________________________
d73846  20200801  wip 20200731.11936             ...debugc <- UPDATE_WALKABOUT_POS(walkabouts.bas:176) <- UPDATE_WALKABOUT_NPC_SLICES <- DISPLAYALL <- main
Game    pau***    Win/32/gfx_directx             UPDATE_WALKABOUT_POS: missing sprite component
                  kaiju.rpg Kaiju Big Battel Fi  
__________________________________________________________________________________________
628ae2  20200801  wip 20200731.11936             OrphanSlice(slices.bas:632) <- SetSliceParent <- UPDATE_WALKABOUT_HERO_SLICES <- UPDATE_WALKABOUT_SLICES
Game    pau***    Win/32/gfx_directx             EXCEPTION_ACCESS_VIOLATION_READ
                  kaiju.rpg Kaiju Big Battel Fi  
__________________________________________________________________________________________
f6243a  20200823  wip 20200823.11965             ChangeSpriteSlice(slices.bas:2247) <- SET_WALKABOUT_SPRITE <- VISHERO <- SCRIPT_FUNCTIONS <- SCRIPTINTERPRETER_LOOP
Game    col***    Win/32/gfx_directx             EXCEPTION_ACCESS_VIOLATION_WRITE
                  AxeCop.rpg Axe Cop             

[bob-the-hamster]

This is a tricky one!
I have a test case that crashes on this, but very tiny seemingly irrelevant changes to the source code can prevent the crash from happening.

For example, if I comment out everything in the implementation of "camera follows hero" in scriptcommands.bas then the crash doesn't happen. Or if I add debug comments inside update_HeroSliceContext() then the crash doesn't happen.

I assume memory is being corrupted and that these small changes are altering the layout of the corrupted memory just enough to prevent the crash

[rversteegen]

Sounds like it could be a dangling pointer. Can you use valgrind or asan (AddressSanitizer)? I have a lot of poor luck with valgrind, sometimes I can't really get it to work, and it's a pain that I always have to spend a long time updating misc/valgrind_suppressions.txt after having upgraded parts of my OS. asan doesn't seem to have that problem. To use asan compile with "scons asan=1", which compiles in memory error checking into C code (it forces gengcc=1). Like valgrind, asan can report reads/writes off the end of allocated memory or access to freed memory.

…

On Tue, 27 Apr 2021 at 09:04, James Paige ***@***.***> wrote: This is a tricky one! I have a test case that crashes on this, but very tiny seemingly irrelevant changes to the source code can prevent the crash from happening. For example, if I comment out everything in the implementation of "camera follows hero" in scriptcommands.bas then the crash doesn't happen. Or if I add debug comments inside update_HeroSliceContext() then the crash doesn't happen. I assume memory is being corrupted and that these small changes are altering the layout of the corrupted memory just enough to prevent the crash — You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub <#1137 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAI4RCPDTPZQDR4HKXLFRN3TKXIPBANCNFSM4O7TTNZA> .

[bob-the-hamster]

I tried valgrind, and the crash simply didn't happen. I'll try asan also On Mon., Apr. 26, 2021, 11:41 p.m. Ralph Versteegen, < ***@***.***> wrote:

…

Sounds like it could be a dangling pointer. Can you use valgrind or asan (AddressSanitizer)? I have a lot of poor luck with valgrind, sometimes I can't really get it to work, and it's a pain that I always have to spend a long time updating misc/valgrind_suppressions.txt after having upgraded parts of my OS. asan doesn't seem to have that problem. To use asan compile with "scons asan=1", which compiles in memory error checking into C code (it forces gengcc=1). Like valgrind, asan can report reads/writes off the end of allocated memory or access to freed memory. On Tue, 27 Apr 2021 at 09:04, James Paige ***@***.***> wrote: > This is a tricky one! > I have a test case that crashes on this, but very tiny seemingly > irrelevant changes to the source code can prevent the crash from happening. > > For example, if I comment out everything in the implementation of "camera > follows hero" in scriptcommands.bas then the crash doesn't happen. Or if I > add debug comments inside update_HeroSliceContext() then the crash doesn't > happen. > > I assume memory is being corrupted and that these small changes are > altering the layout of the corrupted memory just enough to prevent the crash > > — > You are receiving this because you authored the thread. > Reply to this email directly, view it on GitHub > <#1137 (comment) >, > or unsubscribe > < https://github.com/notifications/unsubscribe-auth/AAI4RCPDTPZQDR4HKXLFRN3TKXIPBANCNFSM4O7TTNZA > > . > — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#1137 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AA2IR6LF43VQQHP3MFVJEP3TKYW5RANCNFSM4O7TTNZA> .

[bob-the-hamster]

Oh, another question: how much do we trust the SWAP built-in? We use it a lot for simple types like integers, but I think the only places we ever use it for complex UDTs is when swapping heroes and when re-ordering menudef items in custom I remember being paranoid about SWAP... But I don't remember why. On Tue., Apr. 27, 2021, 7:55 a.m. James Paige, ***@***.***> wrote:

…

I tried valgrind, and the crash simply didn't happen. I'll try asan also On Mon., Apr. 26, 2021, 11:41 p.m. Ralph Versteegen, < ***@***.***> wrote: > Sounds like it could be a dangling pointer. > > Can you use valgrind or asan (AddressSanitizer)? > > I have a lot of poor luck with valgrind, sometimes I can't really get it > to > work, and it's a pain that I always have to spend a long time updating > misc/valgrind_suppressions.txt after having upgraded parts of my OS. > > asan doesn't seem to have that problem. To use asan compile with "scons > asan=1", which compiles in memory error checking into C code (it forces > gengcc=1). Like valgrind, asan can report reads/writes off the end of > allocated memory or access to freed memory. > > On Tue, 27 Apr 2021 at 09:04, James Paige ***@***.***> wrote: > > > This is a tricky one! > > I have a test case that crashes on this, but very tiny seemingly > > irrelevant changes to the source code can prevent the crash from > happening. > > > > For example, if I comment out everything in the implementation of > "camera > > follows hero" in scriptcommands.bas then the crash doesn't happen. Or > if I > > add debug comments inside update_HeroSliceContext() then the crash > doesn't > > happen. > > > > I assume memory is being corrupted and that these small changes are > > altering the layout of the corrupted memory just enough to prevent the > crash > > > > — > > You are receiving this because you authored the thread. > > Reply to this email directly, view it on GitHub > > < > #1137 (comment)>, > > or unsubscribe > > < > https://github.com/notifications/unsubscribe-auth/AAI4RCPDTPZQDR4HKXLFRN3TKXIPBANCNFSM4O7TTNZA > > > > . > > > > — > You are receiving this because you commented. > Reply to this email directly, view it on GitHub > <#1137 (comment)>, > or unsubscribe > <https://github.com/notifications/unsubscribe-auth/AA2IR6LF43VQQHP3MFVJEP3TKYW5RANCNFSM4O7TTNZA> > . >

[rversteegen]

According to SWAP in the manual,

For UDTs, Swap simply exchanges the contents of the structures, without any operators or methods being called.

In other words it shouldn't call any copy-constructors or other constructors, which could be problematic. I don't remember avoiding SWAP.

[bob-the-hamster]

asan does a nice job of narrowing down the problem:

=================================================================
==28631==ERROR: AddressSanitizer: heap-use-after-free on address 0x61300006b898 at pc 0x000000990baa bp 0x7fffffffc2f0 sp 0x7fffffffc2e8
READ of size 8 at 0x61300006b898 thread T0
    #0 0x990ba9 in OrphanSlice /home/james/src/ohrrpgce/slices.bas:621

0x61300006b898 is located 24 bytes inside of 368-byte region [0x61300006b880,0x61300006b9f0)
freed by thread T0 here:
    #0 0x7ffff6effa10 in free (/usr/lib/x86_64-linux-gnu/libasan.so.3+0xc1a10)
    #1 0x990829 in DeleteSlice /home/james/src/ohrrpgce/slices.bas:599
    #2 0x990a0d in DeleteSliceChildren /home/james/src/ohrrpgce/slices.bas:610
    #3 0x9906e9 in DeleteSlice /home/james/src/ohrrpgce/slices.bas:594
    #4 0x7d5c11 in REFRESH_WALKABOUT_LAYER_SORT /home/james/src/ohrrpgce/walkabouts.bas:461
    #5 0x6f351a in REFRESH_MAP_SLICE /home/james/src/ohrrpgce/game.bas:4105
    #6 0x6de43e in GMAP_UPDATES /home/james/src/ohrrpgce/game.bas:2436
    #7 0x6de66a in LOADMAP_GMAP /home/james/src/ohrrpgce/game.bas:2449
    #8 0x7b0af8 in LOADMAPSTATE_GMAP /home/james/src/ohrrpgce/yetmore2.bas:463
    #9 0x6e795d in PREPARE_MAP /home/james/src/ohrrpgce/game.bas:3104
    #10 0x6de21d in INTERPRET_SCRIPTS /home/james/src/ohrrpgce/game.bas:2417
    #11 0x70b909 in main /home/james/src/ohrrpgce/game.bas:772
    #12 0x7ffff48cb2e0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202e0)

previously allocated by thread T0 here:
    #0 0x7ffff6effd28 in malloc (/usr/lib/x86_64-linux-gnu/libasan.so.3+0xc1d28)
    #1 0x98f461 in NewSlice /home/james/src/ohrrpgce/slices.bas:508
    #2 0x98ebe3 in NewSliceOfType /home/james/src/ohrrpgce/slices.bas:461
    #3 0x7cfa15 in CREATE_WALKABOUT_SLICES /home/james/src/ohrrpgce/walkabouts.bas:34
    #4 0x7cfdda in CREATE_HERO_SLICES /home/james/src/ohrrpgce/walkabouts.bas:55
    #5 0x4db292 in ADDHERO /home/james/src/ohrrpgce/moresubs.rbas:130
    #6 0x508099 in GAMESTATE_PARTY_FROM_RELOAD /home/james/src/ohrrpgce/savegame.rbas:597
    #7 0x4fd572 in GAMESTATE_FROM_RELOAD /home/james/src/ohrrpgce/savegame.rbas:304
    #8 0x4fc8e6 in NEW_LOADGAME /home/james/src/ohrrpgce/savegame.rbas:268
    #9 0x4fae2c in LOADGAME /home/james/src/ohrrpgce/savegame.rbas:153
    #10 0x6cb161 in DOLOADGAME /home/james/src/ohrrpgce/game.bas:1045
    #11 0x70c8fc in main /home/james/src/ohrrpgce/game.bas:891
    #12 0x7ffff48cb2e0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202e0)

SUMMARY: AddressSanitizer: heap-use-after-free /home/james/src/ohrrpgce/slices.bas:621 in OrphanSlice

I haven't figured out what to fix yet, but this definitely narrows the search :D

[bob-the-hamster]

Okay, I found a fix for this.

Swapping an active hero and a reserve hero means that you end up with a reserve hero's slice parented to the hero layer, and a active hero's slice parented to the reserve layer.

This normally doesn't matter, and gets fixed every tick when sorting the heroes for drawing.

But it matters if a change of map happens in the same tick as a hero swap, because in that case, the code that preserves the active heroes from deletion when recreating the hero layer misses one, because it is still parented to the reserve layer even though it belongs to an active hero now

At least I THINK that was what was happening, :D

At any rate, this does fix the crash for me.

[rversteegen]

Glad that's solved.

I would just have parented the hero slices to hero_layer(slot) but actually what you did is better, because we ought to loosen the restrictions on protected slices, allowing hero slices to be parented to map layers for example.