macOS: Crash when unplugging headphones

FMOD Engine
,
#1

Hi everyone,

my game (with custom engine) uses the fmod library (v2.02.07) for audio output. Few problems so far which is great!

However, when I unplug my headphones (connected via headphone jack, not USB or bluetooth) during gameplay on macOS, my app crashes with the following console output:

HAL_HardwarePlugIn_DeviceStart: no device
HALPlugIn::StopIOProc: got an error from the plug-in routine, Error: 560947818 (!obj)

Now, I am not sure if fmod is to blame here or some underlying macOS API but the problem is strictly reproducible and only occurs when unplugging the headphones from my machine, not when plugging it in during gameplay.

Any guesses about the potential root cause?

Thanks!
Thomas

#2

Hi,

Do you have any FMOD logs that we could have a look at? If not, you can enable FMOD Logging by including the fmodL.dll and the fmodL_vc.lib. Included in the FMOD Engine directory under FMOD Studio API Windows/api/core/lib/x(the system you are using). Including those in your project, you will then need to initialize the debug system. You will call FMOD_Debug_Initialize(FMOD_DEBUG_LEVEL_LOG, FMOD_DEBUG_MODE_FILE, 0, "FILE NAME"). This will output all FMOD calls to a log file. If you could upload that log file it will help resolve the issue.

#3

Hi Connor,

thanks for getting back to me. I did what you suggested and got the following log:

[LOG] SystemI::init : Initialize version=20207 (125130), maxchannels=32, flags=0x00000000
[LOG] SystemI::setOutputInternal : Setting output to ‘FMOD Core Audio Output’
[LOG] OutputCoreAudio::init : Output running 2 channels at 44100Hz sample rate.
[LOG] OutputCoreAudio::init : Maximum hardware read size: 512 samples, Software buffer size: 512 samples, Number of software buffers: 4.
[LOG] SystemI::init : Output requires a sample rate of 44100Hz, resampling will occur.
[LOG] Thread::initThread : Init FMOD stream thread. Affinity: 0x4000000000000003, Priority: 0xFFFF7FFB, Stack Size: 98304, Semaphore: No, Sleep Time: 10, Looping: Yes.
[LOG] Thread::initThread : Init FMOD mixer thread. Affinity: 0x4000000000000001, Priority: 0xFFFF7FFA, Stack Size: 81920, Semaphore: Yes, Sleep Time: 0, Looping: Yes.
[LOG] SystemI::createSoundInternal : Create name=‘assets/sounds/hit-a.mp3’, mode=0x00000200
[LOG] SystemI::DSPCodecPoolRegister : register codec pool for pool type 3
[LOG] SystemI::createSoundInternal : Sample 0/0: name=‘(null)’, format=2, channels=2, frequency=48000, lengthbytes=8976, lengthpcm=41472, pcmblocksize=1152, loopstart=0, loopend=0, mode=0x00000000, channelmask=0x00000000, channelorder=0, peakvolume=0.000000.
[LOG] SystemI::createSoundInternal : Create name=‘assets/tracks/corelli-op6-no12/corelli-op6-no12.ogg’, mode=0x00000080
[LOG] SystemI::createSoundInternal : Stream: name=‘(null)’, format=2, channels=2, frequency=44100, lengthbytes=3331708, lengthpcm=5340613, pcmblocksize=0, loopstart=0, loopend=0, mode=0x00000000, channelmask=0x00000000, channelorder=0, peakvolume=0.000000.
[LOG] Thread::initThread : Init FMOD file thread. Affinity: 0x4000000000000003, Priority: 0xFFFF7FFC, Stack Size: 65536, Semaphore: No, Sleep Time: 10, Looping: Yes.

I guess it doesn’t show anything unusual (the crash did happen but did not produce any visible FMOD log output) so I suspect the issue is outside of FMOD? I can also not reproduce the problem on Windows.

Best regards

Thomas

#4

Thanks for sharing the log, I cannot see anything in there to indicate this failure is coming from FMOD.
It might be worth seeing if you still get the crash after disabling the default device switching behaviour. You can do this by setting an FMOD_SYSTEM_CALLBACK on FMOD_SYSTEM_CALLBACK_DEVICELISTCHANGED or FMOD_SYSTEM_CALLBACK_ALL and just returning FMOD_OK, e.g

FMOD_RESULT F_CALLBACK DeviceListChangedCallback(FMOD_SYSTEM *system, FMOD_SYSTEM_CALLBACK_TYPE type, void *commanddata1, void *commanddata2, void *userdata)
{
    return FMOD_OK;
}

int main()
{
    FMOD::System *system = 0;
    FMOD_RESULT result = FMOD::System_Create(&system);
    result = system->init(100, FMOD_INIT_NORMAL, 0);
    system->setCallback(&DeviceListChangedCallback, FMOD_SYSTEM_CALLBACK_DEVICELISTCHANGED);
    ...
}

Please give that a shot and let me know the outcome. If it doesn’t crash then you might be able to implement your own switching behaviour inside that callback to workaround the issue. Otherwise I have not been able to reproduce this- are you on the latest MacOS?

#5

Thanks Jeff for the hints. I tried what you suggested. The crash still happens and the FMOD log output stays the same. What I do get is a slightly different general output:

AudioObjectGetPropertyData: no object with given ID 78
AudioObjectRemovePropertyListener: no object with given ID 78

Interestingly, when the crash happens, the stack is (reproducibly) residing in my Metal backend code which I find somewhat curious.

Best regards,
Thomas

#6

Thanks for giving that a shot- is there anything FMOD related in the callstack, and have you seen if this issue reproduces in the FMOD examples that ship with the API?

#7

I tried to reproduce the problem using the play_sound Xcode example that comes with the FMOD engine download. While the example doesn’t crash when I remove my headphone from the headphone jack while its running, I do get a somewhat interesting log output:

2022-08-10 14:07:14.122169+0200 play_sound[4316:32249] SecTaskLoadEntitlements failed error=22 cs_flags=20, pid=4316
2022-08-10 14:07:14.122335+0200 play_sound[4316:32249] SecTaskCopyDebugDescription: play_sound[4316]/0#-1 LF=0
[LOG] SystemI::init : Initialize version=20207 (125130), maxchannels=32, flags=0x00000000
[LOG] SystemI::setOutputInternal : Setting output to ‘FMOD Core Audio Output’
2022-08-10 14:07:14.360654+0200 play_sound[4316:32678] [plugin] AddInstanceForFactory: No factory registered for id <CFUUID 0x600001644520> F8BB1C28-BAE8-11D6-9C31-00039315CD46
[LOG] OutputCoreAudio::init : Output running 2 channels at 44100Hz sample rate.
[LOG] OutputCoreAudio::init : Maximum hardware read size: 512 samples, Software buffer size: 512 samples, Number of software buffers: 4.
[LOG] SystemI::init : Output requires a sample rate of 44100Hz, resampling will occur.
[LOG] Thread::initThread : Init FMOD stream thread. Affinity: 0x4000000000000003, Priority: 0xFFFF7FFB, Stack Size: 98304, Semaphore: No, Sleep Time: 10, Looping: Yes.
[LOG] Thread::initThread : Init FMOD mixer thread. Affinity: 0x4000000000000001, Priority: 0xFFFF7FFA, Stack Size: 81920, Semaphore: Yes, Sleep Time: 0, Looping: Yes.
[LOG] SystemI::createSoundInternal : Create name=‘/Users/thstehle/Library/Developer/Xcode/DerivedData/play_sound-embpzygqjppqtybrdtewamsyzzwf/Build/Products/Debug/play_sound.app/Contents/Resources/media/drumloop.wav’, mode=0x00000000
[LOG] SystemI::createSoundInternal : Sample 0/0: name=‘(null)’, format=2, channels=1, frequency=44100, lengthbytes=84316, lengthpcm=42158, pcmblocksize=0, loopstart=20512, loopend=42157, mode=0x00000002, channelmask=0x00000000, channelorder=0, peakvolume=0.000000.
[LOG] SystemI::createSoundInternal : Create name=‘/Users/thstehle/Library/Developer/Xcode/DerivedData/play_sound-embpzygqjppqtybrdtewamsyzzwf/Build/Products/Debug/play_sound.app/Contents/Resources/media/jaguar.wav’, mode=0x00000000
[LOG] SystemI::createSoundInternal : Sample 0/0: name=‘(null)’, format=2, channels=1, frequency=22050, lengthbytes=77824, lengthpcm=38912, pcmblocksize=0, loopstart=0, loopend=0, mode=0x00000000, channelmask=0x00000000, channelorder=0, peakvolume=0.000000.
[LOG] SystemI::createSoundInternal : Create name=‘/Users/thstehle/Library/Developer/Xcode/DerivedData/play_sound-embpzygqjppqtybrdtewamsyzzwf/Build/Products/Debug/play_sound.app/Contents/Resources/media/swish.wav’, mode=0x00000000
[LOG] SystemI::createSoundInternal : Sample 0/0: name=‘(null)’, format=2, channels=2, frequency=22050, lengthbytes=32768, lengthpcm=32544, pcmblocksize=1017, loopstart=0, loopend=0, mode=0x00000000, channelmask=0x00000000, channelorder=0, peakvolume=0.000000.
=================================================================
Main Thread Checker: UI API called on a background thread: -[NSApplication delegate]
PID: 4316, TID: 32678, Thread name: (none), Queue name: com.apple.root.default-qos.overcommit, QoS: 0
Backtrace:
4 play_sound 0x000000010264151c _Z13Common_Updatev + 44
5 play_sound 0x00000001026402c1 _Z9FMOD_Mainv + 353
6 play_sound 0x0000000102641f61 -[ExampleApplicationDelegate threadMain:] + 65
7 Foundation 0x00007ff809746964 NSThread__start + 1009
8 libsystem_pthread.dylib 0x000000010ad85c0d _pthread_start + 125
9 libsystem_pthread.dylib 0x000000010ad8dccf thread_start + 15
2022-08-10 14:07:14.550038+0200 play_sound[4316:32678] [reports] Main Thread Checker: UI API called on a background thread: -[NSApplication delegate]
PID: 4316, TID: 32678, Thread name: (none), Queue name: com.apple.root.default-qos.overcommit, QoS: 0
Backtrace:
4 play_sound 0x000000010264151c _Z13Common_Updatev + 44
5 play_sound 0x00000001026402c1 _Z9FMOD_Mainv + 353
6 play_sound 0x0000000102641f61 -[ExampleApplicationDelegate threadMain:] + 65
7 Foundation 0x00007ff809746964 NSThread__start + 1009
8 libsystem_pthread.dylib 0x000000010ad85c0d _pthread_start + 125
9 libsystem_pthread.dylib 0x000000010ad8dccf thread_start + 15
2022-08-10 14:07:19.733698+0200 play_sound[4316:32694] HALC_ProxyIOContext::IOWorkLoop: failed to send the final message to the server, Error: 0x10000003
2022-08-10 14:07:19.997210+0200 play_sound[4316:32732] HAL_HardwarePlugIn_DeviceStart: no device
2022-08-10 14:07:19.997720+0200 play_sound[4316:32732] HALPlugIn::StopIOProc: got an error from the plug-in routine, Error: 560947818 (!obj)
2022-08-10 14:07:20.026177+0200 play_sound[4316:32732] HAL_HardwarePlugIn_DeviceDestroyIOProcID: no device
2022-08-10 14:07:20.026338+0200 play_sound[4316:32732] HALPlugIn::DeviceCreateIOProcID: got an error from the plug-in routine, Error: 560947818 (!obj)
2022-08-10 14:07:20.466014+0200 play_sound[4316:32732] HAL_HardwarePlugIn_ObjectHasProperty: no object
2022-08-10 14:07:20.466259+0200 play_sound[4316:32732] HAL_HardwarePlugIn_ObjectHasProperty: no object
2022-08-10 14:07:20.466357+0200 play_sound[4316:32732] HAL_HardwarePlugIn_ObjectHasProperty: no object
2022-08-10 14:07:20.466470+0200 play_sound[4316:32732] HAL_HardwarePlugIn_ObjectHasProperty: no object
2022-08-10 14:07:20.466567+0200 play_sound[4316:32732] HAL_HardwarePlugIn_ObjectHasProperty: no object
2022-08-10 14:07:20.466644+0200 play_sound[4316:32732] HAL_HardwarePlugIn_ObjectHasProperty: no object
2022-08-10 14:07:20.466828+0200 play_sound[4316:32732] HAL_HardwarePlugIn_ObjectHasProperty: no object
[LOG] Thread::callback : FMOD mixer thread finished.
[LOG] OutputCoreAudio::init : Output running 8 channels at 48000Hz sample rate.
[LOG] OutputCoreAudio::init : Maximum hardware read size: 512 samples, Software buffer size: 512 samples, Number of software buffers: 4.
[LOG] DownMix::init : dspbuffersize: 512 rate: 48000. output speaker mode: 7, input speaker mode 3
[LOG] DownMix::init : done.
[LOG] Thread::initThread : Init FMOD mixer thread. Affinity: 0x4000000000000001, Priority: 0xFFFF7FFA, Stack Size: 81920, Semaphore: Yes, Sleep Time: 0, Looping: Yes.

Here, all the HAL_ output comes the moment I unplug my headphone.

I am on an M1 Mac so another thing worth mentioning is maybe that I could build but not launch the example app using the scheme “My Mac”. Instead, I had to use the scheme “My Mac (Rosetta)” which implies that I had to launch an emulated instead of a native app. When trying to launch the native app Xcode tells me: “The LaunchServices launcher has returned an error. Please check the system logs for the underlying cause of the error.” This log, however, looks somewhat uninteresting so I am not posting it now.

Thanks!

Thomas

#8

Our examples haven’t been updated to run natively on Apple Silicon yet, but FMOD should otherwise be running natively on M1 hardware.
It looks like you are still getting the same errors regardless of the architecture differences. It might be worth taking a look at your app on our end to see if we can reproduce the crash, and if we can then we will be able to swap out the FMOD libs for debug versions. Would it be possible for you to upload a basic reproduction to your FMOD Profile?

#9

Jeff,

I appreciate the help. I just uploaded a somewhat minimal example to reproduce the crash. Please compile it using cmake under macOS, run the app from the projects root folder, and unplug a headphone while the song plays.

Thank you very much!
Thomas

#10

Thank you for sending that over, unfortunately I couldn’t reproduce a crash on an m1 or intel Mac.
I am running out of ideas on what this could be; do you have an external audio interface that you are connected to or something like that?

#11

Jeff,

too bad you could not reproduce the issue. I am also out of ideas and would say we let things settle down until a later point. I would get back to you again if the problem persists and/or I discover a new angle on it.

Thank you dearly for all the help so far!

Thomas

#12

One more thing actually, could we please get a full crash callstack or core dump from you?

#13

I dug a little more into the topic and I’m a bit embarrassed now. It looks like the “crash” I talked about the whole time was “just” an automatic breakpoint set by my debugger on a throw call. When the headphone gets unplugged, the thread where the audio is handled leads to a throw by HALDevice::StopIOProc. If I deactivate this breakpoint the program doesn’t halt anymore and continues running after a very slight hiccup (which seems to be normal when I look at the behavior of other apps in the same situation). Obviously, the program also doesn’t halt when I just run it straight from the command line.

For completeness, here is a screenshot of the stack trace from the audio thread:

image
image3223×882 459 KB

Thanks!

#14

That does explain things, I will keep this possibility in mind for inexplicbale crashes in future. Thanks for letting us know, and glad you got to the bottom of it!