sbooth / SFBAudioEngine

A powerhouse of audio functionality for macOS and iOS
https://sbooth.github.io/SFBAudioEngine/
MIT License
552 stars 87 forks source link

Issues queueing and dequeueing Opus tracks #291

Closed fig7 closed 5 months ago

fig7 commented 5 months ago

I am writing my own music player for MacOS and I am using the SFBAudioEngine for playback. It is working very well for me so far.

My player always queues the next track when the audio player indicates that a track is now playing (in audioPlayerNowPlayingChanged()). This works just fine if all the tracks are mp3/vorbis or if they are all opus.

But when my playlist mixes opus and mp3 (or vorbis) tracks, there are problems.

One of two things happen next:

  1. The player unexpectedly transitions between paused and playing before playing the opus track. Then, when the opus track finishes playing, it unexpectedly transitions between playing and paused, leaving my player thinking that playback is paused (which it isn't). I am using audioPlayerPlaybackStateChanged() to observe the state of the player.

  2. Sometimes, the player simply fails to dequeue the opus track, and playback stops.

I have done a little bit of debugging and I think these things happen because opus needs a different audio node, so the player has to switch between audio nodes, and that's when things go wrong. Now that I think about it, I wonder if the unexpected player states come from the "other audio node". The second issue doesn't happen as often, but it's really annoying when it does!

NB. This is on a Mac M1 Mini running MacOS 14.

fig7 commented 5 months ago

I am debugging this now, so I will try to get some more information. I have seen it stop going from opus to vorbis now, too. I've only had it stop playing once so far. In that case, the new decoder somehow got cancelled before it had a chance to get going.

More info: the audio node sometimes generates more than one "EndOfAudio" event. My app doesn't implement the EndOfAudio callback, so the player is commanded to stop! See lines 909-912 in SFBAudioPlayer.mm

I am going to try just implementing a dummy EndOfAudioCallback and see if that solves "problem 2" for me.

More info 2: I'm guessing the guard flags (lines 890-892) should have prevented this from happening, but they didn't for some reason. It looks like they do when the audio plays properly.

sbooth commented 5 months ago

I need to delve into this more deeply but it seems like this could be a synchronization issue between the player's decoder queue, the player node's decoder queue, and the decoding thread.

Are you able to replicate the problem using SimplePlayer?

What is the channel count and sample rate of the files? I doubt this is related to the file format per se but rather the switching of the player node behind the scenes as you suspect.

fig7 commented 5 months ago

I haven't tried. I will have a look at the SimplePlayer tomorrow. I don't know what the sample rates of the files are, but I can check that too. It's quite possible that the sample rates differ. Some of my music I have ripped from CDs, but other tracks were downloaded. I've got mp3s, m4as, oggs, and some flac too. It's all a bit of a mix.

fig7 commented 5 months ago

I can confirm that SimplePlayer has the same problem. My Opus tracks are 48KHz and most of my other tracks are 44.1KHz. The EndOfAudio notification gets called twice. The first call dequeues the next decoder and the second call cancels it. This doesn't happen every time, but it happens often enough to reproduce it easily. Full log from when it goes wrong:

Render block format: <AVAudioFormat 0x600001e48140: 2 ch, 48000 Hz, Float32, deinterleaved> Decoder thread starting AVAudioMixerNode input sample rate (48000.00 Hz) and output sample rate (44100.00 Hz) don't match ↑ rendering: <AVAudioFormat 0x600001e48140: 2 ch, 48000 Hz, Float32, deinterleaved> ← main mixer out: <AVAudioFormat 0x600001e55680: 2 ch, 44100 Hz, Float32, deinterleaved> Enqueuing "Damned If I Do.opus" Dequeued decoder for "Damned If I Do.opus" Processing format: <AVAudioFormat 0x600001e48230: 2 ch, 48000 Hz, Float32, interleaved> Decoding started for "Damned If I Do.opus" Rendering will start in 11.84 msec for "Damned If I Do.opus" Rendering started notification for "Damned If I Do.opus" arrived 1.08 msec late Insufficient audio in ring buffer: 473 frames available, 557 requested Decoding complete for "Damned If I Do.opus" Rendering will complete in 20.47 msec for "Damned If I Do.opus" End of audio in 22.45 msec Collecting decoder for "Damned If I Do.opus" Insufficient audio in ring buffer: 369 frames available, 557 requested End of audio in 19.42 msec Rendering complete notification for "Damned If I Do.opus" arrived 1.36 msec late End of audio notification arrived 1.15 msec late Render block format: <AVAudioFormat 0x600001ee01e0: 2 ch, 44100 Hz, Float32, deinterleaved> Decoder thread starting ↑ rendering: <AVAudioFormat 0x600001ee01e0: 2 ch, 44100 Hz, Float32, deinterleaved> Enqueuing "Love Is A Wonderful Colour.ogg" Dequeued decoder for "Love Is A Wonderful Colour.ogg" Processing format: <AVAudioFormat 0x600001ee01e0: 2 ch, 44100 Hz, Float32, deinterleaved> Decoding started for "Love Is A Wonderful Colour.ogg" End of audio notification arrived 1.35 msec late Canceling decoding for "Love Is A Wonderful Colour.ogg" Collecting decoder for "Love Is A Wonderful Colour.ogg"

sbooth commented 5 months ago

Edit: I believe I'm able to reproduce the issue.

sbooth commented 5 months ago

Please try out the change in #292 which should fix the problem.

Thanks for the bug report!

fig7 commented 5 months ago

My first impression is that the change works. I will give it a more thorough test tomorrow. Many thanks for the quick response.

fig7 commented 5 months ago

As far as I can tell, everything is working perfectly for me now. The issue I was seeing with the player state events (from audioPlayerPlaybackStateChanged()) was a bug in my code. The less said about that the better!