(High Sierra) openemu freezes

[pabloxm]

openemu 2.0.5 on macOS high Sierra gets freeze after some minutes and obviously I can't play

[clobber]

You've provided no details to go on here.

[Zander90]

I faced the same issue as well while using openemu 2.0.5 on High Sierra

I have played both GBA games and PS games on Openemu and it will freeze after a while. Quitting the application or stopping the emulation doesn't work. I would have to force quit it from Activity Monitor.

I have attached my console log to see if that can helps to solve the problem.
Openemu Console Log.txt

[clobber]

Looking at your log:

kernel Sandbox: mdworker(742) deny(1) file-read-data /Users/zander/Library/Application Support/OpenEmu/Save States/GameBoy Advance/2689 - Final Fantasy VI Advance (U)(Xenophobia)/Quick Save State.oesavestate

I'd blame High Sierra and/or APFS at this point. For now try updating to 10.13.1 to see if that fixes any problems. High Sierra was initially a very rough upgrade.

[mrvacbob]

Actually, I think this is worth looking at.

If you see this again, can you open Utilities > Activity Monitor, then select OpenEmu, then select (gear menu) > Spindump, and link that output here? (Note, it will show the name of every app you have running.)

[shysaur]

I've been experiencing this problem as well, and I've tried to investigate it, with mixed success. It seems that under High Sierra, the pipe set up by OpenEmu to monitor the stdout of the XPC helper gets closed for some reason after some amount of time, like if there was an inactivity timeout on it. The OEXPCGameCoreManager method _didReceiveData: sees a zero-length NSData and kills the helper process, which causes the freeze. Even if OpenEmu did not kill the helper, it would die anyway because it would receive a SIGPIPE.

No spindump or sample would find this, and no crash logs are generated, as the closure of the process is a one-time event that lets the process exit cleanly via a simple SIGTERM. This does not even generate a NSTask termination notification, as the notifications are disabled before OEXPCGameCoreManager terminates the XPC helper. After the helper process is closed, the app is just stuck waiting for an event that never arrives as the rest of the UI code still thinks that the XPC helper is up and running.

Obviously this pipe should not get closed without any reason; but it seems that it's some external factor that closes it. I tried to hook the close() syscall with dtrace but it seems that neither the helper process nor the OpenEmu process calls it to close the pipe; which is absurd, somebody must be closing this damn pipe. It might be a bug in the kernel, or I've just missed something and it's just a bug in AppKit or OpenEmu, who knows. At the moment I don't think it is a bug in OpenEmu, but I can't tell for certain.

One "throw hacks at the wall and see what sticks" option to try to fix the bug would be to use a manually created named pipe instead than NSPipe, or just redirect the XPC helper stdout/stderr to /dev/null (as at the moment the output from the xpc helper is thrown away by default anyway).

The short-term workaround is to use the secret preferences to run the game in a background thread instead than in an XPC process.

[shysaur]

@pabloxm @Zander90 to fix your problem, at least for the immediate future, try these steps:

1. unlock the secret preferences by following the instructions at https://github.com/OpenEmu/OpenEmu/wiki/User-guide:-Preferences:-Secrets
2. open the secret preferences and select "background thread" instead of "XPC" for the option "Run games using:"

Remember that this configuration is unsupported and can cause more frequent crashes of the app, but for the most popular cores you should be fine. As long as you are using this option, refrain from posting crash issues here. As soon as a version of OpenEmu that fixes your problem is released, remember to open the secret preferences again and switch back to XPC.

If your problem is still not solved by changing your configuration in this way, please tell us. Also, remember to include in your issue the macOS version and the hardware info!!! Saying just "High Sierra" is not enough; saying "macOS 10.13.1 (17B48) on a MacBook Pro, 13-inch, Mid 2010 with 4 GB of RAM" is. Open About This Mac from the Apple menu to get this info and post it here.

[clobber]

@shysaur No no, I really wouldn't recommend background thread as a workaround - we only use that for debugging and there are some cases where battery saves break and other issues with cores that won't launch a second time because they are not reentrant.

One "throw hacks at the wall and see what sticks" option to try to fix the bug would be to use a manually created named pipe instead than NSPipe, or just redirect the XPC helper stdout/stderr to /dev/null (as at the moment the output from the xpc helper is thrown away by default anyway).

Thanks for digging into this. If you are still debugging and want to give that a shot, please go for it. I have not been able to replicate this so far but maybe I'm just not playing long enough.

[clobber]

I was able to replicate this behavior.

Using the mGBA core plugin (note: VisualBoyAdvance is deprecated and has been removed from next release), I left "Pac-Man Collection (USA)" running overnight for 8 hours. At some point it froze.

Spindump: Spindump.txt

[shysaur]

I imagined there would be some problems with background threads but I did not imagine they were this severe.

Your spindump is consistent with what I'm seeing on my end.

I usually use SNES9x (1.54.1.1) to replicate, as downloaded from the official core update site by OpenEmu itself. The game seems to not matter, I've reproduced the issue with patched Seiken Densetsu 3, Fire Emblem Thracia 776, patched Fire Emblem Mystery of the Emblem, Fire Emblem Genealogy of the Holy War, and Super Mario World. The time it takes can vary wildly but it usually takes less than an hour.

System load seems to not be a factor; today with an otherwise idle machine I got a hang in no more or less time than yesterday with a fully loaded machine (Xcode really likes indexing) and a debugger attached.

I never bothered to try to reproduce it with other cores. It can even happen while the emulation is paused. Initially I thought the issue was easier to reproduce by fast forwarding but it doesn't seem to be the case.

[mrvacbob]

Yes, unfortunately background threads are only designed as a debugging tool. Most of the cores don't clean up after they're stopped, since quitting the helper takes care of that, so they can only load one game.

[clobber]

The time it takes can vary wildly but it usually takes less than an hour.

So far it takes me several hours to replicate this. Today I let OpenEmu run on my machine since noon. I'd let the app sit in background, sometimes minimized, sometimes I'd play the game that I kept running. It took over 11 hours for the helper app to get killed, which happened right in front of me as I came back to my machine and moved the mouse around on screen making the HUD bar appear, at around 11:18 PM after running all day since noon. The only thing I found in Console:

...
default 21:16:49.959531 -0600 OpenEmuHelperApp HALC_ProxyIOContext.cpp:1068:IOWorkLoop: HALC_ProxyIOContext::IOWorkLoop: skipping cycle due to overload
default 21:16:49.971482 -0600 OpenEmuHelperApp HALC_ProxyIOContext.cpp:1068:IOWorkLoop: HALC_ProxyIOContext::IOWorkLoop: skipping cycle due to overload
default 21:16:49.993022 -0600 OpenEmuHelperApp HALB_MachPort.cpp:277:SendMessage: HALB_MachPort::SendMessage: mach_msg() returned error 0x10000003: '(ipc/send) invalid destination port'
error 21:16:49.993057 -0600 OpenEmuHelperApp HALC_ProxyIOContext.cpp:1399:IOWorkLoop: HALC_ProxyIOContext::IOWorkLoop: failed to send the final message to the server, Error: 0x10000003
default 21:16:50.786184 -0600 OpenEmuHelperApp HALC_ProxyIOContext.cpp:1068:IOWorkLoop: HALC_ProxyIOContext::IOWorkLoop: skipping cycle due to overload
default 23:17:58.141173 -0600 kernel AGC:: [OpenEmuHelperApp pid 61003 mux-aware] exiting, non-mux-aware app count 0, runtime: 11:22:45.096

Visual proof:
https://i.imgur.com/2JSADjK.png

Console log after running all day:
openemu-nov10-console.txt

Spindump:
Spindump2.txt

[clobber]

Worth noting that it seems to be easier, or perhaps possible, to trigger the helper process getting killed by moving the mouse around over and over to make the HUD bar appear/disappear. I was just able to do this after letting a game run for 10 minutes and when I came back I started moving the mouse around. Maybe something to it.

[robotoad]

I can replicate an immediate pausing of emulation when running the mGBA core by clicking menu items in the application menu or HUD. In Pac-Man Collection, the pause is immediate. In Metroid Fusion, the game runs for a second or two before pausing. Other cores I tried don't pause when interacting with menus.

It's as of yet unclear if this pause is related to the long-term pause described here, which I so far can't replicate. My hardware is an early 2013 MacBook Pro with an Intel HD Graphics 4000/GeForce GT 650M. Tonight, I'll run OpenEmu overnight again to see if I can replicate the long-term pause.

Edit: I've run Pac-Man Collection in mGBA overnight twice now and experienced no freeze.

[shysaur]

Well I've found out why I could reproduce this bug that easily; I was using a version of OpenEmu built from master instead than the latest official release. The reason why I was using a version of OpenEmu built from source is rather convoluted. The latest official release did not freeze in 5 hours but a release build from master did in few minutes.

Even then, it's not like there were any changes to how the helper process works from the last release...
I'm even more puzzled, especially since the OP doesn't seem like the typical user that would build from source.

[By the way, the kernel Sandbox: mdworker(742) deny(1) file-read-data /Users/zander/Library/Application Support/OpenEmu/Save States/GameBoy Advance/2689 - Final Fantasy VI Advance (U)(Xenophobia)/Quick Save State.oesavestate line @clobber found in the log is completely normal; I've been seeing those since the Mountain Lion era.]

I don't know if the problem faced by Zander90 is the same problem I am seeing, as in his log there is no "Did stop background process." message as I would expect.

[clobber]

I think you're doing it right. I've run all my tests with builds from master where it has mostly taken several hours to replicate a crash. I feel there is something with the mouse and HUD bar where you might be able to trigger it faster, at least from what I've experienced a few times.

"Did stop background process." should only appear when using a debug build, because DLog() prints it.

[clobber]

Also just thought of maybe there is some deprecated API causing this, since we are now linking against the 10.13 SDK.

[shysaur]

"Did stop background process." should only appear when using a debug build, because DLog() prints it.

Oh right I forgot about that.

Also just thought of maybe there is some deprecated API causing this, since we are now linking against the 10.13 SDK.

I'm also thinking of something similar. Or even a behaviour change in a non-deprecated API triggered by linking to the new SDK.

[doktordom]

Hey I'm getting this exact issue on my machine playing GBA advance wars. It is very replicable and occurs after a few minutes of playing. I happened once when I moved the mouse and the UI appeared. The game crashed and then I was unable to do anything with openemu other than force quit. Other times it happened with no input from me, it just spontaneously hangs.

I'm running High Sierra 10.13.1 on a 11-inch macbook air, mid 2012, 8 GB ram and Intel HD graphics 4000.

Let me know if you would like more info.

[clobber]

@doktordom This issue is closed and the bug has been fixed for next release.