Application producing audio hangs when starting to reproduce it about backgroundmusic HOT 4 CLOSED

Yes, I second this. Mostly when a video is about to play (eg. YouTube on Safari), Safari freezes at times for a good 10-12 seconds, giving the colorful beachball. Started happening only after installing BackgroundMusic. OS X 10.11.4 El Capitan.

from backgroundmusic.

I've been getting something like that in Safari as well, but I think only recently and I wasn't sure Background Music was actually causing it. (Rather than something I'd done while developing.) I don't use Safari except for testing, so I might just not have noticed it before, or thought it was just my internet being slow. Safari doesn't hang for me, but it does take a while to start playing audio occasionally. I also just now managed to get the audio to go out of sync, which I hadn't noticed before.

I've made a note to look into these syslog errors:

27/04/2016 1:57:46.953 AM com.apple.WebKit.WebContent[50034]: [01:57:46.953] propertyListenerDispatch signalled err=268451843 (err) (can't get nominal sample rate) at /Library/Caches/com.apple.xbs/Sources/CoreMedia_frameworks/CoreMedia-1731.15.202/Sources/Core/FigSync/FigAudioDeviceClock.c line 1108

27/04/2016 1:57:47.004 AM com.apple.WebKit.WebContent[50034]: [01:57:47.004] faqrp_startTimebaseAndAudioQueue signalled err=-66681 (err) (FigAudioQueueStart(now) failed) at /Library/Caches/com.apple.xbs/Sources/CoreMedia/CoreMedia-1731.15.202/Prototypes/RenderPipelines/FigAudioQueueRenderPipeline.c line 1231

27/04/2016 1:57:46.953 AM com.apple.WebKit.WebContent[50034]: [01:57:46.953] propertyListenerDispatch signalled err=268451843 (err) (can't get nominal sample rate) at /Library/Caches/com.apple.xbs/Sources/CoreMedia_frameworks/CoreMedia-1731.15.202/Sources/Core/FigSync/FigAudioDeviceClock.c line 1108

27/04/2016 2:14:36.660 AM com.apple.WebKit.WebContent[5475]: [02:14:36.660] __fadcGetAnchorTimeInternal_block_invoke signalled err=1937010544 (err) (AudioDeviceGetCurrentTime failed; continuing to interpolate) at /Library/Caches/com.apple.xbs/Sources/CoreMedia_frameworks/CoreMedia-1731.15.202/Sources/Core/FigSync/FigAudioDeviceClock.c line 612

Unfortunately, CoreMedia is closed source, so I can't actually look at any of the C files they mention. I should be able to find the WebKit code that's generating the messages, though.

I've tried a couple of small fixes, but I think I might have to do some fairly in-depth debugging to figure out what's actually going on. I think there's a decent chance this bug is cause by the new code that synchronizes the app and the driver when IO starts. If so, it should at least be easy enough to show that it is actually what causing the problem.

I should really get around to enabling some logging in release builds, too. That would be really useful for bugs like this. Or at least make it easier to do a debug build.

I'll update this issue after I've looked into it properly. Thanks for the reports.

from backgroundmusic.

Yeah I'm sorry for not providing better debug infos. Here's some logs:

Apr 26 21:23:49 swordfish-II coreaudiod[183]: BGM_XPCHelper::WaitForBGMAppToStartOutputDevice: Timed out waiting for the Background Music app to start the output device
Apr 26 21:23:49 swordfish-II com.apple.WebKit.WebContent[594]: [00:39.091890] <<<< FADC >>>> propertyListenerDispatch: can't get nominal sample rate. ERROR 2003332927
Apr 26 21:23:49 swordfish-II com.apple.WebKit.WebContent[594]: [00:39.091872] <<<< FADC >>>> propertyListenerDispatch: can't get nominal sample rate. ERROR 2003332927
Apr 26 21:23:49 swordfish-II com.apple.WebKit.WebContent[594]: [00:39.091914] <<<< FADC >>>> propertyListenerDispatch: can't get nominal sample rate. ERROR 2003332927
Apr 26 21:23:49 swordfish-II com.apple.WebKit.WebContent[594]: [00:39.091920] <<<< FADC >>>> propertyListenerDispatch: can't get nominal sample rate. ERROR 2003332927
Apr 26 21:23:49 swordfish-II com.apple.WebKit.WebContent[594]: [00:39.091939] <<<< FADC >>>> propertyListenerDispatch: can't get nominal sample rate. ERROR 2003332927
Apr 26 21:23:49 swordfish-II com.apple.WebKit.WebContent[594]: [21:23:49.103] propertyListenerDispatch signalled err=2003332927 (err) (can't get nominal sample rate) at /Library/Caches/com.apple.xbs/Sources/CoreMedia_frameworks/CoreMedia-1731.15.202/Sources/Core/FigSync/FigAudioDeviceClock.c line 1108
Apr 26 21:23:49 --- last message repeated 3 times ---
Apr 26 21:23:49 swordfish-II com.apple.WebKit.WebContent[594]: [21:23:49.103] <<< CFByteFlume >>> FigCFHTTPCopyBandwidthInfo: [0x7fe310ec2450] dead connection? returning 0.0 for bandwidth and clearing history
Apr 26 21:23:49 swordfish-II com.apple.WebKit.WebContent[594]: [21:23:49.103] propertyListenerDispatch signalled err=2003332927 (err) (can't get nominal sample rate) at /Library/Caches/com.apple.xbs/Sources/CoreMedia_frameworks/CoreMedia-1731.15.202/Sources/Core/FigSync/FigAudioDeviceClock.c line 1108
Apr 26 21:23:49 swordfish-II com.apple.WebKit.WebContent[594]: [21:23:49.104] faqrp_startTimebaseAndAudioQueue signalled err=-66681 (err) (FigAudioQueueStart(now) failed) at /Library/Caches/com.apple.xbs/Sources/CoreMedia/CoreMedia-1731.15.202/Prototypes/RenderPipelines/FigAudioQueueRenderPipeline.c line 1231
Apr 26 21:23:49 swordfish-II com.apple.WebKit.WebContent[594]: [21:23:49.104] <<<< Boss >>>> bossSetPossiblyOutsourcedTimebaseRate: FigRenderPipelineSetRate on pipeline 0x7fe31726b610 with timebase rate 1.000 and pipeline rate 1.000, failed with err=-66681

These logs start after Safari unfreezes.
Maybe the first line could be useful in debugging this.
I just started reading the code, but it'll take sometime before I actually understand what's going on 😄

from backgroundmusic.

Thanks, @choco. That helped solve it. Turns out it was a pretty simple mistake. I was holding BGM_Device's state mutex longer than I should have been while IO was starting up. So if IO starting also made BGMApp request some data from BGMDriver, a different BGMDriver thread would block trying to take the state mutex so it could return that data. And BGMApp needed that data before it could finish starting IO and let BGMDriver do the same, so they would deadlock until the XPC timeout.

Well, it was simpler than I thought it was going to be.

As always, if b58ad2a doesn't fix the problem for you, let me know and I'll reopen this issue.

from backgroundmusic.