Fix gapless playback #269

ArthaTi · 2020-07-24T07:49:13Z

After the song ends, libspotify continues to push data to the buffer, which breaks gapless playback.

This change fixes this by unloading the track after it ends.

Closes #160.

codecov · 2020-07-24T07:50:19Z

Codecov Report

Merging #269 into master will increase coverage by 0.01%.
The diff coverage is 100.00%.

@@            Coverage Diff             @@
##           master     #269      +/-   ##
==========================================
+ Coverage   96.64%   96.65%   +0.01%     
==========================================
  Files          13       13              
  Lines        1191     1197       +6     
==========================================
+ Hits         1151     1157       +6     
  Misses         40       40

Impacted Files	Coverage Δ
mopidy_spotify/playback.py	`100.00% <100.00%> (ø)`

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 4a28aab...7bdb72d. Read the comment docs.

ArthaTi · 2020-07-24T08:45:02Z

Weird, this fix doesn't seem to be working when running from systemctl. I wonder why. Logger calls I placed in the code are added to the log, so it must be running with my patch added, but the pause between songs is still there.

E: I'll have to do more testing, it seems to only work with my specific setup, weird thing.

E2: I just stopped reproducing it on my own machine, gapless play back isn't working once again.

ArthaTi · 2020-07-24T17:02:19Z

Ok, apparently libspotify sends one of those invalid packets before sending track end signal... is there any way to stop that other than measuring buffer size?

adamcik · 2020-07-24T18:31:15Z

This has been eluding me for years, this is an awesome find! Perhaps you could delay everything by one buffer by queuing it in our code (not in GStreamer) and then just discard the last one if this bad behavior is consistent?

ArthaTi · 2020-07-24T20:17:08Z

@adamcik Thank you! I thought of this solution, and I think it should work well.

I'll ask first, I don't see any access to self from the callbacks — if I were to implement the delay, where should I put the variable? I'm used to avoiding globals, so is a module-scoped variable okay?

adamcik · 2020-07-25T04:23:36Z

We know this should be a singleton, so I think we can get away with doing this module scoped. At least it's good enough to get things going and see if it works?

ArthaTi · 2020-07-27T19:54:51Z

Too many commits for this little thing, excuse my stupidity. At least it's working well now, I've been playing music and radios all day, I'm not getting any errors and transitions are good.

@adamcik I'd like to request a review.

adamcik

I've added some suggestions, and mostly questions about things I don't know the answer to off the top of my head. The one that I would like addressed is just adding some more comments for future readers of the code, rest I'm not as sure of.

It's been quite some time since I've been deep in the audio code for mopidy, at some point my attempts at getting gapless working and unblocking plugable outputs ground to a halt likely due to what this PR fixes.

adamcik · 2020-07-29T04:41:02Z

mopidy_spotify/playback.py

@@ -15,6 +15,9 @@
 # Extra log level with lower importance than DEBUG=10 for noisy debug logging
 TRACE_LOG_LEVEL = 5

+# Last audio data sent to the buffer, currently on hold


I would put in a small explanation about why we need to do this, it's not obvious without the context of this PR. So perhaps a short sentence with a link to this PR or a self contained paragraph?

adamcik · 2020-07-29T04:44:20Z

mopidy_spotify/playback.py

@@ -78,6 +83,7 @@ def change_track(self, track):
            sp_track.load(self._timeout)
            self.backend._session.player.load(sp_track)
            self.backend._session.player.play()
+            _held_buffer = None


@jodal probably knows the answer to this better than me, but when would the session start being able to fill this value async? I.e. should we reset it before calling load/play, or does it depend on the current state of the session?

Could protecting this global with a lock be reasonable, or are we just asking for deadlocks if we aren't careful?

music_delivery will start firing as soon as player.play() is called and so a race sounds possible. Is there any issue with resetting it along with the other stuff before the try block?

It should be fine if placed before. My mistake I didn't think it could happen. I'll correct this.

adamcik · 2020-07-29T04:46:20Z

mopidy_spotify/playback.py

+    if _held_buffer:
+        consumed = audio_actor.emit_data(_held_buffer).get()
+    else:
+        consumed = True


I don't know if this should be true when there isn't a held buffer, as a follow on effect would be increasing the duration incorrectly?

I set it as true, because we take the current buffer and put it on hold, which (if my understanding of frame consumption is right) means we did consume the frames — even if we'll push it to Mopidy later.

On the other hand, I'm not sure if the buffer_timestamp is increased correctly if its done before emitting data.

It does seem weird to attach what we know is the wrong timestamp to the buffer we are emitting to GST (although the error will be very small). Should we be doing something more like buffer_timestamp.increase(_held_buffer.duration)?

EDIT: Sorry, confused myself. The timestamp attached to the buffer is obviously correct.

I think this is fine. It doesn't matter when we increment buffer_timestamp as long as it's before we use in the next delivery.

adamcik · 2020-07-29T04:55:12Z

Also, if you feel your git skills are up to it, feel free to tidy up the commits by rebasing/squashing etc (but no pressure if you feel that would just create a mess). We often do this type of cleanup on our own changes to keep the history tidy. As we'll often go through a similar process as you have in this PR finding more things to fix/adjust...

adamcik · 2020-07-30T04:59:44Z

@jodal can/should the empty buffer suppression be moved to pyspotify, or should we document change things so we could do a buffer == pyspotify.SOME_CONSTANT_FOR_THE_FINAL_SAMPLE type check akin to checking for EOS in the GStreamer world?

Oops... Cleanup

kingosticks · 2020-08-24T15:13:53Z

Nice! This is a great find and I don't understand how I missed / forgot about this PR. It prompted me to find https://stackoverflow.com/questions/26014520/libspotify-c-sending-zeros-at-the-end-of-track which also talks about that final data buffer of 22050 zeros. I think your solution works great and I am happy to go with it. Catching this funny final music_delivery case as it happens is also an option. We could then avoid emitting the large empty buffer which is the ultimate cause of our nasty gap. Something like:

    if num_frames == pyspotify.NUM_FRAMES_EOT: # 22050
        consumed = True
      else:
        consumed = audio_actor.emit_data(buffer_).get()

The above works with or without the addition of session.player.unload() but we might as well have that too since it makes sense and it also stops the duration being increased any further than the fake final delivery already has.

That Stack Overflow post also talks about how the duration is pushed beyond the length of the track by this fake final delivery and otherwise may come up a little short. So another option might be detect when the buffer_timestamp increase is going to take us beyond the length of the track.

EDIT:
I found this patch also worked well. It might be all in my head but the track changes sound smoother now on a Rapsberry Pi, it used to stutter sometimes.

diff --git a/mopidy_spotify/playback.py b/mopidy_spotify/playback.py
index d86d6da2..f0d287ff 100644
--- a/mopidy_spotify/playback.py
+++ b/mopidy_spotify/playback.py
@@ -182,6 +182,10 @@ def music_delivery_callback(
     )
     assert known_format, "Expects 16-bit signed integer samples"
 
+    if num_frames == 22050:
+        logger.info(f"Empty final music delivery before end_of_track")
+        return 0
+
     duration = audio.calculate_duration(num_frames, audio_format.sample_rate)
     buffer_ = audio.create_buffer(
         bytes(frames), timestamp=buffer_timestamp.get(), duration=duration
@@ -207,6 +211,7 @@ def end_of_track_callback(session, end_of_track_event, audio_actor):
     logger.debug("End of track reached")
     end_of_track_event.set()
     audio_actor.emit_data(None)
+    session.player.unload()

ArthaTi · 2020-08-25T11:28:38Z

@kingosticks Your proposed solution is what I thought of at first and used as a workaround, but I wasn't sure if this condition would always trigger only when needed. I think buffer holding is better for this reason.

Also, sorry for stalling the PR for the time, I hope the added comments should be okay now.

By the way, because I was away and my laptop had weird issues with Python, I had to use plain Spotify for a week. Their clients are so inconsistent and broken. Mopidy is really a bless. Thank you for making this project ❤️

kingosticks · 2020-08-24T11:51:02Z

mopidy_spotify/playback.py

@@ -78,6 +83,7 @@ def change_track(self, track):
            sp_track.load(self._timeout)
            self.backend._session.player.load(sp_track)
            self.backend._session.player.play()
+            _held_buffer = None


music_delivery will start firing as soon as player.play() is called and so a race sounds possible. Is there any issue with resetting it along with the other stuff before the try block?

kingosticks · 2020-08-25T11:44:41Z

mopidy_spotify/playback.py

+    if _held_buffer:
+        consumed = audio_actor.emit_data(_held_buffer).get()
+    else:
+        consumed = True


It does seem weird to attach what we know is the wrong timestamp to the buffer we are emitting to GST (although the error will be very small). Should we be doing something more like buffer_timestamp.increase(_held_buffer.duration)?

EDIT: Sorry, confused myself. The timestamp attached to the buffer is obviously correct.

kingosticks · 2020-08-25T11:53:41Z

I understand and I do agree that delaying the buffer is nicer in theory, but involving inter-thread communication makes it more complicated too.

kingosticks · 2020-08-25T12:29:56Z

And I will add, I love that you've fixed this. There're some albums I've only ever heard on Spotify and they sound almost brand new (better!) with gapless fixed - amazing!

jodal

I think this looks good! All the testing and eyes on what is quite small changes make me confident this is a clear improvement.

I prefer holding the buffer to discarding deliveries of exactly 22050 frames. 22050*2=44100, as in https://en.wikipedia.org/wiki/44,100_Hz, so that sounds like exactly 0.5s of audio and not an obscure sample size we'll never see in other situations.

jodal · 2020-08-26T20:01:04Z

Regarding the failing CI checks:

If you rebase one of the three flake8 warnings will be fixed. The other two are comment lines from this PR that needs to be wrapped to be shorter.
The single test that fails, 'test_music_delivery_creates_gstreamer_buffer_and_gives_it_to_audio', I think just needs to deliver two buffers instead of one, and still assert that just a single buffer is delivered to Mopidy's audio subsystem.

kingosticks · 2020-09-22T17:00:44Z

What happens with the global _held_buffer under pytest? Don't they all ~~run in parallel and~~ all access the same variable?

kingosticks · 2020-09-22T23:50:05Z

~~In fact, and even when not running in parallel,~~ _held_buffer isn't reset to None between all those music_delivery_callback tests.

EDIT: pytest doesn't run tests in parallel, that was nose that did that.

kingosticks · 2020-11-23T14:21:47Z

Closing this in favour of the version at #277 that's tweaked for easier testing.

Fix gapless playback

0423b5e

Add buffer holding

9e8520a

adamcik self-assigned this Jul 29, 2020

adamcik reviewed Jul 29, 2020

View reviewed changes

bugfix

fe5b0c0

Oops... Cleanup

adamcik mentioned this pull request Aug 24, 2020

Playback randomly stops until I skip to the next track #271

Closed

adamcik requested review from jodal and kingosticks August 24, 2020 08:38

Improve comments

e7d2733

kingosticks approved these changes Aug 25, 2020

View reviewed changes

Move buffer clearing to avoid race conditions

7bdb72d

ArthaTi requested a review from adamcik August 26, 2020 18:56

jodal approved these changes Aug 26, 2020

View reviewed changes

kingosticks mentioned this pull request Sep 29, 2020

Soaku gapless playback #277

Merged

kingosticks closed this Nov 23, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fix gapless playback #269

Fix gapless playback #269

ArthaTi commented Jul 24, 2020 •

edited

Loading

codecov bot commented Jul 24, 2020 •

edited

Loading

ArthaTi commented Jul 24, 2020 •

edited

Loading

ArthaTi commented Jul 24, 2020

adamcik commented Jul 24, 2020

ArthaTi commented Jul 24, 2020 •

edited

Loading

adamcik commented Jul 25, 2020

ArthaTi commented Jul 27, 2020

adamcik left a comment

adamcik Jul 29, 2020

adamcik Jul 29, 2020

kingosticks Aug 24, 2020

ArthaTi Aug 25, 2020

adamcik Jul 29, 2020

ArthaTi Jul 30, 2020

kingosticks Aug 25, 2020 •

edited

Loading

kingosticks Aug 25, 2020

adamcik commented Jul 29, 2020

adamcik commented Jul 30, 2020

kingosticks commented Aug 24, 2020 •

edited

Loading

ArthaTi commented Aug 25, 2020

kingosticks Aug 24, 2020

kingosticks Aug 25, 2020 •

edited

Loading

kingosticks commented Aug 25, 2020

kingosticks commented Aug 25, 2020

jodal left a comment

jodal commented Aug 26, 2020

kingosticks commented Sep 22, 2020 •

edited

Loading

kingosticks commented Sep 22, 2020 •

edited

Loading

kingosticks commented Nov 23, 2020

Fix gapless playback #269

Fix gapless playback #269

Conversation

ArthaTi commented Jul 24, 2020 • edited Loading

codecov bot commented Jul 24, 2020 • edited Loading

Codecov Report

ArthaTi commented Jul 24, 2020 • edited Loading

ArthaTi commented Jul 24, 2020

adamcik commented Jul 24, 2020

ArthaTi commented Jul 24, 2020 • edited Loading

adamcik commented Jul 25, 2020

ArthaTi commented Jul 27, 2020

adamcik left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

kingosticks Aug 25, 2020 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

adamcik commented Jul 29, 2020

adamcik commented Jul 30, 2020

kingosticks commented Aug 24, 2020 • edited Loading

ArthaTi commented Aug 25, 2020

Choose a reason for hiding this comment

kingosticks Aug 25, 2020 • edited Loading

Choose a reason for hiding this comment

kingosticks commented Aug 25, 2020

kingosticks commented Aug 25, 2020

jodal left a comment

Choose a reason for hiding this comment

jodal commented Aug 26, 2020

kingosticks commented Sep 22, 2020 • edited Loading

kingosticks commented Sep 22, 2020 • edited Loading

kingosticks commented Nov 23, 2020

ArthaTi commented Jul 24, 2020 •

edited

Loading

codecov bot commented Jul 24, 2020 •

edited

Loading

ArthaTi commented Jul 24, 2020 •

edited

Loading

ArthaTi commented Jul 24, 2020 •

edited

Loading

kingosticks Aug 25, 2020 •

edited

Loading

kingosticks commented Aug 24, 2020 •

edited

Loading

kingosticks Aug 25, 2020 •

edited

Loading

kingosticks commented Sep 22, 2020 •

edited

Loading

kingosticks commented Sep 22, 2020 •

edited

Loading