Frame rate limit and audio are broken too

BonzaiThePenguin commented 9 years ago

Compared to the version on the Play Store, the latest CI build doesn't cap the framerate properly (it runs about twice as fast, and the frame limit option seems to do nothing) and the audio is a broken mess. What happened?

LG Tribute, quad-core 1.2 GHz, Android 4.4.2.

BonzaiThePenguin commented 9 years ago

It seems to randomly lock up too, where it doesn't crash but stops responding to inputs and prevents the back/home/multitasking buttons from appearing.

AbandonedCart commented 9 years ago

You may want to take a minute and check the currently open issues before adding any more reports. The audio / framerate are being tested now, but the freeze is already listed in https://github.com/reicast/reicast-emulator/issues/521

BonzaiThePenguin commented 9 years ago

Searching for audio and framerate turned up nothing, and I'm supposed to assume that all lockups are identical?

AbandonedCart commented 9 years ago

Audio and framerate are both working fine. The only issue that could be found is when increasing the frameskip, then disabling frame limit, then enabling it again didn't apply until returning to the menu first. If frameskip was untouched, the other options worked flawlessly.

As stated, the audio and framerate was being tested now. You are welcome to assume all lockups are identical, but what was being asked is you try to make sure the issue wasn't reported before making a new one. I am sure you would prefer more time is spent finding a solution than scattered reports.

BonzaiThePenguin commented 9 years ago

I started testing the CI builds to figure out where each of the issues first appeared, and it turns out all of them appeared starting with the 2015-01-06 19:59:52 build. The one right before that, 2015-01-06 14:19:16, works fine.

To reiterate, the main issues that appeared are that the audio stutters and the game almost always locks up within the first few screens – whether the 50/60 Hz screen, the Sega logo, or the save file load screen. The one time I was able to get into gameplay the framelimit did not seem to work, as the game ran way too fast.

BonzaiThePenguin commented 9 years ago

The CDI issue is probably related, as I may have mistakenly assumed the freeze was due to the CDI format rather than the emulator itself. I'll go test the CDI format with the first build from January 6.

BonzaiThePenguin commented 9 years ago

Yep, the .cdi file worked fine in the first build from 1/06/15! So all of the bugs were caused by a change in the second build.

AbandonedCart commented 9 years ago

It sounds like you may need https://github.com/reicast/reicast-emulator/pull/585 The second change is TMU interrupts and the above commit was included in the build I tested.

AbandonedCart commented 9 years ago

If you get a chance, try out the newest build from the loungekatt branch (should be just below the main test builds) and see if the same issues exist. That should determine if the commit I suspect is the one you need.

BonzaiThePenguin commented 9 years ago

Nope, the 1/23 build under LoungeKatt continues to lock up within the first few seconds.

BonzaiThePenguin commented 9 years ago

Your branch has the modified timing interrupt code in it.

AbandonedCart commented 9 years ago

It does. The difference was the commit I was referring to was the only one it didn't have. It verified it wasn't the controller changes that were also on the same day as the break.

AbandonedCart commented 9 years ago

The change was merged. A new build should be available shortly.

skmp commented 9 years ago

So, it looks like 6ad25b8 broke games? (I did do some limited testing and it seemed to work alright)

AbandonedCart commented 9 years ago

I haven't been able to reproduce the issue and only the format has been an issue with anyone else.

AbandonedCart commented 9 years ago

It's possible it's specific to the device. It has a Snapdragon 400, though, so it should be about the same as most mid-range devices from 2013-2014

hooby3dfx commented 9 years ago

Yea there is def something like that in the latest code which leads to a hang after playing for several minutes. It might even be possible to repro by just starting games and letting them sit for ~10 mins. Ill try and get specific tests/timing to repro and then try after reverting tmu. On Jan 28, 2015 11:44 AM, "TwistedUmbrella" notifications@github.com wrote:

It's possible it's specific to the device. It has a Snapdragon 400, though, so it should be about the same as most mid-range devices from 2013-2014

— Reply to this email directly or view it on GitHub https://github.com/reicast/reicast-emulator/issues/594#issuecomment-71868859 .

AbandonedCart commented 9 years ago

There is a freeze after around 15-20 on nvidia (#521) but apparently another freeze somewhat instantly on this. I believe the instant freeze is TMU but the nvidia one was before that. To find the freeze here, you'd have to test with something other than a shield to avoid a false positive.

AbandonedCart commented 9 years ago

What other devices do you guys have handy? On the Note 4, I get the freeze at about 15 but no audio or frame rate issues. I'm going to try a Nexus 5 as well. Preferably, we need something with a similar hardware profile.

BonzaiThePenguin commented 9 years ago

With the latest builds I am unable to use the emulator for more than a few seconds – the game doesn't seem to matter, nor does the format. Well, maybe the games matter, but it just happens to trigger a freeze for Sonic Adventure and Sonic Adventure 2, for the CDI and GDI formats.

Almost every time I am unable to get past the SEGA screen or the 50Hz/60Hz selection screens, and out of the few times it didn't freeze it almost always froze at the save file select screen. One time Sonic Adventure 2 managed to get to actual gameplay, but it froze shortly after running way too fast.

BonzaiThePenguin commented 9 years ago

By emulator I mean once a game is running, I don't mean the Settings screen or anything like that.

BonzaiThePenguin commented 9 years ago

I'll go download the latest build again and make sure it's still happening.

BonzaiThePenguin commented 9 years ago

Yep, it froze right when the Sonic Team logo was about to fade out completely.

BonzaiThePenguin commented 9 years ago

Is there anything I can do to help? I know how to build Reicast and my LG Tribute is set to developer mode, but I'm not at all familiar with how to actually use a debugger or profiler with this – I just manually copy the APK over using the Android File Transfer tool.

BonzaiThePenguin commented 9 years ago

I figured out how to attach the NDK debugger and ran a newly-installed copy of reicast on my phone, and it worked fine until immediately after I tapped on Sonic Adventure 2 in the games list. At that point it returned the following:

[New Thread 9539]

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 9539]
no_update () at jni/../jni/../../../core/rec-ARM/ngen_arm.S:147
147     ldr pc,[r2,r1,lsl #2]
(gdb) list
142 .global no_update
143 no_update:              @ next_pc _MUST_ be on r4 *R4 NOT R0 anymore*
144 
145     sub r2,r8,#33816576
146     ubfx r1,r4,#1,#23
147     ldr pc,[r2,r1,lsl #2]
148 
149     @bic r1,r4,#0xFF000000
150     @ldr pc,[r2,r1,lsl #1]
151

Actually, the emulator seems to be absolutely riddled with SIGSEGV errors.

BonzaiThePenguin commented 9 years ago

The build from 10/22/2014 does not have this issue, although that's probably because the broken interrupt code was available but not used. It does get this segfault, though:

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 15263]
lws_plat_context_late_destroy () at jni/../jni/../../../core/deps/libwebsocket/lws-plat-unix.c:279
279     close(context->dummy_pipe_fds[1]);

If I continue to execute the 10/22 build, it gets a SIGSEGV here:

Program received signal SIGSEGV, Segmentation fault.
fprint_hex(__sFILE*, char const*, unsigned char*, unsigned int&, unsigned int) () at jni/../jni/../../../core/hw/sh4/dyna/blockmanager.cpp:607
607 }

Followed by a ton of SIGSEGV errors due to a null block in print_blocks:

Program received signal SIGSEGV, Segmentation fault.
0x6049b2d4 in print_blocks() () at jni/../jni/../../../core/hw/sh4/dyna/blockmanager.cpp:623
623     for (size_t i=0;i<all_blocks.size();i++)
(gdb) fg
Continuing.

Program received signal SIGSEGV, Segmentation fault.
print_blocks() () at /Users/mikemcfadden/android-ndk-r9c/sources/cxx-stl/stlport/stlport/stl/_vector.h:192
192   size_type size() const        { return size_type(this->_M_finish - this->_M_start); }
(gdb) fg
Continuing.

Program received signal SIGSEGV, Segmentation fault.
print_blocks() () at jni/../jni/../../../core/hw/sh4/dyna/blockmanager.cpp:631
631             fprintf(f,"hash: %s\n",blk->hash());
(gdb) fg
Continuing.

Program received signal SIGSEGV, Segmentation fault.
print_blocks() () at jni/../jni/../../../core/hw/sh4/dyna/blockmanager.cpp:633
633             fprintf(f,"code: %08X\n",blk->code);
(gdb) fg
Continuing.

etc.

BonzaiThePenguin commented 9 years ago

Last update for now, since I'm pretty sure I can't offer any more information. I disabled pausing and printing on SIGSEGV using handle SIGSEGV nostop noprint so the emulator would run again normally, then paused at random points during its execution. I noticed that thread 17 was being used for the emulator core, then waited until the emulator froze and paused it again, and thread 17 turned into __futex_syscall3. Google suggests that call is associated with thread deadlocks, which would explain why the emulation stops working. Also, I should mention that the virtual controller continues to provide haptic feedback, which I guess makes sense since the emulation runs on a separate thread.

(gdb) fg
Continuing.
^C
Program received signal SIGINT, Interrupt.
[Switching to Thread 17965]
0x4005cec8 in epoll_wait () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
(gdb) info threads
  Id   Target Id         Frame 
  22   Thread 18147      0x4005bd14 in __ioctl () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  21   Thread 18127      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  20   Thread 18117      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  19   Thread 18106      0x4005bd14 in __ioctl () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  18   Thread 18105      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  17   Thread 18104      0x605eb140 in SH4_TCB () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libdc.so
  16   Thread 18103      0x40049894 in ?? () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  15   Thread 18099      0x4005cf4c in poll () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  14   Thread 18064      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  13   Thread 17991      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  12   Thread 17990      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  11   Thread 17989      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  10   Thread 17977      0x4005bd14 in __ioctl () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  9    Thread 17976      0x4005bd14 in __ioctl () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  8    Thread 17975      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  7    Thread 17974      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  6    Thread 17973      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  5    Thread 17972      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  4    Thread 17971      0x4005cb64 in recvmsg () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  3    Thread 17970      0x4005c8fc in __rt_sigtimedwait () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  2    Thread 17969      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
* 1    Thread 17965      0x4005cec8 in epoll_wait () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
(gdb) thread 17
[Switching to thread 17 (Thread 18104)]
#0  0x605eb140 in SH4_TCB () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libdc.so
(gdb) info stack
#0  0x605eb140 in SH4_TCB () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libdc.so
#1  0x605eacd0 in SH4_TCB () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libdc.so
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
(gdb) fg
Continuing.
^C
Program received signal SIGINT, Interrupt.
[Switching to Thread 17965]
0x4005cec8 in epoll_wait () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
(gdb) info threads
  Id   Target Id         Frame 
  22   Thread 18147      0x4005bd14 in __ioctl () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  21   Thread 18127      0x4005bd14 in __ioctl () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  20   Thread 18117      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  19   Thread 18106      0x4005bd14 in __ioctl () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  18   Thread 18105      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  17   Thread 18104      0x6053d8d4 in _vmem_ReadMem8SX32(unsigned int) () at jni/../jni/../../../core/hw/mem/_vmem.cpp:167
  16   Thread 18103      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  15   Thread 18099      0x4005cf4c in poll () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  14   Thread 18064      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  13   Thread 17991      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  12   Thread 17990      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  11   Thread 17989      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  10   Thread 17977      0x4005bd14 in __ioctl () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  9    Thread 17976      0x4005bd14 in __ioctl () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  8    Thread 17975      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  7    Thread 17974      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  6    Thread 17973      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  5    Thread 17972      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  4    Thread 17971      0x4005cb64 in recvmsg () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  3    Thread 17970      0x4005c8fc in __rt_sigtimedwait () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  2    Thread 17969      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
* 1    Thread 17965      0x4005cec8 in epoll_wait () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
(gdb) fg
Continuing.
^C
Program received signal SIGINT, Interrupt.
0x4005cec8 in epoll_wait () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
(gdb) info threads
  Id   Target Id         Frame 
  22   Thread 18147      0x4005bd14 in __ioctl () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  21   Thread 18127      0x4005bd14 in __ioctl () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  20   Thread 18117      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  19   Thread 18106      0x4005bd14 in __ioctl () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  18   Thread 18105      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  17   Thread 18104      sh4_sched_now() () at jni/../jni/../../../core/hw/sh4/sh4_sched.cpp:94
  16   Thread 18103      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  15   Thread 18099      0x4005cf4c in poll () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  14   Thread 18064      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  13   Thread 17991      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  12   Thread 17990      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  11   Thread 17989      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  10   Thread 17977      0x4005bd14 in __ioctl () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  9    Thread 17976      0x4005bd14 in __ioctl () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  8    Thread 17975      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  7    Thread 17974      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  6    Thread 17973      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  5    Thread 17972      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  4    Thread 17971      0x4005cb64 in recvmsg () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  3    Thread 17970      0x4005c8fc in __rt_sigtimedwait () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  2    Thread 17969      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
* 1    Thread 17965      0x4005cec8 in epoll_wait () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
(gdb) thread 17
[Switching to thread 17 (Thread 18104)]
#0  sh4_sched_now() () at jni/../jni/../../../core/hw/sh4/sh4_sched.cpp:94
94      return sh4_sched_ffb-Sh4cntx.sh4_sched_next;
(gdb) backtrace
#0  sh4_sched_now() () at jni/../jni/../../../core/hw/sh4/sh4_sched.cpp:94
#1  0x60550f54 in sh4_sched_remaining(int) () at jni/../jni/../../../core/hw/sh4/sh4_sched.cpp:43
#2  0x60550fbc in sh4_sched_ffts() () at jni/../jni/../../../core/hw/sh4/sh4_sched.cpp:58
#3  0x60552fc4 in UpdateSystem () at jni/../jni/../../../core/hw/sh4/interpr/sh4_interpreter.cpp:210
#4  0x60de2ec4 in intc_sched () at jni/../jni/../../../core/rec-ARM/ngen_arm.S:132
#5  0x60de2ec4 in intc_sched () at jni/../jni/../../../core/rec-ARM/ngen_arm.S:132
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
(gdb) fg
Continuing.
^C
Program received signal SIGINT, Interrupt.
[Switching to Thread 17965]
0x4005cec8 in epoll_wait () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
(gdb) info threads
  Id   Target Id         Frame 
  22   Thread 18147      0x4005bd14 in __ioctl () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  21   Thread 18127      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  20   Thread 18117      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  19   Thread 18106      0x4005bd14 in __ioctl () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  18   Thread 18105      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  17   Thread 18104      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  16   Thread 18103      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  15   Thread 18099      0x4005cf4c in poll () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  14   Thread 18064      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  13   Thread 17991      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  12   Thread 17990      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  11   Thread 17989      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  10   Thread 17977      0x4005bd14 in __ioctl () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  9    Thread 17976      0x4005bd14 in __ioctl () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  8    Thread 17975      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  7    Thread 17974      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  6    Thread 17973      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  5    Thread 17972      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  4    Thread 17971      0x4005cb64 in recvmsg () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  3    Thread 17970      0x4005c8fc in __rt_sigtimedwait () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
  2    Thread 17969      0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
* 1    Thread 17965      0x4005cec8 in epoll_wait () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so

Lastly, while I was running the debugger I managed to get to gameplay for the second time in hundreds of attempts, so I quickly opened Photo Booth and recorded the following video:

http://ivideoapp.com/random/reicast_issues.mov

Notice the game is running way too fast, the audio is incredibly choppy, and that when I tried to get a closeup of the in-game clock running fast the game froze.

AbandonedCart commented 9 years ago

The game runs too fast when audio is broken. Audio is what limits the emulator thread. Turbo uses that to stop the audio thread in order to send the emulator into what looks like fast forward. The troubling part is that the same errors you are getting, I am unable to reproduce. Hopefully @skmp or @hooby3dfx will be able to duplicate them. I'm beginning to think it may be a hardware driver issue with something that was updated but doesn't have the reflection needed.

BonzaiThePenguin commented 9 years ago

Well, the point was that Reicast is constantly reading from and writing to out of bounds memory addresses, and capturing the SIGSEGV signals to continue operating as if nothing is wrong. To emphasize, that is horrifically bad. It can end up clobbering any arbitrary value within the program's address space, with the exact effects depending on what was being stored in that section of memory. That will ultimately depend on the specific device.

BonzaiThePenguin commented 9 years ago

It was also shown to likely be a thread deadlocking problem, which are notorious for being hard to reproduce due to the precise timing mechanisms involved. Haven't seen any evidence of anything being caused by a driver issue, just classic threading and OOB memory issues.

skmp commented 9 years ago

Handling SIGSEGVs is a core feature/flow on reicast -- they are used to optimize various things around the core. None of these are out of bounds accesses, it's just one of the many optimizations the core does. They are used to track texture updates, code updates, fast-path code re-write, and some other parts as well.

From what I see I'd say it is an audio issue. What happens is something goes wrong on the audio sync code, which then leads to a deadlock on the "wait for audio to sync" logic. Can you try turning off the speed limiter and see if the lockups go away?

On Thu, Jan 29, 2015 at 4:46 PM, Mike McFadden notifications@github.com wrote:

It was also shown to likely be a thread deadlocking problem, which are notorious for being hard to reproduce due to the precise timing mechanisms involved. Haven't seen any evidence of anything being caused by a driver issue, just classic threading and OOB memory issues.

— Reply to this email directly or view it on GitHub https://github.com/reicast/reicast-emulator/issues/594#issuecomment-72046813 .

~skmp

skmp commented 9 years ago

Also, for the sigsegvs, there's logic in there that only handles the sigsegvs that are generated on purpose. For sigsegvs of unknown sources reicast fwds them to the OS (and this leads to a crash/log).

You can see the relevant sigsegv magic at https://github.com/reicast/reicast-emulator/blob/master/core/linux/common.cpp#L59, VramLockedWrite, BM_LockedWrite, as well as ngen_readm_fail_v2.

skmp commented 9 years ago

Also note, reicast does all kind of interesting things with the stack, so any stack traces that start with SH4_TCB, or any traces after SH4_TCB (or ARM7_TCB) should be considered invalid.

AbandonedCart commented 9 years ago

Audio driver errors are not going to be in the reicast or logcat logs. They would be printed to the last_kmsg with any other hardware driver faults that may or may not be present. It may help to either look over or even post that log to verify. Some audio issues have broken apps or even caused reboots and show no signs in the system.

BonzaiThePenguin commented 9 years ago

I suspected some of the SIGSEGVs were being captured intentionally as part of the dynarec or whatever, but hadn't considered that some of them were being generated intentionally too. Interesting.

The frame limiter doesn't seem to have any effect – it still freezes, and the framerate was too fast to begin with so turning it off just continued that – and turning off audio emulation also did not prevent it from freezing. I'll start throwing printfs in the lock/unlock sections to see if I can capture the deadlock.

BonzaiThePenguin commented 9 years ago

For some reason it didn't occur to me to run a stack trace when the emulator thread is stuck in a deadlock! Here it is:

(gdb) thread 18
[Switching to thread 18 (Thread 20645)]
#0  0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
(gdb) info stack
#0  0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
#1  0x4004a128 in __pthread_cond_timedwait_relative () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
#2  0x4004a188 in __pthread_cond_timedwait () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so
#3  0x60562fa0 in cResetEvent::Wait() () at jni/../jni/../../../core/linux/common.cpp:157
#4  0x60542a48 in rend_end_sch(int, int, int) () at jni/../jni/../../../core/hw/pvr/spg.cpp:238
#5  0x60551638 in handle_cb(int) () at jni/../jni/../../../core/hw/sh4/sh4_sched.cpp:133
#6  0x60551710 in sh4_sched_tick(int) () at jni/../jni/../../../core/hw/sh4/sh4_sched.cpp:155
#7  0x60553390 in UpdateSystem () at jni/../jni/../../../core/hw/sh4/interpr/sh4_interpreter.cpp:210
#8  0x60de37c4 in intc_sched () at jni/../jni/../../../core/rec-ARM/ngen_arm.S:132
#9  0x60de37c4 in intc_sched () at jni/../jni/../../../core/rec-ARM/ngen_arm.S:132

skmp commented 9 years ago

OOOhhh, it's waiting for a render. Hum, interesting. That means the render never gets scheduled.

On Fri, Jan 30, 2015 at 5:31 AM, Mike McFadden notifications@github.com wrote:

For some reason it didn't occur to me to run a stack trace when the emulator thread is stuck in a deadlock! Here it is:

(gdb) thread 18 [Switching to thread 18 (Thread 20645)]

0 0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so

(gdb) info stack

0 0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so

1 0x4004a128 in __pthread_cond_timedwait_relative () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so

2 0x4004a188 in __pthread_cond_timedwait () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so

3 0x60562fa0 in cResetEvent::Wait() () at jni/../jni/../../../core/linux/common.cpp:157

4 0x60542a48 in rend_end_sch(int, int, int) () at jni/../jni/../../../core/hw/pvr/spg.cpp:238

5 0x60551638 in handle_cb(int) () at jni/../jni/../../../core/hw/sh4/sh4_sched.cpp:133

6 0x60551710 in sh4_sched_tick(int) () at jni/../jni/../../../core/hw/sh4/sh4_sched.cpp:155

7 0x60553390 in UpdateSystem () at jni/../jni/../../../core/hw/sh4/interpr/sh4_interpreter.cpp:210

8 0x60de37c4 in intc_sched () at jni/../jni/../../../core/rec-ARM/ngen_arm.S:132

9 0x60de37c4 in intc_sched () at jni/../jni/../../../core/rec-ARM/ngen_arm.S:132

— Reply to this email directly or view it on GitHub https://github.com/reicast/reicast-emulator/issues/594#issuecomment-72152810 .

~skmp

skmp commented 9 years ago

Will take a look as soon as possible, working with a new client the past weeks and I've been quite busy..

On Mon, Feb 2, 2015 at 8:55 PM, skmp skmp@emudev.org wrote:

OOOhhh, it's waiting for a render. Hum, interesting. That means the render never gets scheduled.

On Fri, Jan 30, 2015 at 5:31 AM, Mike McFadden notifications@github.com wrote:

For some reason it didn't occur to me to run a stack trace when the emulator thread is stuck in a deadlock! Here it is:

(gdb) thread 18 [Switching to thread 18 (Thread 20645)]

0 0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so

(gdb) info stack

0 0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so

1 0x4004a128 in __pthread_cond_timedwait_relative () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so

2 0x4004a188 in __pthread_cond_timedwait () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so

3 0x60562fa0 in cResetEvent::Wait() () at jni/../jni/../../../core/linux/common.cpp:157

4 0x60542a48 in rend_end_sch(int, int, int) () at jni/../jni/../../../core/hw/pvr/spg.cpp:238

5 0x60551638 in handle_cb(int) () at jni/../jni/../../../core/hw/sh4/sh4_sched.cpp:133

6 0x60551710 in sh4_sched_tick(int) () at jni/../jni/../../../core/hw/sh4/sh4_sched.cpp:155

7 0x60553390 in UpdateSystem () at jni/../jni/../../../core/hw/sh4/interpr/sh4_interpreter.cpp:210

8 0x60de37c4 in intc_sched () at jni/../jni/../../../core/rec-ARM/ngen_arm.S:132

9 0x60de37c4 in intc_sched () at jni/../jni/../../../core/rec-ARM/ngen_arm.S:132

— Reply to this email directly or view it on GitHub https://github.com/reicast/reicast-emulator/issues/594#issuecomment-72152810 .

~skmp

~skmp

hooby3dfx commented 9 years ago

@BonzaiThePenguin can i enlist your help with figuring out some of the revs where these shananigans started? my plan is to grab a build from http://builds.reicast.com/ from back in late 2014 to see if sonic 2 crashes after a few minutes and then work my way forwards. goal is to find the last version where it was stable so we can determine what is causing the stability issues. can you try the same approach?

BonzaiThePenguin commented 9 years ago

Absolutely, I'd be glad to help. I wish I still had my list around from a while ago, I already tested them! I don't remember all of the results so I'll have to test again, but I remember builds from November-December caused the analog stick to get stuck, then for a while in December it started printing out OpenGL error messages as toast notifications, then in January it started locking up. I think I'm using a build of Reicast from October as that was the last usable version on my device.

Did you guys ever figure out whether there were legitimate bugs with out-of-bounds memory accesses that could be causing it? I get that the emulator relies on segfaults as part of its normal operation, but with a cursory glance there seemed to be some real areas where it attempted to clobber memory addresses unintentionally. And those are only the ones that were so far out of bounds that it raised the segfault. Seems like it might be worth doing a pass-through of the code.

BonzaiThePenguin commented 9 years ago

Actually, wait, I already figured this one out at the top of this thread:

I started testing the CI builds to figure out where each of the issues first appeared, and it turns out all of them appeared starting with the 2015-01-06 19:59:52 build. The one right before that, 2015-01-06 14:19:16, works fine.

To reiterate, the main issues that appeared are that the audio stutters and the game almost always locks up within the first few screens – whether the 50/60 Hz screen, the Sega logo, or the save file load screen. The one time I was able to get into gameplay the framelimit did not seem to work, as the game ran way too fast.

hooby3dfx commented 9 years ago

Derp, thanks!! I will confirm later if this matches the introduction of some other issues. On Mar 31, 2015 1:46 PM, "Mike McFadden" notifications@github.com wrote:

Actually, wait, I already figured this one out at the top of this thread:

I started testing the CI builds to figure out where each of the issues first appeared, and it turns out all of them appeared starting with the 2015-01-06 19:59:52 build. The one right before that, 2015-01-06 14:19:16, works fine.

To reiterate, the main issues that appeared are that the audio stutters and the game almost always locks up within the first few screens – whether the 50/60 Hz screen, the Sega logo, or the save file load screen. The one time I was able to get into gameplay the framelimit did not seem to work, as the game ran way too fast.

— Reply to this email directly or view it on GitHub https://github.com/reicast/reicast-emulator/issues/594#issuecomment-88185264 .

skmp commented 9 years ago

This should be now fixed. Check w/ http://reicast-builds.s3.amazonaws.com/builds/heads/master-c25ce04/reicast-android-debug-c25ce04.apk

(Was a bug on the scheduling system double firing expired events)

BonzaiThePenguin commented 9 years ago

Trying it out now!

BonzaiThePenguin commented 9 years ago

Unfortunately I can't get far enough to test, since the file browser crashes in TimSort when I attempt to browse to the root of my device (/storage) where external_SD and emulated are.

java.util.TimSort.sort(TimSort.java:169)
java.util.Arrays.sort(Arrays.java:2023)
com.reicast.emulator.FileBrowser.navigate(FileBrowser.java:462)
com.reicast.emulator.FileBrowser$5.onClick(FileBrowser.java:494)
android.view.View.performClick(View.java:4461)
...

Actually come to think of it, my ROM is stored in emulated/0 so I guess I don't need to browse all the way to the root. Still needs to be fixed tho!

BonzaiThePenguin commented 9 years ago

For some reason it requires me to select a folder within /data/media/0? Never heard of that path before. It defaults to /data/media/0/Android/data/com.ooi.android.smb2 and crashes when I get to /data.

BonzaiThePenguin commented 9 years ago

Alright I manually typed the paths to the ROM and games directory to get it working. The game still runs way too fast with stuttering audio. It hasn't locked up yet though.

BonzaiThePenguin commented 9 years ago

Yep, relaunched a few more times to confirm. The freezing issue seems to be resolved!

Since it isn't locking up constantly, I can provide a bit more info about the speed issues. This all applies to Sonic Adventure 2:

all of the 2D menus seem to work perfectly – the sound is fine and the speed is fine
the 3D Sonic Adventure 2 logo that shows up before the main menu seems to work fine too
as soon as I enter any 3D level the game starts to run way too fast and the audio stutters. This affected levels that used to display toast messages about OpenGL errors (mainly levels with Tails) and levels that used to work perfectly (Chao Garden with Sonic).
if I wait at the "press start" screen for the demo to play, that runs way too fast also.

BonzaiThePenguin commented 9 years ago

BTW I'm available if you want to run a ton of debug builds to see if anything works. Heck if there was some way of just granting access to my phone over the Internet so you could debug directly on it I'd set that up, but running a ton of debug builds seems like the next best thing.

skmp commented 9 years ago

I've isolated the issue on the tmu overflow handler. It triggers a known edge case that I was lazy to care about (there's even a comment about it) and I figured no game would trigger.... -.-

skmp / reicast-emulator

Frame rate limit and audio are broken too #594

0 0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so

0 0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so

1 0x4004a128 in __pthread_cond_timedwait_relative () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so

2 0x4004a188 in __pthread_cond_timedwait () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so

3 0x60562fa0 in cResetEvent::Wait() () at jni/../jni/../../../core/linux/common.cpp:157

4 0x60542a48 in rend_end_sch(int, int, int) () at jni/../jni/../../../core/hw/pvr/spg.cpp:238

5 0x60551638 in handle_cb(int) () at jni/../jni/../../../core/hw/sh4/sh4_sched.cpp:133

6 0x60551710 in sh4_sched_tick(int) () at jni/../jni/../../../core/hw/sh4/sh4_sched.cpp:155

7 0x60553390 in UpdateSystem () at jni/../jni/../../../core/hw/sh4/interpr/sh4_interpreter.cpp:210

8 0x60de37c4 in intc_sched () at jni/../jni/../../../core/rec-ARM/ngen_arm.S:132

9 0x60de37c4 in intc_sched () at jni/../jni/../../../core/rec-ARM/ngen_arm.S:132

0 0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so

0 0x4005d090 in __futex_syscall3 () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so

1 0x4004a128 in __pthread_cond_timedwait_relative () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so

2 0x4004a188 in __pthread_cond_timedwait () from /Users/mikemcfadden/Desktop/reicast-emulator/shell/android/obj/local/armeabi-v7a/libc.so

3 0x60562fa0 in cResetEvent::Wait() () at jni/../jni/../../../core/linux/common.cpp:157

4 0x60542a48 in rend_end_sch(int, int, int) () at jni/../jni/../../../core/hw/pvr/spg.cpp:238

5 0x60551638 in handle_cb(int) () at jni/../jni/../../../core/hw/sh4/sh4_sched.cpp:133

6 0x60551710 in sh4_sched_tick(int) () at jni/../jni/../../../core/hw/sh4/sh4_sched.cpp:155

7 0x60553390 in UpdateSystem () at jni/../jni/../../../core/hw/sh4/interpr/sh4_interpreter.cpp:210

8 0x60de37c4 in intc_sched () at jni/../jni/../../../core/rec-ARM/ngen_arm.S:132

9 0x60de37c4 in intc_sched () at jni/../jni/../../../core/rec-ARM/ngen_arm.S:132