search

libretro / flycast

Flycast is a multiplatform Sega Dreamcast emulator. NOTE: No longer actively developed, use upstream repo for libretro from now on - https://github.com/flyinghead/flycast
http://reicast.com
GNU General Public License v2.0
155 stars 77 forks source link

Auto save-state/loads broken #891

Closed ghost closed 4 years ago

ghost commented 4 years ago

It would appear that save states are saving but upon load I'm experiencing a black screen with the fps counter barely moving/not moving at all. I've tried removing lto and even a debug build but I can't seem to mitigate the issue.

A gdb backtrace shows the only flycast_libretro originating thread waiting on a condition variable.

Let me know if you have any ideas and I can help debug this further.

flyinghead commented 4 years ago

Can you get a verbose log? A backtrace with flycast symbols of the threads would be helpful too.

ghost commented 4 years ago

No problems with the core if save/load states are disabled.

flycast compiled against dbf96863b03ff020e32850b5a748904373056f4f

flags:

-march=armv8-a+crc+simd -mtune=cortex-a35 -mcpu=cortex-a35 -Ofast -pipe -fno-plt -fdata-sections -ffunction-sections -Wl,--gc-sections -fno-stack-protector -fno-ident -fomit-frame-pointer -fmerge-all-constants -fno-math-errno -Wl,--gc-sections -falign-functions=1 
-falign-jumps=1 -falign-loops=1 -fno-unwind-tables -fno-asynchronous-unwind-tables -fno-unroll-loops -fmerge-all-constants -frename-registers -funsafe-math-optimizations -ftree-vectorize -DHOST_CPU=0x20000006 -DTARGET_LINUX_ARMv8 -DNO_ASM -DARM_ASM -frename-registers -ftree-vectorize -g -DTARGET_NO_OPENMP -D__LIBRETRO__  
-DHAVE_GLSYM_PRIVATE -DNO_VERIFY -DLOW_END -DLOW_RES -fno-builtin-sqrtf -DHAVE_MODEM -DNDEBUG -DRELEASE -funroll-loops -DHAVE_TEXUPSCALE -DHAVE_OPENGLES -DHAVE_OPENGLES2 DFLAC__HAS_OGG=0 -DFLAC__NO_DLL -DHAVE_LROUND -DHAVE_STDINT_H -DHAVE_STDLIB_H -DHAVE_SYS_PARAM_H -D_7ZIP_ST -DUSE_FLAC -DUSE_LZMA 
-O3 -c -fno-strict-aliasing -ffast-math -fomit-frame-pointer -fPIC
Using host libthread_db library "/usr/lib/libthread_db.so.1".
0x0000007f94b0e200 in pthread_cond_timedwait@@GLIBC_2.17 () from /usr/lib/libpthread.so.0
(gdb) thread apply all bt

Thread 12 (Thread 0x7e7a820170 (LWP 2174)):
#0  0x0000007f94b0dea0 in pthread_cond_wait@@GLIBC_2.17 () from /usr/lib/libpthread.so.0
#1  0x0000005560c47a24 in ?? ()
#2  0xb94103995100135a in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 11 (Thread 0x7e7b527170 (LWP 2173)):
#0  0x0000007f9230c2f8 in ioctl () from /usr/lib/libc.so.6
#1  0x0000007f94db5ef0 in ?? () from /usr/lib/libasound.so.2
#2  0x0000005560c47fd4 in ?? ()
#3  0x0000007ff7616110 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 10 (Thread 0x7e7bd28170 (LWP 2169)):
#0  0x0000007f94b109c0 in do_futex_wait.constprop () from /usr/lib/libpthread.so.0
#1  0x0000007f94b10af8 in __new_sem_wait_slow.constprop.0 () from /usr/lib/libpthread.so.0
#2  0x0000007f9298bd68 in ?? () from /usr/lib/mali-egl/libgbm.so.1
#3  0x0000007ff7615c70 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 9 (Thread 0x7e7c529170 (LWP 2168)):
#0  0x0000007f9230aa14 in poll () from /usr/lib/libc.so.6
#1  0x0000007f92b9aee0 in ?? () from /usr/lib/mali-egl/libgbm.so.1
#2  0x0000007ff7615be0 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 8 (Thread 0x7e7cd2a170 (LWP 2167)):
#0  0x0000007f94b109c0 in do_futex_wait.constprop () from /usr/lib/libpthread.so.0
#1  0x0000007f94b10af8 in __new_sem_wait_slow.constprop.0 () from /usr/lib/libpthread.so.0
#2  0x0000007f92b9aca8 in ?? () from /usr/lib/mali-egl/libgbm.so.1
#3  0x0000007ff7615be0 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 7 (Thread 0x7e7d52b170 (LWP 2166)):
#0  0x0000007f94b109c0 in do_futex_wait.constprop () from /usr/lib/libpthread.so.0
#1  0x0000007f94b10af8 in __new_sem_wait_slow.constprop.0 () from /usr/lib/libpthread.so.0
#2  0x0000007f92b9aca8 in ?? () from /usr/lib/mali-egl/libgbm.so.1
#3  0x0000007ff7615be0 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 6 (Thread 0x7e7dd2c170 (LWP 2165)):
#0  0x0000007f94b109c0 in do_futex_wait.constprop () from /usr/lib/libpthread.so.0
#1  0x0000007f94b10af8 in __new_sem_wait_slow.constprop.0 () from /usr/lib/libpthread.so.0
#2  0x0000007f92b9aca8 in ?? () from /usr/lib/mali-egl/libgbm.so.1
#3  0x0000007ff7615be0 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 5 (Thread 0x7e7e52d170 (LWP 2164)):
--Type <RET> for more, q to quit, c to continue without paging--
#0  0x0000007f94b109c0 in do_futex_wait.constprop () from /usr/lib/libpthread.so.0
#1  0x0000007f94b10af8 in __new_sem_wait_slow.constprop.0 () from /usr/lib/libpthread.so.0
#2  0x0000007f92b9aca8 in ?? () from /usr/lib/mali-egl/libgbm.so.1
#3  0x0000007ff7615be0 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 4 (Thread 0x7e84afa170 (LWP 2163)):
#0  0x0000007f922e1a18 in clock_nanosleep@@GLIBC_2.17 () from /usr/lib/libc.so.6
#1  0x0000007f922e71e4 in nanosleep () from /usr/lib/libc.so.6
#2  0x0000007f9230d868 in usleep () from /usr/lib/libc.so.6
#3  0x0000007f92b416a8 in ?? () from /usr/lib/mali-egl/libgbm.so.1
#4  0x0000007ff7615bd0 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 3 (Thread 0x7e852fb170 (LWP 2161)):
#0  0x0000007f94b109c0 in do_futex_wait.constprop () from /usr/lib/libpthread.so.0
#1  0x0000007f94b10af8 in __new_sem_wait_slow.constprop.0 () from /usr/lib/libpthread.so.0
#2  0x00000055609ac2cc in ?? ()
#3  0x0000007f94b074b8 in start_thread () from /usr/lib/libpthread.so.0
#4  0x0000007f9231395c in thread_start () from /usr/lib/libc.so.6

Thread 2 (Thread 0x7f91964170 (LWP 2160)):
#0  0x0000007f94b0dea0 in pthread_cond_wait@@GLIBC_2.17 () from /usr/lib/libpthread.so.0
#1  0x0000005560d37890 in ?? ()
#2  0x0000007ff76162a0 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 1 (Thread 0x7f919a3470 (LWP 2159)):
#0  0x0000007f94b0e200 in pthread_cond_timedwait@@GLIBC_2.17 () from /usr/lib/libpthread.so.0
#1  0x0000007f8e800678 in scond_wait_timeout (cond=0x5570a8f7a0, lock=0x5570a91210, timeout_us=timeout_us@entry=100000) at core/libretro-common/rthreads/rthreads.c:900
#2  0x0000007f8e7bb098 in cResetEvent::Wait (this=this@entry=0x7f90c256d8 <rs>, msec=msec@entry=100) at core/libretro/common.cpp:537
#3  0x0000007f8d5a55fc in rend_single_frame () at core/hw/pvr/Renderer_if.cpp:192
#4  0x0000007f8e7b7278 in retro_run () at core/libretro/libretro.cpp:1222
#5  0x0000005560d57154 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)```

```librga:RGA_GET_VERSION:4.00,4.000000                                                                            
ctx=0x5570a66850,ctx->rgaFd=3                                                                                   
Rga built version:version:+2017-09-28 10:12:42                                                                  
[INFO] RetroArch 1.8.6 (Git 6c4c93e17b)                                                                         
[INFO] Redirecting save file to "/roms/dreamcast/m.srm".
[INFO] Redirecting save state to "/roms/dreamcast/m.state".                                                                                                                   [INFO] === Build =======================================                                                                                                                                                                         [INFO] Capabilities:  ASIMD                                                                                     
[INFO] Built: May 14 2020                                                                                                                                                                                                        
[INFO] Version: 1.8.6                                                                                           
[INFO] Git: 6c4c93e17b                                                                                          
[INFO] =================================================                            
[INFO] Loading dynamic libretro core from: "./flycast_libretro.so"
[INFO] [Overrides] no core-specific overrides found at /home/odroid/.config/retroarch/config/Flycast/Flycast.cfg.
[INFO] [Overrides] no content-dir-specific overrides found at /home/odroid/.config/retroarch/config/Flycast/dreamcast.cfg.
[INFO] [Overrides] no game-specific overrides found at /home/odroid/.config/retroarch/config/Flycast/m.cfg.
[INFO] [Environ]: GET_LANGUAGE: "0".                                                                            
[INFO] [Environ]: RETRO_ENVIRONMENT_SET_CORE_OPTIONS_INTL.   
[INFO] [Environ]: SET_CONTROLLER_INFO.                                                                          
[INFO] [Remaps]: remap directory: /home/odroid/.config/retroarch/config/remaps
[INFO] Redirecting save file to "/roms/dreamcast/m.srm".
[INFO] Redirecting save state to "/roms/dreamcast/m.state".
[INFO] [Environ]: GET_LOG_INTERFACE.                                                                            
[INFO] [Environ]: GET_PERF_INTERFACE.                                                                           
[INFO] [Environ]: SET_PIXEL_FORMAT: XRGB8888.                                                                   
[INFO] [Environ]: SET_KEYBOARD_CALLBACK.                                                                        
[INFO] [Environ]: SET_DISK_CONTROL_EXT_INTERFACE.
[INFO] Content loading skipped. Implementation will load it on its own.
[INFO] [Environ]: GET_RUMBLE_INTERFACE.                                                                         
[libretro INFO] Rumble interface supported!   
[INFO] [Environ]: SYSTEM_DIRECTORY: "/home/odroid/.config/retroarch/bios".                                                                                                                                                       
[INFO] [Environ]: SET_SAVE_STATE_IN_BACKGROUND: yes.                                                                                                                                                                             
[INFO] [Environ]: RETRO_ENVIRONMENT_SET_CORE_OPTIONS_DISPLAY.                                                                                                                                                                    
[INFO] [Environ]: RETRO_ENVIRONMENT_SET_CORE_OPTIONS_DISPLAY.
[libretro INFO] File extension is: .cdi
[INFO] [Environ]: GET_PREFERRED_HW_RENDER.
[INFO] [Environ]: SET_HW_RENDER.
[INFO] Requesting OpenGLES2 context.
[libretro INFO] 00:00:723 hw/mem/_vmem.cpp:556 N[VMEM]: Info: nvmem is enabled, with addr space of size 4GB
[libretro INFO] 00:00:850 hw/maple/maple_devs.cpp:569 N[MAPLE]: Loaded VMU from file "/home/odroid/.config/retroarch/bios/dc/vmu_save_A1.bin"
[libretro INFO] 00:00:851 hw/maple/maple_devs.cpp:569 N[MAPLE]: Loaded VMU from file "/home/odroid/.config/retroarch/bios/dc/vmu_save_B1.bin"
[libretro INFO] 00:00:852 hw/maple/maple_devs.cpp:569 N[MAPLE]: Loaded VMU from file "/home/odroid/.config/retroarch/bios/dc/vmu_save_C1.bin"
[libretro INFO] 00:00:854 hw/maple/maple_devs.cpp:569 N[MAPLE]: Loaded VMU from file "/home/odroid/.config/retroarch/bios/dc/vmu_save_D1.bin"
[libretro INFO] 00:00:865 nullDC.cpp:152 N[BOOT]: [LUT]: Product number: T1212N    .
[INFO] [Environ]: SET_ROTATION: 0
[INFO] [RCHEEVOS]: ext_hash 0b886555 ('cdi')
[INFO] Skipping SRAM load..
[INFO] [RCHEEVOS]: Load task finished
[INFO] Found auto save state in: /roms/dreamcast/m.state.auto
Auto-loading save state from "/roms/dreamcast/m.state.auto" succeeded.
[INFO] Version of libretro API: 1
[INFO] Compiled against API: 1
[INFO] [Cheats]: Load game-specific cheatfile: /home/odroid/.config/retroarch/cheats/Flycast/m.cht
[INFO] [Audio]: Set audio input rate to: 44100.00 Hz.
[INFO] [Video]: Video @ 960x720
[INFO] [Video]: Using HW render, OpenGL driver forced.
[INFO] [Video]: Using configured "gl" driver for GL HW render.
[INFO] [GL]: Found GL context: kms
[INFO] [GL]: Detecting screen resolution 1074791425x1074791425.
rk-debug mali-ver=rsx-p0-1.2
EGL: major=1, minor=4
EGL: Vendor=ARM
EGL: Version=1.4 Bifrost-"r6p0-01rel0"
EGL: ClientAPIs=OpenGL_ES
EGL: Extensions=EGL_KHR_partial_update EGL_KHR_image_pixmap EGL_EXT_image_dma_buf_import EGL_KHR_config_attribs EGL_KHR_image EGL_KHR_image_base EGL_KHR_fence_sync EGL_KHR_wait_sync EGL_KHR_gl_colorspace EGL_KHR_get_all_proc_addresses EGL_IMG_context_priority EGL_ARM_pixmap_multisample_discard EGL_ARM_implicit_external_sync EGL_KHR_gl_texture_2D_image EGL_KHR_gl_renderbuffer_image EGL_KHR_create_context EGL_KHR_surfaceless_context EGL_KHR_gl_texture_cubemap_image EGL_EXT_create_context_robustness
EGL: ClientExtensions=EGL_EXT_client_extensions EGL_EXT_platform_base EGL_KHR_client_get_all_proc_addresses EGL_KHR_platform_x11 EGL_EXT_platform_x11 EGL_KHR_platform_gbm

[INFO] [GL]: Vendor: ARM, Renderer: Mali-TDVX.
[INFO] [GL]: Version: OpenGL ES 3.2 v1.r6p0-01rel0.abe21775750b0ba1ad10e2a1a5cf9985.
[INFO] [GL]: Using resolution 0x0
[INFO] [GL]: Default shader backend found: glsl.
[INFO] [Shader driver]: Using GLSL shader backend.
[WARN] [GL]: Stock GLSL shaders will be used.
[INFO] [GLSL]: Found GLSL vertex shader.
[INFO] [GLSL]: Found GLSL fragment shader.
[INFO] [GLSL]: Linking GLSL program.
[INFO] [GLSL]: Found GLSL vertex shader.
[INFO] [GLSL]: Found GLSL fragment shader.
[INFO] [GLSL]: Linking GLSL program.
[INFO] [GLSL]: Found GLSL vertex shader.
[INFO] [GLSL]: Found GLSL fragment shader.
[INFO] [GLSL]: Linking GLSL program.
[INFO] [GL]: Using 1 textures.
[INFO] [GL]: Loaded 1 program(s).
[INFO] [GL]: Initializing HW render (512 x 512).
[INFO] [GL]: Max texture size: 8192 px, renderbuffer size: 8192 px.
[INFO] [GL]: Supports FBO (render-to-texture).
[WARN] [udev]: Couldn't open any keyboard, mouse or touchpad. Are permissions set correctly for /dev/input/event*?
[INFO] [udev]: Plugged pad: odroidgo2_joypad (1:1) on port #0.
[INFO] [udev]: Pad #0 (/dev/input/event2) supports 0 force feedback effects.
[INFO] [Joypad]: Found joypad driver: "udev".
[WARN] [udev]: Full-screen pointer won't be available.
[INFO] [Font]: Using font rendering backend: bitmap.
[INFO] [Video]: Found display server: null
[INFO] ALSA: Using signed 16-bit format.
[INFO] ALSA: Period size: 384 frames
[INFO] ALSA: Buffer size: 1536 frames
[INFO] [Menu]: Found menu display driver: "gl".
[INFO] [Font]: Using font rendering backend: freetype.
[INFO] [Font]: Using font rendering backend: freetype.
[INFO] [Font]: Using font rendering backend: freetype.
[INFO] [Menu]: Found menu display driver: "gl".
[CDROM] No sg devices found and sg kernel module is not loaded.
[INFO] [LED]: LED driver = 'null' 0x556104f928
[INFO] [MIDI]: Initializing ...
[INFO] [MIDI]: Input disabled.
[INFO] [MIDI]: Output disabled.
[INFO] [MIDI]: Initialized "alsa" driver.
[INFO] Loading history file: [/home/odroid/.config/retroarch/content_history.lpl].
[INFO] Loading history file: [/home/odroid/.config/retroarch/content_music_history.lpl].
[INFO] Loading history file: [/home/odroid/.config/retroarch/content_image_history.lpl].
[INFO] Loading favorites file: [/home/odroid/.config/retroarch/content_favorites.lpl].
[INFO] [GL]: VSync => on
[INFO] [Font]: Using font rendering backend: freetype.
[INFO] [Font]: Using font rendering backend: freetype.
[INFO] [Font]: Using font rendering backend: freetype.
[INFO] [Environ]: SET_INPUT_DESCRIPTORS:
[INFO] Loading state: "/roms/dreamcast/m.state.auto".
[INFO] State size: 28120411 bytes.
[INFO] State size: 27589179 bytes.
[libretro INFO] 00:02:223 hw/maple/maple_devs.cpp:569 N[MAPLE]: Loaded VMU from file "/home/odroid/.config/retroarch/bios/dc/vmu_save_A1.bin"
[libretro INFO] 00:02:224 hw/maple/maple_devs.cpp:569 N[MAPLE]: Loaded VMU from file "/home/odroid/.config/retroarch/bios/dc/vmu_save_B1.bin"
[libretro INFO] 00:02:225 hw/maple/maple_devs.cpp:569 N[MAPLE]: Loaded VMU from file "/home/odroid/.config/retroarch/bios/dc/vmu_save_C1.bin"
[libretro INFO] 00:02:227 hw/maple/maple_devs.cpp:569 N[MAPLE]: Loaded VMU from file "/home/odroid/.config/retroarch/bios/dc/vmu_save_D1.bin"
[libretro INFO] 00:02:290 hw/maple/maple_devs.cpp:569 N[MAPLE]: Loaded VMU from file "/home/odroid/.config/retroarch/bios/dc/vmu_save_A1.bin"
[libretro INFO] 00:02:291 hw/maple/maple_devs.cpp:569 N[MAPLE]: Loaded VMU from file "/home/odroid/.config/retroarch/bios/dc/vmu_save_B1.bin"
[libretro INFO] 00:02:292 hw/maple/maple_devs.cpp:569 N[MAPLE]: Loaded VMU from file "/home/odroid/.config/retroarch/bios/dc/vmu_save_C1.bin"
[libretro INFO] 00:02:293 hw/maple/maple_devs.cpp:569 N[MAPLE]: Loaded VMU from file "/home/odroid/.config/retroarch/bios/dc/vmu_save_D1.bin"
# stops here
flyinghead commented 4 years ago

Does loading a savestate work when loaded manually as opposed to autosave/load?

ghost commented 4 years ago

I confirm that manually saving/loading state works.

flyinghead commented 4 years ago

Thanks for confirming. I haven't tested auto-save/load for a long time so I wouldn't be surprised if it's broken on all platforms.

ghost commented 4 years ago

what's curious is when it's stuck on the condition variable, if I ctrl-c then it says save state loaded but then proceeds to exit (as expected).

flyinghead commented 4 years ago

Can you check the size of the .state.auto files compared to that of regular .state files? Savestates are now compressed so they will all have a different size but they should be comparable.

On my system auto-savestates are truncated. It seems RA exits before the savestate is flushed to disk. A good test for this issue is to rename a .state file to .state.auto and check if it autoloads fine.

ghost commented 4 years ago

I turned save state compression off. Both state and state.auto files were the same size but had different checksums. The hang on startup occurs when loading the state.auto file but you're right in that replacing the state.auto with a state file works.

We have not seen this particular auto save/load-state issue for any other cores. Do you know if there might be a race condition in flycast somewhere?

flyinghead commented 4 years ago

Flycast savestates are quite big compared to other cores, so that might be reason why this issue only happens for flycast.

There might be something wrong in flycast but it seems the problem is in RetroArch. States are saved by an asynchronous task, and RA doesn't wait for this task to finish before exiting.

ghost commented 4 years ago

I ran a trace using printf and indeed the serialize function does complete - so you may be right in that RA is not serializing it correctly.

flyinghead commented 4 years ago

This should have been fixed in RetroArch: https://github.com/libretro/RetroArch/commit/6083450d4e2c49da74d0c4a4a1a4833a2a6a66fa