WIP: new Spotify API #917

roderickvd · 2021-12-29T07:17:58Z

roderickvd
Dec 29, 2021
Maintainer

roderickvd · 2021-12-30T19:44:06Z

roderickvd
Dec 30, 2021
Maintainer Author

@gdesmott w.r.t. your lyrics structs, a couple of points:

The response is different between get_lyrics and get_lyrics_for_image. Follow the links for Gists to sample responses.
There are tracks with lyrics without timestamps. I know so because a few days ago my Spotify TV app showed lyrics with a message along the lines of "the lyrics for this track are not synchronised yet". I forgot to remember the track.

To add lyrics parsing to librespot-metadata, we'll have to deal with these, preferably unifying them so we don't have double types.

9 replies

gdesmott Dec 31, 2021

No, it requires you already have that art. That's why you have to specify the image_id in the call. That ID has to match with the track (e.g. be a cover for that album) or the call will fail; you can't just specify any random ID even if it exists for some other track.

Then I really don't see the point of this API. Why use that instead of the simpler one if you have to pass the track ID anyway? What's the point of passing the extra art?

What about this: we keep the existing low level API on SpClient unchanged. Then we add a higher level API on Track::get_lyrics() using the first low level API and returning a parsed version? I don't see the point of providing a high level API for the art variant.

gdesmott Dec 31, 2021

I'm about to close off -- can you see a difference in response? Can you post a gist?

Here is one. It seems to be exactly the same except the missing time attributes.

roderickvd Jan 1, 2022
Maintainer Author

I'm about to close off -- can you see a difference in response? Can you post a gist?

Here is one. It seems to be exactly the same except the missing time attributes.

That seems fortunate, because I think we can then just wrap timestamps in an Option<u32> and serde will do its thing.

It may also be that lyrics.kind indicates whether it's time-synchronised or not. LINE for synchronised, TEXT for unsynchronised. Can we affirm this with a couple more tracks?

Then I really don't see the point of this API. Why use that instead of the simpler one if you have to pass the track ID anyway? What's the point of passing the extra art?

I'm not sure I agree. First of all get_lyrics_for_image has some more optional metadata fields. Second the colours that are returned could well be different from the default one, when you pass an alternative album cover. So if someone intends to project lines over art, then that extended v2 API could be useful to them.

I don't doubt that the v1 interface would cover the 90% of use cases, but that doesn't mean we can't be complete or cater to that remaining 10% especially when it is cheap to do so.

What about this: we keep the existing low level API on SpClient unchanged.

This and then parsing in librespot_metadata::Track I agree with.

Then we add a higher level API on Track::get_lyrics() using the first low level API and returning a parsed version? I don't see the point of providing a high level API for the art variant.

We could have both Track::get_lyrics and Track::get_lyrics_for_image and still use the same structs, when we use #[serde(rename = "name")] to transform one into the other.

gdesmott Jan 2, 2022

That seems fortunate, because I think we can then just wrap timestamps in an Option and serde will do its thing.

That means users won't able to rely on the timing always being set which is unfortunate (extra test or unwrap, etc). Maybe we should return a 2-variants enum, one with timestamps and one without?

It may also be that lyrics.kind indicates whether it's time-synchronised or not. LINE for synchronised, TEXT for unsynchronised. Can we affirm this with a couple more tracks?

Good thinking, I'll do some more tests to check.

Second the colours that are returned could well be different from the default one, when you pass an alternative album cover.

That's a very good point, I didn't think about that.

roderickvd Jan 3, 2022
Maintainer Author

That seems fortunate, because I think we can then just wrap timestamps in an Option and serde will do its thing.

That means users won't able to rely on the timing always being set which is unfortunate (extra test or unwrap, etc). Maybe we should return a 2-variants enum, one with timestamps and one without?

From an API standpoint that might make sense. Hopefully it won't cause too much duplication in the implementation.

It may also be that lyrics.kind indicates whether it's time-synchronised or not. LINE for synchronised, TEXT for unsynchronised. Can we affirm this with a couple more tracks?

Good thinking, I'll do some more tests to check.

Great, I'll see what you can come up with.

roderickvd · 2021-12-30T23:02:30Z

roderickvd
Dec 30, 2021
Maintainer Author

Some new commits pushed today, most prominently:

05c768f to add audio preview, image and head file support to spclient
0fdff0d to filter explicit tracks depending on the client setting

In line with 0fdff0d I will start tracking the autoplay setting of the client. Before, I thought about keeping the --autoplay command line option as an override, but I am starting to feel like we should remove that knob. Other than backwards compatibility, I don't see any need for the override when the client toggle works just fine. It would save some cruft and potential confusion between mismatching librespot and client states. Opinions?

1 reply

roderickvd Jan 1, 2022
Maintainer Author

Made it so in 2d699e2.

roderickvd · 2022-01-01T19:57:28Z

roderickvd
Jan 1, 2022
Maintainer Author

Working on the switch to the Symphonia decoder. To start off the discussion, this requires bumping MSRV to 1.51. I already know the opinion of @JasonLG1979 😆 and welcome any others.

What this would bring us, is support for MP3, Ogg Vorbis and FLAC all in one package. You can just fire any audio stream at it and it will figure out what to do. Also, it's under active development.

If we were to support MP3 and FLAC in any other way, it would mean pulling in specific libraries per format (which aren't too great for MP3, Rust native, and AFAIK non-existent for FLAC) and creating a decoder per format.

7 replies

roderickvd Jan 3, 2022
Maintainer Author

Fixed in 096269c.

roderickvd Jan 3, 2022
Maintainer Author

OK, with the latest commits I am done with swapping out the decoder. I propose that we only enable FLAC and start advertising HiFi capabilities to the Spotify servers after Spotify HiFi actually gets released and we have had the chance to test it.

Edit: I still have to update the passthrough decoder to use Symphonia's OggReader instead of the one from ogg crate that has become legacy with the removal of lewton.

roderickvd Jan 4, 2022
Maintainer Author

Author @pdeljanov of the Symphonia project was kind enough to review our implementation and suggested a couple of improvements, that found their way in eabdd79.

In 3e09eff I made some further improvements to speed up the initial loading time. This has become more important now that we are signalling Spotify of our loading state, during which the interaction with the UI is limited. Before we signalled that, this wasn't as noticeable. The part of this commit where we've changed the initial block size is a bit more experimental and I'd appreciate some feedback on it.

pdeljanov Jan 5, 2022

Hi @roderickvd,

Unfortunately I think we may have gotten some signals crossed in our email discussion. I believe you were thinking about Spotify tracks, and I was thinking of Symphonia tracks! 😆 It's much easier to explain with code, so I submitted PR #925 to fix the mix-up. This'll do what we discussed in our email thread.

Cheers!

roderickvd Jan 5, 2022
Maintainer Author

Thanks for the help @pdeljanov. Indeed tracks can mean two different things in the domain of librespot and Symphonia.

acid-sun · 2022-01-05T15:10:44Z

acid-sun
Jan 5, 2022

Hi. HNY!
Tracks were no longer stored in cache after switching to symphonia.
Broke gapless play after сommit 01448cc.

11 replies

roderickvd Jan 6, 2022
Maintainer Author

It is possible that gapless playback does not work due to a broken preload. At f3a66d4 gapless playback works fine with symphonia and works preload next track.

I’m a bit at a loss because:

the commit after that only improves the accuracy of the actual position while playing;
my reference hapless album “The Whirlwind” by Transatlantic plays fine.

For test gapless playback I use minimix

@acid-sun can you confirm the album I mentioned above plays gapless for you?

I’m not at home right now but will try your album shortly.

It's likely this is because while version 0.4 of Symphonia provides the information required for gapless playback via. CodecParameters (leading_padding, trailing_padding, and n_frames), it does not trim the audio buffers itself. I believe lewton does.

@pdeljanov can it be that the result of these headers differs from track to track? Because I can play my album gaplessly.

(Also it doesn’t explain why that later commit broke it for @acid-sun. It’s not complete though, I will push an update shortly that also handles the new actual positions after a seek.)

If you can wait a couple of weeks I can try to add this functionality to Symphonia's mainline branch and then have it published in v0.5.

Sure! We are in no hurry to release a new librespot and gapless is an important feature.

Now caching works fine.

Thanks for the feedback.

acid-sun Jan 6, 2022

Sorry, The Whirlwind don't available for my region. I have problem with Pink Floyd The Wall and Dark Side of the Moon.
I found a way that gapless playback works. If I seek to <30 seconds of the end of track, then preload is working.

roderickvd Jan 6, 2022
Maintainer Author

I found a way that gapless playback works. If I seek to <30 seconds of the end of track, then preload is working.

Thanks, I can reproduce it now and will start working on a fix.

roderickvd Jan 6, 2022
Maintainer Author

Gapless playback should be fixed in 67ae0fc.

@pdeljanov seems like trimming those headers isn't required for gapless playback, at least not audibly?

pdeljanov Jan 7, 2022

The number of silent samples is usually pretty small. A low number of milliseconds. It would really only be noticeable if the rest of the audio pipeline is also designed around gapless playback. I'll still aim to get gapless playback fully implemented in v0.5 just in case.

Malvineous · 2022-01-06T17:25:43Z

Malvineous
Jan 6, 2022

What's the status of this patch, is it ready for use? I thought it was from the comments here but I'm unable to get it to play any audio. It either plays in silence, or it makes the playback buttons in the web player go greyed out so you can't click them. The logs say things like:

[2022-01-06T17:20:41Z ERROR librespot_playback::player] Player Commands Error: channel closed
[2022-01-06T17:20:41Z ERROR librespot_playback::player] Player Commands Error: channel closed
[2022-01-06T17:20:42Z ERROR librespot_core::mercury] error 400 for uri hm://radio-apollo/v3/stations/spotify:station:playlist:xxx
[2022-01-06T17:20:42Z ERROR librespot_connect::spirc] ContextError: Error { kind: Unavailable, error: Response(MercuryResponse { uri: "hm://radio-apollo/v3/stations/spotify:station:playlist:xxx", status_code: 400, payload: [] }) }

I'm guessing this means it's not in a functional state yet?

12 replies

roderickvd Jan 7, 2022
Maintainer Author

However this was all happening at the same time as the old API was giving me all those channel errors (#927), whereas those have all gone now and everything is working fine again. So I wonder whether it was down to problems on Spotify's end?

Could certainly be that you were in an affected region.

Certainly that HTTP error 502 Bad Gateway suggests something was up. The new-api branch is now reporting ping times around 300 ms with some up at 800 ms so it's still not fast but apparently better than it was. Either way the tracks all seem to play fine now, even if I wipe the cache to make sure they have to re-download.

Yeah, although this new branch spews out loads of errors, it's pretty robust in the sense that it doesn't panic on all these unexpected errors anymore.

I still see the same MercuryResponse error for hm://remote/user so that doesn't seem to be related to last night's errors.

Still interested if you get that [DEBUG librespot_core::mercury] subscribed uri=hm://remote/user/xxx/ count=0 later?

If so, this is a harmless race condition. I get that sometimes too, but not always. Sometimes Spotify sends us an update packet really faster after authentication, before we've set up our event listeners. There's room for improvement here, but so far it's been harmless for me.

I still get this when selecting a playlist, but it doesn't seem to cause any problems:

[ERROR librespot_core::mercury] error 400 for uri hm://radio-apollo/v3/stations/spotify:station:playlist:4d71Mz5CgmWSYR6Sdf216u
[ERROR librespot_core::session] could not dispatch command: Service unavailable { error handling Mercury response: MercuryResponse { uri: "hm://radio-apollo/v3/stations/spotify:station:playlist:4d71Mz5CgmWSYR6Sdf216u", status_code: 400, payload: [] } }

Precisely which steps do you take that trigger this? I can't reproduce it.

About the only difference I can see is that now the files are downloading successfully whereas last night they seemed not to. I guess you could try putting some code in to intentionally fail a download randomly to see if there is a race condition? It may not be worth it though, because if new-api can recover once the downloads are working again then that would be fine.

That's right. Although nicer error messages would be fine, I'd rather spend my free time developing other things.

Thanks for helping out.

Malvineous Jan 7, 2022

Still interested if you get that [DEBUG librespot_core::mercury] subscribed uri=hm://remote/user/xxx/ count=0 later?

Sorry I forgot to reply to that. Yes, I see that immediately after the could not dispatch command: Service unavailable error.

I still get this when selecting a playlist, but it doesn't seem to cause any problems:

[ERROR librespot_core::mercury] error 400 for uri hm://radio-apollo/v3/stations/spotify:station:playlist:4d71Mz5CgmWSYR6Sdf216u
[ERROR librespot_core::session] could not dispatch command: Service unavailable { error handling Mercury response: MercuryResponse { uri: "hm://radio-apollo/v3/stations/spotify:station:playlist:4d71Mz5CgmWSYR6Sdf216u", status_code: 400, payload: [] } }

Precisely which steps do you take that trigger this? I can't reproduce it.

Open web player
Select a song and play it, then pause it
Load librespot/new-api
In the web player, change the active device to librespot.
librespot will display many debug messages.
Scroll up in the librespot output, this error appears just after the active device was changed, right after DEBUG librespot_core::http_client] Requesting https://gae2-spclient.spotify.com:443/metadata/4/track/... and before Received metadata: gid.

As a last resort, maybe try connecting to ap-gae2.spotify.com:4070?

Thanks for helping out.

You're welcome!

roderickvd Jan 9, 2022
Maintainer Author

I still can't reproduce. Maybe you can tell me exactly which playlist / album / station you are getting this with.

Malvineous Jan 11, 2022

I get it on every single song on every single playlist I use (my own playlists or others'). Have you tried connecting to ap-gae2.spotify.com:4070 in case it's an endpoint-specific issue?

Today I started seeing channel errors in the old API again (which stop songs from playing) so I tried out the new one again, but none of the previous issues came up and everything played properly. I did however see these new errors:

[2022-01-11T02:19:14Z DEBUG librespot_audio::fetch::receive] Streamer expected partial content but got: 502 Bad Gateway
[2022-01-11T02:19:14Z ERROR librespot_audio::fetch::receive] Error from streamer for range 6384168 (+65140): Error { kind: FailedPrecondition, error: StatusCode(502) }

However despite this the song downloaded successfully and played correctly. I moved the file out of the cache folder and tried playing the song again to re-download it, and after doing this a few times I got a download without seeing the 502 Bad Gateway error. I did a byte compare on this 'error free' file against the first one that had the 502 error, but they were byte identical. My concern was that it could have cached a corrupted file and forever wanted to play the bad version, but this does not appear to be the case, and the correct file gets cached despite the 502 error.

I'm not sure how it manages to download correctly despite getting a HTTP 502 error but however it does it it seems to work well!

roderickvd Jan 12, 2022
Maintainer Author

Very strange but see my comment below that I'll make it so that we just bail on anything but a HTTP 206.

gdesmott · 2022-01-08T13:54:56Z

gdesmott
Jan 8, 2022

Is there any plan to add API to search the Spotify catalog? I didn't find any.

10 replies

michaelherger Jan 10, 2022

Is this different from the master branch? Because I'm using my own client ID and scopes to get a token I then use via the web API successfully (based on master/dev branches).

roderickvd Jan 10, 2022
Maintainer Author

It is, but thanks for making me look that up. The signature in dev is get_token(session: &Session, client_id: &str, scopes: &str). We don't need session anymore (TokenProvider is now a component of Session) but I'll add that client_id argument again.

gdesmott Jan 10, 2022

To work with the open Spotify API you'd have to get a token with your the client ID you got from Spotify for Developers.

Yes I think I'll need that as I want the catalog search to only return songs which are part of the user's catalog. If I understood things correctly, I'll need to use this auth method to have Spotify do the filtering.

michaelherger Jan 10, 2022

It is, but thanks for making me look that up. The signature in dev is get_token(session: &Session, client_id: &str, scopes: &str). We don't need session anymore (TokenProvider is now a component of Session) but I'll add that client_id argument again.

Thanks!

roderickvd Jan 12, 2022
Maintainer Author

In 32df4a4 I think I did you one better: I made client_id a field of SessionConfig. So you now can do session.token_provider().get_token(comma_separated_scopes) after you've done Session::connect(SessionConfig { client_id: ...)

Also I'm listening to the client_id metadata that are pushed over spirc update frames, for the odd chance that we're pushed a replacement. It's not that I've seen that happen, but I am seeing this metadata being pushed and am assuming that's for some reason. I am thinking that at some point they just might do an over-the-air exchange of the hard-coded keymaster ID for a more specific one when you've authenticated over Mercury. It won't hurt, I guess.

roderickvd · 2022-01-09T22:11:31Z

roderickvd
Jan 9, 2022
Maintainer Author

As I was updating all the crates, I found out that GStreamer would lag with audio when forwarding to the next track. Meaning: it would play a short bit of the previous track. In e69d5a8 I fixed that by flushing the buffers.

Also I removed the thread and accompanying channels to write samples to the buffer pool. That code could simply be moved to write_bytes. That still pushes the entire buffer to GStreamer so should block no more or less than the thread it was in.

Before that in d2c377d I got rid of the critical GStreamer error on shutdown, complaining we did not clean up GStreamer properly. It now also reports the Paused and Playing states properly to GStreamer.

Users of GStreamer are invited to test a bit more.

5 replies

gdesmott Jan 10, 2022

The GStreamer backend is a bit upside down. The proper way to integrate Spotify with GStreamer is to have it as a source element, which is what I did.

I'd be intersted to hear from users of this backend about their actual use cases and if they could use my element instead.

roderickvd Jan 10, 2022
Maintainer Author

Technically I agree but here it is, in use and well. There have been at least two discussions on this here:

kingosticks Jan 10, 2022

The GStreamer backend is a bit upside down. The proper way to integrate Spotify with GStreamer is to have it as a source element, which is what I did.

Certainly if you just want Spotify playback your element looks perfect. For me, a big benefit of gstreamer elements is having them readily available through the system package manager. That benefit isn't applicable (yet.. maybe..) to rust gstreamer elements and building all that is slightly off-putting (enough for me that I still have not gotten around to trying it - sorry!).

If someone wanted to use your element along with Spotify Connect, I think they'd have to go and write a load more code themselves. I'm not sure the librespot API in it's current state would make this easy. It might not even be possible since spirc always requires a Player(?); if true, this is more a problem with librespot API rather than your element. Or do you have ideas how someone might do this?

gdesmott Jan 10, 2022

For me, a big benefit of gstreamer elements is having them readily available through the system package manager. That benefit isn't applicable (yet.. maybe..) to rust gstreamer elements and building all that is slightly off-putting (enough for me that I still have not gotten around to trying it - sorry!).

If your application is in Rust it's actually quite easy to build and statically link the GStreamer element. See for example how I did it here.
This one is even simpler as the element has been released as a crate to crates.io but you can do the same using the git repo.
This still requires having GStreamer's headers libraries installed though.

Or do you have ideas how someone might do this?

I don't have much experience with most of librespot so I can't really say, sorry.

kingosticks Jan 10, 2022

In my specific case it's actually a Python application so sadly not as easy as that.

acid-sun · 2022-01-10T14:43:35Z

acid-sun
Jan 10, 2022

I have playlist, which contains track, which do not have OGG, only AAC_24 and preview MP3_96, all know "Panic! At The Disco - I Write Sins Not Tragedies". At album this track was skiped, but if this track is in playlist app panic.
[2022-01-10T14:32:21Z INFO librespot_playback::player] Loading with Spotify URI spotify:track:5cY8y2XgOfkAh4kSWLFKkz
[2022-01-10T14:32:21Z ERROR librespot_playback::player] is not available in any supported format
[2022-01-10T14:32:21Z ERROR librespot_playback::player] Skipping to next track, unable to load track <SpotifyId("spotify:track:5cY8y2XgOfkAh4kSWLFKkz")>: ()
[2022-01-10T14:32:21Z DEBUG librespot_connect::spirc] Marked <gid: "\253(_/\322\267K\245\232\353\030Xn\271B\233" context: "NonPlayable"> at 7 as NonPlayable
[2022-01-10T14:32:21Z DEBUG librespot_playback::player] command=Preload(SpotifyId("spotify:track:4EUVY2XtbjfGNA13BVlZGF"))
[2022-01-10T14:32:21Z DEBUG librespot_playback::player] Preloading track thread '' panicked at 'Map must not be polled after it returned Poll::Ready', C:\Users\Oleg.cargo\registry\src\github.com-1ecc6299db9ec823\futures-util-0.3.19\src\future\future\map.rs:62:17
stack backtrace:
[2022-01-10T14:32:21Z DEBUG librespot_core::http_client] Requesting https://...
0: 0x13fc8ff2f - std::sys_common::backtrace::_print::impl$0::fmt
at /rustc/f1edd0429582dd29cccacaf50fd134b05593bd9
c/library\std\src\sys_common\backtrace.rs:46
1: 0x13fcaddaa - core::fmt::write
at /rustc/f1edd0429582dd29cccacaf50fd134b05593bd9
c/library\core\src\fmt\mod.rs:1163
2: 0x13fc87c18 - std::io::Write::write_fmt<std::sys::windows::stdio::S
tderr>
at /rustc/f1edd0429582dd29cccacaf50fd134b05593bd9
c/library\std\src\io\mod.rs:1696
3: 0x13fc92d26 - std::panicking::default_hook::closure$1
at /rustc/f1edd0429582dd29cccacaf50fd134b05593bd9
c/library\std\src\panicking.rs:210
4: 0x13fc92727 - std::panicking::default_hook
at /rustc/f1edd0429582dd29cccacaf50fd134b05593bd9
c/library\std\src\panicking.rs:229
5: 0x13fc93385 - std::panicking::rust_panic_with_hook
at /rustc/f1edd0429582dd29cccacaf50fd134b05593bd9
c/library\std\src\panicking.rs:624
6: 0x13f72e395 - std::error::Error::description::h0a0d18df5d7a91d1
7: 0x13f72d627 - std::sys_common::backtrace::__rust_end_short_backtrac
e::hef05e2e013942a1a
8: 0x13fcc5d1d - std::panicking::begin_panic::hb382b5ce01249ebe
9: 0x13f7480f1 - <futures_util::future::future::map::Map<Fut,F> as cor
e::future::future::Future>::poll::h5230a456f2a71e53
10: 0x13f7310fd - <futures_util::future::try_future::MapErr<Fut,F> as c
ore::future::future::Future>::poll::h34a92d7b627bc8fb
11: 0x13f71fe37 - <librespot_playback::player::PlayerInternal as core::
future::future::Future>::poll::he1cea2728931cd1c
12: 0x13f61df09 - tokio::park::thread::CachedParkThread::block_on::hde0
e8836b1d4c158
13: 0x13f63b571 - tokio::runtime::Runtime::block_on::h1c3ff49e75e785a3
14: 0x13f64c050 - std::sys_common::backtrace::__rust_begin_short_backtr
ace::hd2976bb75edb005a
15: 0x13f618a86 - core::num::dec2flt::number::Number::try_fast_path::h4
606dcfdd0bd751f
16: 0x13fc9b06c - std::sys::windows::thread::impl$0::new::thread_start
at /rustc/f1edd0429582dd29cccacaf50fd134b05593bd9
c/library\std\src\sys\windows\thread.rs:58
17: 0x777455dd - BaseThreadInitThunk
18: 0x778a295d - RtlUserThreadStart
[2022-01-10T14:32:22Z DEBUG librespot_playback::player] drop PlayerInternal[0]

After this error, there is no sounds.
[2022-01-10T14:32:29Z ERROR librespot_playback::player] Player Commands Error: channel closed

2 replies

roderickvd Jan 10, 2022
Maintainer Author

Yeah that's one panic I have yet to fix. It occurs when there is only one track in the queue and that track cannot be played. The player then tries to load the same track again, but that already returned Err and cannot be polled again.

Separate from that, loading external MP3's isn't supported yet. It's on the list. Edit: note that this is a preview only. Getting that URL is in spclient already but it's not something librespot-playback will ever use probably. There are quite a few podcasts though that host their shows externally, and those I would like to stream, but the tracks don't seem to be pushed over spirc, and from the context of a show I don't think you can figure out which episode to play.

So these are two issues really.

roderickvd Jan 13, 2022
Maintainer Author

Panic is fixed in e627cb4.

Malvineous · 2022-01-11T03:52:54Z

Malvineous
Jan 11, 2022

Got another crash similar to last time. It looks like when the old API comes up with those channel errors, that's when the new API starts getting weird errors too. Here, I tried to play a song the old API couldn't play, the new API appeared to load it fine but actually it looked like it skipped it. I skipped to the next track (thinking it was playing fine) and it appears my attempt to play the next track while it was already being played caused another crash (possibly, I'm just guessing).

This is the log from the first track which looked like it worked but it didn't:

[2022-01-11T03:41:53Z TRACE librespot_audio::fetch] Streaming from https://audio-ak-spotify-com.akamaized.net/audio/d4cb9741f05522443de3bdac8da46e5b12b7d230?__t
oken__=exp=1641958913~hmac=xxx
[2022-01-11T03:41:54Z DEBUG librespot_audio::fetch::receive] Ping time now estimated as: 767 ms
[2022-01-11T03:41:54Z DEBUG librespot_audio::fetch::receive] Ping time now estimated as: 511 ms
[2022-01-11T03:41:54Z DEBUG librespot_audio::fetch::receive] Streamer expected partial content but got: 502 Bad Gateway
[2022-01-11T03:41:54Z ERROR librespot_audio::fetch::receive] Error from streamer for range 8970728 (+65140): Error { kind: FailedPrecondition, error: StatusCode
(502) }
[2022-01-11T03:41:54Z DEBUG librespot_audio::fetch::receive] Streamer expected partial content but got: 502 Bad Gateway
[2022-01-11T03:41:54Z ERROR librespot_audio::fetch::receive] Error from streamer for range 8970728 (+65140): Error { kind: FailedPrecondition, error: StatusCode(502) }
[2022-01-11T03:41:54Z DEBUG librespot_audio::fetch::receive] Streamer expected partial content but got: 502 Bad Gateway
[2022-01-11T03:41:54Z ERROR librespot_audio::fetch::receive] Error from streamer for range 445383 (+131072): Error { kind: FailedPrecondition, error: StatusCode(502) }
[2022-01-11T03:41:55Z ERROR librespot_playback::player] Unable to read audio file: Symphonia Decoder Error: Deadline expired before operation could complete { wait timeout exceeded }
[2022-01-11T03:41:55Z ERROR librespot_playback::player] Skipping to next track, unable to load track <SpotifyId("spotify:track:0cDzrU9CYuMGdlPGqP9J1M")>: ()
[2022-01-11T03:41:55Z DEBUG librespot_connect::spirc] Marked <gid: "\006\262\230\"\260rG+\2448b\276\301/r\312" context: "NonPlayable"> at 11 as NonPlayable
[2022-01-11T03:41:55Z DEBUG librespot_playback::player] command=Preload(SpotifyId("spotify:track:2ofyE55r1zqwNRl4543fu9"))
[2022-01-11T03:41:55Z DEBUG librespot_playback::player] Preloading track
[2022-01-11T03:41:55Z DEBUG librespot_core::http_client] Requesting https://gae2-spclient.spotify.com:443/metadata/4/track/4e90c3921ed34d8193239af912898e91?product=0
thread '<unnamed>' panicked at 'Map must not be polled after it returned `Poll::Ready`', ~/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-util-0.3.17/src/future/future/map.rs:62:17

At this point I skipped to the next track, which gave normal logs until:

[2022-01-11T03:41:56Z TRACE librespot_metadata::audio::file] Ignoring file <956895f8f8bf6492acda1971baf58c766168650b> with unspecified format
[2022-01-11T03:41:56Z TRACE librespot_metadata::audio::file] Ignoring file <451d2dbad0733bebec90336655b039a4b8ec20e8> with unspecified format
[2022-01-11T03:41:56Z TRACE librespot_metadata::audio::file] Ignoring file <61c91d890b2de1d218c84bc852884473ecf80912> with unspecified format
[2022-01-11T03:41:56Z TRACE librespot_metadata::audio::file] Ignoring file <39e55a2d9006a03052e2bd8cd6a30da24e0aeb3c> with unspecified format
[2022-01-11T03:41:56Z DEBUG librespot_audio::fetch] File 9ac5ec0d43c25797e31540291955de65551cc1ed already in cache
   0:     0x559a59eeb4bc - std::backtrace_rs::backtrace::libunwind::trace::hacbdc529f9249eb6
                               at /rustc/1.57.0/library/std/src/../../backtrace/src/backtrace/libunwind.rs:90:5
   1:     0x559a59eeb4bc - std::backtrace_rs::backtrace::trace_unsynchronized::he82c9103d3c2f8e9
                               at /rustc/1.57.0/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
   2:     0x559a59eeb4bc - std::sys_common::backtrace::_print_fmt::he08f43104cac826b
                               at /rustc/1.57.0/library/std/src/sys_common/backtrace.rs:67:5
   3:     0x559a59eeb4bc - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::h627a8335e7bebb2f
                               at /rustc/1.57.0/library/std/src/sys_common/backtrace.rs:46:22
   4:     0x559a59f11dfc - core::fmt::write::he9d97a03f755e207
                               at /rustc/1.57.0/library/core/src/fmt/mod.rs:1163:17
   5:     0x559a59ee46a5 - std::io::Write::write_fmt::h818ed02cd529ffbf
                               at /rustc/1.57.0/library/std/src/io/mod.rs:1696:15
   6:     0x559a59eed1d0 - std::sys_common::backtrace::_print::hb3813087dcbfdeac
                               at /rustc/1.57.0/library/std/src/sys_common/backtrace.rs:49:5
   7:     0x559a59eed1d0 - std::sys_common::backtrace::print::h7dc7d2e4b731f93c
                               at /rustc/1.57.0/library/std/src/sys_common/backtrace.rs:36:9
   8:     0x559a59eed1d0 - std::panicking::default_hook::{{closure}}::hc97cb1eaecd6020f
                               at /rustc/1.57.0/library/std/src/panicking.rs:210:50
   9:     0x559a59eecd85 - std::panicking::default_hook::h5747255ca2a8355f
                               at /rustc/1.57.0/library/std/src/panicking.rs:227:9
  10:     0x559a59eed884 - std::panicking::rust_panic_with_hook::h51a840d50a086d4c
                               at /rustc/1.57.0/library/std/src/panicking.rs:624:17
  11:     0x559a5971aaa2 - std::panicking::begin_panic::{{closure}}::h38722cf56adaf5ae
                               at /rustc/1.57.0/library/std/src/panicking.rs:544:9
  12:     0x559a5971b359 - std::sys_common::backtrace::__rust_end_short_backtrace::h39840a07c287877b
                               at /rustc/1.57.0/library/std/src/sys_common/backtrace.rs:139:18
  13:     0x559a5971a9e3 - std::panicking::begin_panic::h929b78a6cbeca555
                               at /rustc/1.57.0/library/std/src/panicking.rs:543:12
  14:     0x559a58f32ffc - <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll::h6ecb6060fa32800e
                               at ~/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-util-0.3.17/src/future/future/map.rs:62:17
  15:     0x559a58f31c58 - <futures_util::future::future::Map<Fut,F> as core::future::future::Future>::poll::h75b592dbfef5d2bb
                               at ~/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-util-0.3.17/src/lib.rs:95:13
  16:     0x559a58f1b698 - <futures_util::future::try_future::MapErr<Fut,F> as core::future::future::Future>::poll::h759cd9f045b3e372
                               at ~/.cargo/registry/src/github.com-1ecc6299db9ec823/futures-util-0.3.17/src/lib.rs:95:13
  17:     0x559a58eacb85 - <librespot_playback::player::PlayerInternal as core::future::future::Future>::poll::h92d9f8e1eeb38a9e
                               at /data/code/librespot-newapi/playback/src/player.rs:1030:23
  18:     0x559a58c65c92 - tokio::park::thread::CachedParkThread::block_on::{{closure}}::hdaf9ae600e268d8d
                               at ~/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.14.0/src/park/thread.rs:263:54
  19:     0x559a58c92020 - tokio::coop::with_budget::{{closure}}::hec4ae7eff8189f37
                               at ~/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.14.0/src/coop.rs:106:9
  20:     0x559a58cefcc8 - std::thread::local::LocalKey<T>::try_with::hb07e25fb57e1118f
                               at /rustc/1.57.0/library/std/src/thread/local.rs:399:16
  21:     0x559a58cef19d - std::thread::local::LocalKey<T>::with::h5022e54b091974fe
                               at /rustc/1.57.0/library/std/src/thread/local.rs:375:9
  22:     0x559a58c651b6 - tokio::coop::with_budget::h620e1b9223e1c888
                               at ~/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.14.0/src/coop.rs:99:5
  23:     0x559a58c651b6 - tokio::coop::budget::h99945c0e140fc66b
                               at ~/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.14.0/src/coop.rs:76:5
  24:     0x559a58c651b6 - tokio::park::thread::CachedParkThread::block_on::ha274c14488e2b783
                               at ~/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.14.0/src/park/thread.rs:263:31
  25:     0x559a58ced383 - tokio::runtime::enter::Enter::block_on::hbf6f0acca9ae81f8
                               at ~/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.14.0/src/runtime/enter.rs:151:13
  26:     0x559a58ce0088 - tokio::runtime::thread_pool::ThreadPool::block_on::hb936dea333d8bd47
                               at ~/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.14.0/src/runtime/thread_pool/mod.rs:77:9
  27:     0x559a58c9758d - tokio::runtime::Runtime::block_on::h640b887ada5fe50d
                               at ~/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-1.14.0/src/runtime/mod.rs:463:43
  28:     0x559a58cc1716 - librespot_playback::player::Player::new::{{closure}}::h4e769252dd5f6d7a
                               at /data/code/librespot-newapi/playback/src/player.rs:386:13
  29:     0x559a58c82de3 - std::sys_common::backtrace::__rust_begin_short_backtrace::h1337c644ab97e3f0
                               at /rustc/1.57.0/library/std/src/sys_common/backtrace.rs:123:18
  30:     0x559a58c83b0f - std::thread::Builder::spawn_unchecked::{{closure}}::{{closure}}::hcacecabdfc925fb0
                               at /rustc/1.57.0/library/std/src/thread/mod.rs:483:17
  31:     0x559a58c72313 - <core::panic::unwind_safe::AssertUnwindSafe<F> as core::ops::function::FnOnce<()>>::call_once::h79c6631ae30d4a48
                               at /rustc/1.57.0/library/core/src/panic/unwind_safe.rs:271:9
  32:     0x559a58c949d0 - std::panicking::try::do_call::h02bebc9359a586dc
                               at /rustc/1.57.0/library/std/src/panicking.rs:403:40
  33:     0x559a58c9719b - __rust_try
  34:     0x559a58c92547 - std::panicking::try::h0fad0e26cea00549
                               at /rustc/1.57.0/library/std/src/panicking.rs:367:19
  35:     0x559a58cadf13 - std::panic::catch_unwind::h6a311e05eed72018
                               at /rustc/1.57.0/library/std/src/panic.rs:133:14
  36:     0x559a58c838af - std::thread::Builder::spawn_unchecked::{{closure}}::hd80051e9d876ac68
                               at /rustc/1.57.0/library/std/src/thread/mod.rs:482:30
  37:     0x559a58c74a6e - core::ops::function::FnOnce::call_once{{vtable.shim}}::h87577c585bc1786a
                               at /rustc/1.57.0/library/core/src/ops/function.rs:227:5
  38:     0x559a59ef2da3 - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::h557b09f8abc0f6de
                               at /rustc/1.57.0/library/alloc/src/boxed.rs:1691:9
  39:     0x559a59ef2da3 - <alloc::boxed::Box<F,A> as core::ops::function::FnOnce<Args>>::call_once::h3924c8cb9f0692ee
                               at /rustc/1.57.0/library/alloc/src/boxed.rs:1691:9
  40:     0x559a59ef2da3 - std::sys::unix::thread::Thread::new::thread_start::h1e947f390c6c05e3
                               at /rustc/1.57.0/library/std/src/sys/unix/thread.rs:106:17
  41:     0x7f3dc7250259 - start_thread
  42:     0x7f3dc702c5e3 - __GI___clone
  43:                0x0 - <unknown>
[2022-01-11T03:41:56Z DEBUG librespot_playback::player] drop PlayerInternal[0]
[2022-01-11T03:41:56Z INFO  librespot_playback::player] <Sorry> (190453 ms) loaded

I'm not sure whether this is two different crashes or whether it's one "panic" but the backtrace ends up being displayed much later in the logs. Either way the player buttons got disabled in the web player and I had to terminate librespot to get things working again.

2 replies

roderickvd Jan 12, 2022
Maintainer Author

Thanks, that's good info. It does seem like if you're in a region with Mercury errors, the CDN will fail too. Perhaps even Akamai is just a front to Spotify's own servers. Anyway I will make it so that:
a) the streamer bails out on anything but a partial content response
b) that reloading error is gracefully handled (it tries to again load a track that gave an error before, but is still preloaded)

roderickvd Jan 13, 2022
Maintainer Author

Should be gracefully handled now by 8d8d6d4, ab67370 and e627cb4.

roderickvd · 2022-01-16T00:21:08Z

roderickvd
Jan 16, 2022
Maintainer Author

abbc3ba made it so the message listeners can be installed before connection. Previously there was a race condition where it was possible that messages arrived in the meantime. These messages are becoming increasingly important and looking ahead even more so with the dealer, so this was important plumbing.

Previously you called Session::connect(credentials) to set up the connection and do the authentication. Then you would create do Spirc::new(session). This is now changed to first create a Session::new (that performs no network operations), then create a Spirc::new(session, credentials). That will automatically call Session::connect(credentials).

0 replies

AbhayAysola · 2022-01-20T15:44:07Z

AbhayAysola
Jan 20, 2022

Remove unsafe code

The only instances of unsafe code are the 2 calls to String::from_utf8_unchecked. There is a safe version of this but has some extra overhead due to checking if the bytes are valid utf8. So either we use the safe version - String::from_utf8 and have the extra overhead, or we keep the unsafe code.

27 replies

JasonLG1979 Jan 22, 2022

If you did:

pipeline.add_filter(a);
pipeline.add_filter(b);
pipeline.add_filter(c);

and then iterated over filter they would maintain their order.

roderickvd Jan 22, 2022
Maintainer Author

In my mind really normalisation and volume could also be combined as basically volume sort of functions as the make up gain of the normalizer (although it's never a boast).

You could, but:
a) not everyone uses normalisation;
b) not everyone uses dynamic normalisation;
c) the dynamic normalisation make-up gain is expected in dB.

So basically it would go Pipeline[ [ [Dynamics -> Volume] ] -> [ [Converter -> Dither] ] -> [Sink] ]

I'm not sure about that syntax, and the definition of "dynamics" and "converter".

They would be processed in the order in which you added the filter.

Right I was thinking of a HashMap, never mind.

JasonLG1979 Jan 22, 2022

a) not everyone uses normalisation;

Then Dynamics would be a noop inside the [Dynamics -> Volume] element.

b) not everyone uses dynamic normalisation;

"Dynamics" in this case means gain adjustments either via basic or dynamic limiting. "Dynamics" may not be the right word you can substitute normalisation. If you think about it an oversimplified explanation of a compressor/limiter is basically turning the volume up and down really fast in response to the incoming signal level. Basic normalization is that but just static throughout the song and a volume knob is still very much the same except even more static. They all alter the signal level.

c) the dynamic normalisation make-up gain is expected in dB.

That really doesn't matter at all. The make up gain is applied after the compression stage calling it makeup gain or volume in our case it's still the same thing except that volume can never be a boast ofc. Again maybe I have confused you with the terms. Again my point is that normalization and volume vary the signal level so they do very similar things.

roderickvd Jan 22, 2022
Maintainer Author

c) the dynamic normalisation make-up gain is expected in dB.

That really doesn't matter at all. The make up gain is applied after the compression stage calling it makeup gain or volume in our case it's still the same thing except that volume can never be a boast ofc. Again maybe I have confused you with the terms.

Yes this may be definitions. The "make-up gain" has a pretty specific position in the new dynamic limiter. And since you were using that wording, I thought you were referring to that (step 6 I believe).

Again my point is that normalization and volume vary the signal level so they do very similar things.

Sure. But what it'll look like in code depends on how you mix in the mixer (pretty bad, I know).

JasonLG1979 Jan 22, 2022

Sure. But what it'll look like in code depends on how you mix in the mixer (pretty bad, I know).

A hardware volume control would be a noop as far as sample manipulation but would instead tickle alsa,lol!!!.

The idea of arbitrary Filters is starting to fall apart though... From the outside of the Pipeline it wouldn't matter. The Pipeline would have functions/methods for getting and setting the volume and would handle the internals as a matter of implementation details.

roderickvd · 2022-01-22T22:22:55Z

roderickvd
Jan 22, 2022
Maintainer Author

Could you guys help me out? I'm trying to port the client-token retrieval from librespot-org/librespot-java@08b7890 but it doesn't work. I must be overlooking something in 1528292. Every request returns HTTP 400.

3 replies

roderickvd Jan 22, 2022
Maintainer Author

Never mind, got it! I should have written the protobuf in bytes of course and not as a text representation 🤦‍♂️

SuisChan Jan 22, 2022

Also if you are trying to get the client-token with challenges then suffix should be sent in uppercase or again HTTP Error 400

roderickvd Jan 22, 2022
Maintainer Author

Fixed in 4ea1b77 and also implemented expiry.

JasonLG1979 · 2022-01-23T05:03:59Z

JasonLG1979
Jan 23, 2022

@roderickvd is it still the plan to remove the basic normalisation mode? It's had a depreciation warning since 0e9fdbe

If so I can remove it. If not I can remove the depreciation warning.

1 reply

roderickvd Jan 23, 2022
Maintainer Author

I want to leave it around a little bit longer, so people learn to love the new dynamic limiter. Then we can remove it. The deprecation warning can stay.

Malvineous · 2022-01-24T02:46:36Z

Malvineous
Jan 24, 2022

Any chance these messages could be converted from an array of ASCII codes to strings? It makes it a bit harder to figure out what went wrong when you only see the ASCII codes. I converted them back to a string and it's just JSON data, so having the debug message print JSON would be helpful for debugging:

[2022-01-24T02:41:17Z ERROR librespot_core::session] could not dispatch command: Service unavailable { error handling Mercury response: MercuryResponse { uri: "social-connect/v2/session_update", status_code: 200, payload: [[123, 34, 115, 101, 115, 115, 105, 111, 110, 34, 58, 123, 34, 116, 105, ...

3 replies

roderickvd Jan 24, 2022
Maintainer Author

Believe me I tried last week and I spent almost two evenings before discarding it. Point is, sometimes it's JSON, sometimes it's a UTF8, sometimes it's a protobuf, sometime's it's a nested protobuf... I thought the same but implementing it is a pain.

Malvineous Jan 24, 2022

Ah right fair enough. Is it too hard to treat it as ASCII and blank out any characters < 32 or > 126? Maybe it's not worth it, looking more closely the old API also can't handle the messages either and they don't look particularly relevant.

roderickvd Jan 24, 2022
Maintainer Author

Feel free if you want to give it a shot. Doing that will print misleading lines for protobufs.

Malvineous · 2022-01-24T03:04:22Z

Malvineous
Jan 24, 2022

Getting those channel errors again. Previously the new API has been able to download the files anyway, but today it can't.

[2022-01-24T02:51:30Z TRACE librespot_audio::fetch] Streaming from https://audio-ak-spotify-com.akamaized.net/audio/1eb087a66073405cca4f2f15afe6de02a1eea480?__token__=exp=1643079090~hmac=xxx
[2022-01-24T02:51:31Z DEBUG librespot_audio::fetch::receive] Ping time now estimated as: 1051 ms
[2022-01-24T02:51:31Z DEBUG librespot_audio::fetch::receive] Ping time now estimated as: 646 ms
[2022-01-24T02:51:31Z ERROR librespot_audio::fetch::receive] Streamer error requesting range 2415324 +65140: Error { kind: FailedPrecondition, error: StatusCode(502) }
[2022-01-24T02:51:31Z ERROR librespot_audio::fetch::receive] Streamer error requesting range 2415324 +65140: Error { kind: FailedPrecondition, error: StatusCode(502) }
[2022-01-24T02:51:32Z DEBUG librespot_core::session] Session strong=8 weak=7
[2022-01-24T02:51:32Z ERROR librespot_audio::fetch::receive] Streamer error requesting range 2415324 +65140: Error { kind: FailedPrecondition, error: StatusCode(502) }
[2022-01-24T02:51:32Z ERROR librespot_audio::fetch::receive] Streamer error requesting range 2415324 +65140: Error { kind: FailedPrecondition, error: StatusCode(502) }
[2022-01-24T02:51:32Z ERROR librespot_audio::fetch::receive] Streamer error requesting range 823857 +131072: Error { kind: FailedPrecondition, error: StatusCode(502) }
[2022-01-24T02:51:48Z ERROR librespot_playback::player] Unable to read audio file: Symphonia Decoder Error: Deadline expired before operation could complete { wait timeout exceeded }
[2022-01-24T02:51:48Z ERROR librespot_playback::player] Skipping to next track, unable to load track <SpotifyId("spotify:track:5WbcLrD3XG9UlLRHhW0Pzt")>: ()   
[2022-01-24T02:51:48Z DEBUG librespot_connect::spirc] Marked <gid: "\303\035\373\221\274;O\026\255\257\236\266\240\353\371#" context: "NonPlayable"> at 16 as NonPlayable
[2022-01-24T02:51:48Z DEBUG librespot_playback::player] command=Preload(SpotifyId("spotify:track:6rBX5GMyHshDqu1c7fTocQ"))
[2022-01-24T02:51:48Z DEBUG librespot_playback::player] Preloading track
...
[2022-01-24T02:51:49Z TRACE librespot_audio::fetch] Streaming from https://audio-ak-spotify-com.akamaized.net/audio/ef98ab85fa8d7bf4f1b464d107bb065b213465d8?__token__=exp=1643079108~hmac=xxx
[2022-01-24T02:51:50Z DEBUG librespot_audio::fetch::receive] Ping time now estimated as: 1088 ms
[2022-01-24T02:51:50Z DEBUG librespot_audio::fetch::receive] Ping time now estimated as: 636 ms
[2022-01-24T02:51:50Z ERROR librespot_audio::fetch::receive] Streamer error requesting range 4859040 +65140: Error { kind: FailedPrecondition, error: StatusCode(502) }
[2022-01-24T02:51:50Z ERROR librespot_audio::fetch::receive] Streamer error requesting range 576864 +4: Error { kind: FailedPrecondition, error: StatusCode(502) }
[2022-01-24T02:51:50Z ERROR librespot_audio::fetch::receive] Streamer error requesting range 576864 +131072: Error { kind: FailedPrecondition, error: StatusCode(502) }
[2022-01-24T02:51:50Z ERROR librespot_audio::fetch::receive] Streamer error requesting range 4859040 +65140: Error { kind: FailedPrecondition, error: StatusCode(502) }
[2022-01-24T02:52:06Z ERROR librespot_playback::player] Unable to read audio file: Symphonia Decoder Error: Deadline expired before operation could complete { wait timeout exceeded }
[2022-01-24T02:52:06Z DEBUG librespot_playback::player] Unable to preload SpotifyId("spotify:track:6rBX5GMyHshDqu1c7fTocQ")

$ ping 8.8.8.8
PING 8.8.8.8 (8.8.8.8) 56(84) bytes of data.
64 bytes from 8.8.8.8: icmp_seq=1 ttl=118 time=20.5 ms
64 bytes from 8.8.8.8: icmp_seq=2 ttl=118 time=21.0 ms
64 bytes from 8.8.8.8: icmp_seq=3 ttl=118 time=20.1 ms
64 bytes from 8.8.8.8: icmp_seq=4 ttl=118 time=19.5 ms

$ ping ap-gae2.spotify.com
PING ap-gae2.spotify.com (104.199.240.237) 56(84) bytes of data.
64 bytes from 237.240.199.104.bc.googleusercontent.com (104.199.240.237): icmp_seq=1 ttl=57 time=165 ms
64 bytes from 237.240.199.104.bc.googleusercontent.com (104.199.240.237): icmp_seq=2 ttl=57 time=163 ms
64 bytes from 237.240.199.104.bc.googleusercontent.com (104.199.240.237): icmp_seq=3 ttl=57 time=168 ms
64 bytes from 237.240.199.104.bc.googleusercontent.com (104.199.240.237): icmp_seq=4 ttl=57 time=165 ms

Unfortunately in this case it locks up the web player too, with all the controls disabled:

And the current track, normally highlighted in green, disappears so you don't know where you're up to. It doesn't appear to try to advance to the next track, and it looks like perhaps preloading the next track might be interfering with this.

I've noticed that the new API always tends to disable the playback controls while it's loading the next track, so as you move between tracks the buttons grey out in between tracks, and the green song in the playlist disappears (but then returns when playback starts). The old API used to jump straight to the next track without hiding it, and without disabling the buttons so if it got stuck you could still skip to the next track.

11 replies

kingosticks Jan 25, 2022

You could try doing a (large) Range request with wget to see if the data rate is any slower. Could it be possible that non-range requests are being served out of a cache? Are you able to more closely compare the two types of response?

roderickvd Jan 25, 2022
Maintainer Author

Additionally: I did some digging around the hyper code and see that the initial window sizes are set to 64 kB: https://github.com/hyperium/hyper/blob/f1b89c117cffebed4b2b8eb2d221fd9b25c1d3d1/src/proto/h2/mod.rs#L30. Enabling HTTP/2 adaptive windows makes this value vary by flow control.

You may experiment this by trying some builder options in http_client.rs (like the adaptive window line I described in my previous comment). Documentation is here. Of particular note are:

http1_max_buf_size (400 kB by default)
http2_initial_connection_window_size
http2_initial_stream_window_size
http2_max_frame_size

Note that you must remove http2_adaptive_window(true) for the other HTTP/2 settings to take effect (they overrule each other).

Let me know what you find out!

roderickvd Feb 13, 2022
Maintainer Author

Have you been able to make progress on this?

roderickvd May 21, 2022
Maintainer Author

Sorry I haven't heard from your investigations, they would have been very useful.

As this discussion is somewhat as a notepad to myself and hopefully others who will join the fray, I wanted to add something we spoke about earlier in this thread: the controls becoming inaccessible during a load. In recent iOS app versions I have seen that this leads to incorrect behaviour when the playback screen is minimised (i.e. when you are browsing the Spotify catalogue while you have the playback bar in the bottom of the screen). In this case the bar disappears and re-appears on every load and that is not how it should be.

We may have to revert parts of the librespot code that kept the playback controls alive, but I removed because they caused the thread to panic. We should put that code back in (though hopefully in a bit nicer form) and find a way to better deal with the panics. In new-api, librespot will recover from the panics but it's ugly as heck to see these panics in the log just because of pushing the "next" button while loading. I'm talking about the notify function in spirc.rs -- just compare what's now in 0.4.0 and new-api and you'll see what I mean.

Malvineous May 22, 2022

Sorry for the lack of response, I haven't had a chance to spend time investigating further. After setting the initial chunk time to 256 MB everything has been working pretty well. The buttons grey out for a second or so when skipping songs too quickly or jumping to another point in the playlist but it's no big deal, and I haven't run into any other issues.

I'm not familiar enough with the internals to know how to address the disabled controls. Since they are only disabled between starting playback and the first chunk being available, is it possible to tie it into the playback state rather than the actual audio playback, so that they can become enabled while the first chunk is downloading?

The old API used to do this, but a side effect was that the song would start playing, the playback time would start incrementing, then a few seconds later it would jump back to 0:00 and audio would start.

So if you do figure out a way to enable the controls, it might look a bit weird on slower connections if the song starts "playing" with no sound, then shortly afterwards jumps back to 0:00 when it finally does start playing.

Malvineous · 2022-01-25T18:44:00Z

Malvineous
Jan 25, 2022

I've been doing a bit more in-depth experimentation and found another issue, this time with metadata.

If I try to retrieve the album metadata (e.g. via metadata::Album::get()) then it works fine for most albums, but for some (like https://open.spotify.com/album/67oWpbbiJmI38ps3SLi0GN) it fails with this error:

Operation attempted past the valid range { month must be in the range 1..=12 }

This works with the old API. Looking more closely, it seems this album's metadata only has a year, but no month or day. The old API was able to supply the album's release date as just a year, whereas the new metadata changes appear to make the month and day mandatory, so the function fails completely when the month and/or day are missing from the album release date.

2 replies

roderickvd Jan 25, 2022
Maintainer Author

Please refer to #943. I'll push a fix in a few minutes.

Malvineous Jan 26, 2022

That did the trick, thanks for the quick fix!

roderickvd · 2022-01-25T21:56:48Z

roderickvd
Jan 25, 2022
Maintainer Author

31c6824 adds server key verification to prevent man-in-the-middle attacks and interception of credentials. Something librespot-java already had in 2019, so about time!

0 replies

Malvineous · 2022-01-26T04:55:31Z

Malvineous
Jan 26, 2022

I see the new API has changed the behaviour after reaching the end of the last track in a playlist. With the old API, when it got to the end of the playlist it would just stop, which was great for starting some music when you went to bed, knowing it would stop after you had gone to sleep. But with the new API once it gets to the end of the playlist it starts playing random songs forever, so you eventually get woken up again by some song you don't recognise.

I've also noticed that if you start a long playlist, after the 81st song it forgets about the playlist and starts playing random songs too. The old API used to just stop after song 81, which I think is because when you start a playlist, you only get told about the first 81 songs, and librespot doesn't request the next lot of songs in the playlist when it gets to the last one in the subset.

Assuming there are no plans to support playlists longer than 81 songs, is there a way to restore the old behaviour so that after the end of the playlist, playback just stops? I've had a look at the command line options and while there are options for things like disabling gapless playback, I couldn't see anything that seemed related to this.

I figure this is related to #434 but I mention it here as the switch to playing random songs seems to be new behaviour in this branch.

2 replies

roderickvd Jan 26, 2022
Maintainer Author

I see the new API has changed the behaviour after reaching the end of the last track in a playlist. With the old API, when it got to the end of the playlist it would just stop, which was great for starting some music when you went to bed, knowing it would stop after you had gone to sleep. But with the new API once it gets to the end of the playlist it starts playing random songs forever, so you eventually get woken up again by some song you don't recognise.

You probably have autoplay enabled in your Spotify client? We now follow the client setting; there is no --autoplay command-line option anymore. Just disable that in your client.

I've also noticed that if you start a long playlist, after the 81st song it forgets about the playlist and starts playing random songs too. The old API used to just stop after song 81, which I think is because when you start a playlist, you only get told about the first 81 songs, and librespot doesn't request the next lot of songs in the playlist when it gets to the last one in the subset.

Is this the same you describe in your first paragraph or do you mean something different?

I figure this is related to #434 but I mention it here as the switch to playing random songs seems to be new behaviour in this branch.

I'm not sure if it's the same. That issue concerns the point that with the current API, we are only told about the last 10 or 20 songs of a playlist when you don't start the playlist on track number 1.

Malvineous May 22, 2022

I meant to reply to this one too. I'm not sure what you mean by disabling autoplay in the client. I'm using the web player and there doesn't seem to be any autoplay related option there.

It appears to be an ongoing source of complaints, with librespot being the only client that (used to) let you disable autoplay:

That last one seems to hint that they were supposed to add the ability to turn off autoplay via the web player six months ago but it still doesn't seem to have been implemented, so it would be great if it could be overridden in the client, otherwise there's no way to get it to stop playing at the end of a playlist.

Is this the same you describe in your first paragraph or do you mean something different?

What happens is that when librespot runs out of songs, it starts playing random ones. It can run out of songs in two ways, one is by getting to the end of a playlist, and another is by getting to song 81 in a large playlist (when started at song 1), since librespot doesn't request more tracks after the initial 81. (Same issue if you start play back at song 20, it only gets as far as song 101, starting at 100 it only goes to song 181, etc.)

Only the second one (stopping after 81 songs) is an unrelated "issue", however the end result is the same - librespot continues to play random songs instead of just stopping and remaining silent, with the issue here being there is no way to tell it to just stop like it used to, when you don't want random songs playing forever.

If that 81-song issue was fixed, that would be great, but once it got to the true end of the playlist you'd still want a way to just stop in silence instead of switching to random songs.

acid-sun · 2022-02-12T19:40:48Z

acid-sun
Feb 12, 2022

The track is interrupted quite often. I noticed that this happens until the track is downloaded. Here is the log:

[2022-02-12T19:14:32Z TRACE librespot_audio::fetch] Streaming from https://audio-fa.scdn.co/audio/23cc19dfb217fcaebc2cd63ebdace8820b1f6661?1644779672_-w2Kl72Rmu72ZiC80NWVqhW-uhoOal0EHEUyWQ733n0=
[2022-02-12T19:14:32Z DEBUG librespot_core::mercury] unknown subscription uri=social-connect/v2/session_update
[2022-02-12T19:14:32Z TRACE librespot_core::mercury] response pushed over Mercury: MercuryResponse { uri: "social-connect/v2/session_update", status_code: 200, payload: [[123, 34, 115, 101, 115, 115, 105, 111, 110, 34, 58, 123, 34, 116, 105, 109, 101, 115, 116, 97, 109, 112, 34, 58, 34, 49, 54, 52, 52, 54, 57, 51, 50, 55, 50, 54, 55, 50, 34, 44, 34, 115, 101, 115, 115, 105, 111, 110, 95, 105, 100, 34, 58, 34, 99, 101, 101, 98, 54, 54, 99, 98, 57, 56, 51, 102, 50, 53, 99, 49, 55, 50, 57, 100, 55, 52, 102, 55, 53, 98, 48, 99, 53, 49, 102, 54, 34, 44, 34, 106, 111, 105, 110, 95, 115, 101, 115, 115, 105, 111, 110, 95, 116, 111, 107, 101, 110, 34, 58, 34, 54, 50, 74, 101, 119, 98, 69, 57, 84, 88, 55, 108, 116, 67, 103, 68, 108, 51, 65, 104, 82, 103, 55, 70, 112, 53, 75, 113, 80, 53, 119, 115, 74, 78, 106, 114, 105, 80, 90, 78, 49, 88, 102, 73, 101, 119, 90, 112, 49, 55, 72, 87, 82, 111, 121, 87, 111, 68, 53, 90, 99, 97, 88, 103, 98, 67, 108, 119, 67, 76, 82, 57, 73, 108, 105, 80, 97, 80, 117, 48, 110, 81, 84, 52, 67, 89, 81, 100, 122, 90, 49, 50, 111, 86, 88, 70, 100, 87, 112, 66, 103, 101, 81, 49, 104, 120, 108, 97, 34, 44, 34, 106, 111, 105, 110, 95, 115, 101, 115, 115, 105, 111, 110, 95, 117, 114, 108, 34, 58, 34, 104, 109, 58, 47, 47, 115, 111, 99, 105, 97, 108, 45, 99, 111, 110, 110, 101, 99, 116, 47, 118, 50, 47, 115, 101, 115, 115, 105, 111, 110, 115, 47, 106, 111, 105, 110, 47, 54, 50, 74, 101, 119, 98, 69, 57, 84, 88, 55, 108, 116, 67, 103, 68, 108, 51, 65, 104, 82, 103, 55, 70, 112, 53, 75, 113, 80, 53, 119, 115, 74, 78, 106, 114, 105, 80, 90, 78, 49, 88, 102, 73, 101, 119, 90, 112, 49, 55, 72, 87, 82, 111, 121, 87, 111, 68, 53, 90, 99, 97, 88, 103, 98, 67, 108, 119, 67, 76, 82, 57, 73, 108, 105, 80, 97, 80, 117, 48, 110, 81, 84, 52, 67, 89, 81, 100, 122, 90, 49, 50, 111, 86, 88, 70, 100, 87, 112, 66, 103, 101, 81, 49, 104, 120, 108, 97, 34, 44, 34, 115, 101, 115, 115, 105, 111, 110, 95, 111, 119, 110, 101, 114, 95, 105, 100, 34, 58, 34, 55, 56, 56, 99, 102, 51, 102, 52, 51, 57, 101, 102, 51, 50, 48, 52, 98, 102, 57, 98, 97, 51, 51, 99, 50, 99, 55, 57, 99, 99, 54, 55, 34, 44, 34, 115, 101, 115, 115, 105, 111, 110, 95, 109, 101, 109, 98, 101, 114, 115, 34, 58, 91, 123, 34, 106, 111, 105, 110, 101, 100, 95, 116, 105, 109, 101, 115, 116, 97, 109, 112, 34, 58, 34, 49, 54, 52, 52, 54, 57, 51, 50, 55, 50, 54, 53, 52, 34, 44, 34, 105, 100, 34, 58, 34, 55, 56, 56, 99, 102, 51, 102, 52, 51, 57, 101, 102, 51, 50, 48, 52, 98, 102, 57, 98, 97, 51, 51, 99, 50, 99, 55, 57, 99, 99, 54, 55, 34, 44, 34, 117, 115, 101, 114, 110, 97, 109, 101, 34, 58, 34, 54, 54, 48, 109, 121, 119, 107, 49, 112, 111, 116, 57, 119, 105, 114, 122, 110, 120, 98, 112, 104, 54, 108, 112, 99, 34, 44, 34, 100, 105, 115, 112, 108, 97, 121, 95, 110, 97, 109, 101, 34, 58, 34, 65, 99, 105, 68, 32, 83, 117, 78, 34, 44, 34, 105, 115, 95, 108, 105, 115, 116, 101, 110, 105, 110, 103, 34, 58, 116, 114, 117, 101, 44, 34, 105, 115, 95, 99, 111, 110, 116, 114, 111, 108, 108, 105, 110, 103, 34, 58, 116, 114, 117, 101, 125, 93, 44, 34, 106, 111, 105, 110, 95, 115, 101, 115, 115, 105, 111, 110, 95, 117, 114, 105, 34, 58, 34, 115, 112, 111, 116, 105, 102, 121, 58, 115, 111, 99, 105, 97, 108, 115, 101, 115, 115, 105, 111, 110, 58, 54, 50, 74, 101, 119, 98, 69, 57, 84, 88, 55, 108, 116, 67, 103, 68, 108, 51, 65, 104, 82, 103, 55, 70, 112, 53, 75, 113, 80, 53, 119, 115, 74, 78, 106, 114, 105, 80, 90, 78, 49, 88, 102, 73, 101, 119, 90, 112, 49, 55, 72, 87, 82, 111, 121, 87, 111, 68, 53, 90, 99, 97, 88, 103, 98, 67, 108, 119, 67, 76, 82, 57, 73, 108, 105, 80, 97, 80, 117, 48, 110, 81, 84, 52, 67, 89, 81, 100, 122, 90, 49, 50, 111, 86, 88, 70, 100, 87, 112, 66, 103, 101, 81, 49, 104, 120, 108, 97, 34, 44, 34, 105, 115, 95, 115, 101, 115, 115, 105, 111, 110, 95, 111, 119, 110, 101, 114, 34, 58, 116, 114, 117, 101, 44, 34, 105, 115, 95, 108, 105, 115, 116, 101, 110, 105, 110, 103, 34, 58, 116, 114, 117, 101, 44, 34, 105, 115, 95, 99, 111, 110, 116, 114, 111, 108, 108, 105, 110, 103, 34, 58, 116, 114, 117, 101, 44, 34, 105, 110, 105, 116, 105, 97, 108, 83, 101, 115, 115, 105, 111, 110, 84, 121, 112, 101, 34, 58, 34, 73, 78, 95, 80, 69, 82, 83, 79, 78, 34, 44, 34, 104, 111, 115, 116, 65, 99, 116, 105, 118, 101, 68, 101, 118, 105, 99, 101, 73, 100, 34, 58, 34, 99, 48, 99, 99, 101, 54, 56, 50, 56, 52, 53, 97, 101, 49, 52, 49, 100, 52, 99, 99, 52, 98, 98, 102, 49, 49, 49, 98, 102, 48, 51, 51, 101, 98, 51, 48, 100, 102, 101, 49, 34, 44, 34, 109, 97, 120, 77, 101, 109, 98, 101, 114, 67, 111, 117, 110, 116, 34, 58, 56, 125, 44, 34, 114, 101, 97, 115, 111, 110, 34, 58, 34, 78, 69, 87, 95, 83, 69, 83, 83, 73, 79, 78, 34, 44, 34, 117, 112, 100, 97, 116, 101, 95, 115, 101, 115, 115, 105, 111, 110, 95, 109, 101, 109, 98, 101, 114, 115, 34, 58, 91, 123, 34, 106, 111, 105, 110, 101, 100, 95, 116, 105, 109, 101, 115, 116, 97, 109, 112, 34, 58, 34, 49, 54, 52, 52, 54, 57, 51, 50, 55, 50, 54, 53, 52, 34, 44, 34, 105, 100, 34, 58, 34, 55, 56, 56, 99, 102, 51, 102, 52, 51, 57, 101, 102, 51, 50, 48, 52, 98, 102, 57, 98, 97, 51, 51, 99, 50, 99, 55, 57, 99, 99, 54, 55, 34, 44, 34, 117, 115, 101, 114, 110, 97, 109, 101, 34, 58, 34, 54, 54, 48, 109, 121, 119, 107, 49, 112, 111, 116, 57, 119, 105, 114, 122, 110, 120, 98, 112, 104, 54, 108, 112, 99, 34, 44, 34, 100, 105, 115, 112, 108, 97, 121, 95, 110, 97, 109, 101, 34, 58, 34, 65, 99, 105, 68, 32, 83, 117, 78, 34, 44, 34, 105, 115, 95, 108, 105, 115, 116, 101, 110, 105, 110, 103, 34, 58, 116, 114, 117, 101, 44, 34, 105, 115, 95, 99, 111, 110, 116, 114, 111, 108, 108, 105, 110, 103, 34, 58, 116, 114, 117, 101, 125, 93, 125]] }
[2022-02-12T19:14:32Z ERROR librespot_core::session] could not dispatch command: Service unavailable { error handling Mercury response: MercuryResponse { uri: "social-connect/v2/session_update", status_code: 200, payload: [[123, 34, 115, 101, 115, 115, 105, 111, 110, 34, 58, 123, 34, 116, 105, 109, 101, 115, 116, 97, 109, 112, 34, 58, 34, 49, 54, 52, 52, 54, 57, 51, 50, 55, 50, 54, 55, 50, 34, 44, 34, 115, 101, 115, 115, 105, 111, 110, 95, 105, 100, 34, 58, 34, 99, 101, 101, 98, 54, 54, 99, 98, 57, 56, 51, 102, 50, 53, 99, 49, 55, 50, 57, 100, 55, 52, 102, 55, 53, 98, 48, 99, 53, 49, 102, 54, 34, 44, 34, 106, 111, 105, 110, 95, 115, 101, 115, 115, 105, 111, 110, 95, 116, 111, 107, 101, 110, 34, 58, 34, 54, 50, 74, 101, 119, 98, 69, 57, 84, 88, 55, 108, 116, 67, 103, 68, 108, 51, 65, 104, 82, 103, 55, 70, 112, 53, 75, 113, 80, 53, 119, 115, 74, 78, 106, 114, 105, 80, 90, 78, 49, 88, 102, 73, 101, 119, 90, 112, 49, 55, 72, 87, 82, 111, 121, 87, 111, 68, 53, 90, 99, 97, 88, 103, 98, 67, 108, 119, 67, 76, 82, 57, 73, 108, 105, 80, 97, 80, 117, 48, 110, 81, 84, 52, 67, 89, 81, 100, 122, 90, 49, 50, 111, 86, 88, 70, 100, 87, 112, 66, 103, 101, 81, 49, 104, 120, 108, 97, 34, 44, 34, 106, 111, 105, 110, 95, 115, 101, 115, 115, 105, 111, 110, 95, 117, 114, 108, 34, 58, 34, 104, 109, 58, 47, 47, 115, 111, 99, 105, 97, 108, 45, 99, 111, 110, 110, 101, 99, 116, 47, 118, 50, 47, 115, 101, 115, 115, 105, 111, 110, 115, 47, 106, 111, 105, 110, 47, 54, 50, 74, 101, 119, 98, 69, 57, 84, 88, 55, 108, 116, 67, 103, 68, 108, 51, 65, 104, 82, 103, 55, 70, 112, 53, 75, 113, 80, 53, 119, 115, 74, 78, 106, 114, 105, 80, 90, 78, 49, 88, 102, 73, 101, 119, 90, 112, 49, 55, 72, 87, 82, 111, 121, 87, 111, 68, 53, 90, 99, 97, 88, 103, 98, 67, 108, 119, 67, 76, 82, 57, 73, 108, 105, 80, 97, 80, 117, 48, 110, 81, 84, 52, 67, 89, 81, 100, 122, 90, 49, 50, 111, 86, 88, 70, 100, 87, 112, 66, 103, 101, 81, 49, 104, 120, 108, 97, 34, 44, 34, 115, 101, 115, 115, 105, 111, 110, 95, 111, 119, 110, 101, 114, 95, 105, 100, 34, 58, 34, 55, 56, 56, 99, 102, 51, 102, 52, 51, 57, 101, 102, 51, 50, 48, 52, 98, 102, 57, 98, 97, 51, 51, 99, 50, 99, 55, 57, 99, 99, 54, 55, 34, 44, 34, 115, 101, 115, 115, 105, 111, 110, 95, 109, 101, 109, 98, 101, 114, 115, 34, 58, 91, 123, 34, 106, 111, 105, 110, 101, 100, 95, 116, 105, 109, 101, 115, 116, 97, 109, 112, 34, 58, 34, 49, 54, 52, 52, 54, 57, 51, 50, 55, 50, 54, 53, 52, 34, 44, 34, 105, 100, 34, 58, 34, 55, 56, 56, 99, 102, 51, 102, 52, 51, 57, 101, 102, 51, 50, 48, 52, 98, 102, 57, 98, 97, 51, 51, 99, 50, 99, 55, 57, 99, 99, 54, 55, 34, 44, 34, 117, 115, 101, 114, 110, 97, 109, 101, 34, 58, 34, 54, 54, 48, 109, 121, 119, 107, 49, 112, 111, 116, 57, 119, 105, 114, 122, 110, 120, 98, 112, 104, 54, 108, 112, 99, 34, 44, 34, 100, 105, 115, 112, 108, 97, 121, 95, 110, 97, 109, 101, 34, 58, 34, 65, 99, 105, 68, 32, 83, 117, 78, 34, 44, 34, 105, 115, 95, 108, 105, 115, 116, 101, 110, 105, 110, 103, 34, 58, 116, 114, 117, 101, 44, 34, 105, 115, 95, 99, 111, 110, 116, 114, 111, 108, 108, 105, 110, 103, 34, 58, 116, 114, 117, 101, 125, 93, 44, 34, 106, 111, 105, 110, 95, 115, 101, 115, 115, 105, 111, 110, 95, 117, 114, 105, 34, 58, 34, 115, 112, 111, 116, 105, 102, 121, 58, 115, 111, 99, 105, 97, 108, 115, 101, 115, 115, 105, 111, 110, 58, 54, 50, 74, 101, 119, 98, 69, 57, 84, 88, 55, 108, 116, 67, 103, 68, 108, 51, 65, 104, 82, 103, 55, 70, 112, 53, 75, 113, 80, 53, 119, 115, 74, 78, 106, 114, 105, 80, 90, 78, 49, 88, 102, 73, 101, 119, 90, 112, 49, 55, 72, 87, 82, 111, 121, 87, 111, 68, 53, 90, 99, 97, 88, 103, 98, 67, 108, 119, 67, 76, 82, 57, 73, 108, 105, 80, 97, 80, 117, 48, 110, 81, 84, 52, 67, 89, 81, 100, 122, 90, 49, 50, 111, 86, 88, 70, 100, 87, 112, 66, 103, 101, 81, 49, 104, 120, 108, 97, 34, 44, 34, 105, 115, 95, 115, 101, 115, 115, 105, 111, 110, 95, 111, 119, 110, 101, 114, 34, 58, 116, 114, 117, 101, 44, 34, 105, 115, 95, 108, 105, 115, 116, 101, 110, 105, 110, 103, 34, 58, 116, 114, 117, 101, 44, 34, 105, 115, 95, 99, 111, 110, 116, 114, 111, 108, 108, 105, 110, 103, 34, 58, 116, 114, 117, 101, 44, 34, 105, 110, 105, 116, 105, 97, 108, 83, 101, 115, 115, 105, 111, 110, 84, 121, 112, 101, 34, 58, 34, 73, 78, 95, 80, 69, 82, 83, 79, 78, 34, 44, 34, 104, 111, 115, 116, 65, 99, 116, 105, 118, 101, 68, 101, 118, 105, 99, 101, 73, 100, 34, 58, 34, 99, 48, 99, 99, 101, 54, 56, 50, 56, 52, 53, 97, 101, 49, 52, 49, 100, 52, 99, 99, 52, 98, 98, 102, 49, 49, 49, 98, 102, 48, 51, 51, 101, 98, 51, 48, 100, 102, 101, 49, 34, 44, 34, 109, 97, 120, 77, 101, 109, 98, 101, 114, 67, 111, 117, 110, 116, 34, 58, 56, 125, 44, 34, 114, 101, 97, 115, 111, 110, 34, 58, 34, 78, 69, 87, 95, 83, 69, 83, 83, 73, 79, 78, 34, 44, 34, 117, 112, 100, 97, 116, 101, 95, 115, 101, 115, 115, 105, 111, 110, 95, 109, 101, 109, 98, 101, 114, 115, 34, 58, 91, 123, 34, 106, 111, 105, 110, 101, 100, 95, 116, 105, 109, 101, 115, 116, 97, 109, 112, 34, 58, 34, 49, 54, 52, 52, 54, 57, 51, 50, 55, 50, 54, 53, 52, 34, 44, 34, 105, 100, 34, 58, 34, 55, 56, 56, 99, 102, 51, 102, 52, 51, 57, 101, 102, 51, 50, 48, 52, 98, 102, 57, 98, 97, 51, 51, 99, 50, 99, 55, 57, 99, 99, 54, 55, 34, 44, 34, 117, 115, 101, 114, 110, 97, 109, 101, 34, 58, 34, 54, 54, 48, 109, 121, 119, 107, 49, 112, 111, 116, 57, 119, 105, 114, 122, 110, 120, 98, 112, 104, 54, 108, 112, 99, 34, 44, 34, 100, 105, 115, 112, 108, 97, 121, 95, 110, 97, 109, 101, 34, 58, 34, 65, 99, 105, 68, 32, 83, 117, 78, 34, 44, 34, 105, 115, 95, 108, 105, 115, 116, 101, 110, 105, 110, 103, 34, 58, 116, 114, 117, 101, 44, 34, 105, 115, 95, 99, 111, 110, 116, 114, 111, 108, 108, 105, 110, 103, 34, 58, 116, 114, 117, 101, 125, 93, 125]] } }
[2022-02-12T19:14:32Z DEBUG librespot::component] new ChannelManager
[2022-02-12T19:14:32Z DEBUG librespot_audio::fetch::receive] Ping time now estimated as: 275 ms
[2022-02-12T19:14:33Z DEBUG librespot_audio::fetch::receive] Ping time now estimated as: 321 ms
[2022-02-12T19:14:34Z DEBUG librespot_audio::fetch::receive] Ping time now estimated as: 368 ms
[2022-02-12T19:14:34Z DEBUG librespot_audio::fetch::receive] Ping time now estimated as: 406 ms
[2022-02-12T19:14:36Z INFO  librespot_playback::player] <Steady Rain (Natural)> (598998 ms) loaded
[2022-02-12T19:14:36Z WARN  librespot_playback::player] This track will at its peak be subject to 4.94 dB of dynamic limiting.
[2022-02-12T19:14:36Z WARN  librespot_playback::player] Please lower pregain to avoid.
[2022-02-12T19:14:36Z DEBUG librespot_playback::player] Normalisation Data: NormalisationData { track_gain_db: 2.8699989318847656, track_peak: 1.0082058906555176, album_gain_db: 2.1599998474121094, album_peak: 1.0152734518051147 }
[2022-02-12T19:14:36Z DEBUG librespot_playback::player] Calculated Normalisation Factor for Track: 139.16%
[2022-02-12T19:14:36Z TRACE librespot_playback::player] == Starting sink ==
[2022-02-12T19:14:36Z TRACE librespot_playback::audio_backend::alsa] Desired Frames per Buffer: 22050
[2022-02-12T19:14:36Z TRACE librespot_playback::audio_backend::alsa] Desired Frames per Period: 5512
[2022-02-12T19:14:36Z TRACE librespot_playback::audio_backend::alsa] Actual Frames per Buffer: 22050
[2022-02-12T19:14:36Z TRACE librespot_playback::audio_backend::alsa] Actual Frames per Period: 5512
[2022-02-12T19:14:36Z TRACE librespot_playback::audio_backend::alsa] Period Buffer size in bytes: 44096
[2022-02-12T19:14:36Z TRACE librespot_playback::audio_backend::alsa] Period Buffer capacity: 44096
[2022-02-12T19:14:36Z TRACE librespot_connect::spirc] ==> kPlayStatusPlay
[2022-02-12T19:14:36Z TRACE librespot_connect::spirc] Sending status to server: [kPlayStatusPlay]
[2022-02-12T19:14:37Z DEBUG librespot_audio::fetch::receive] Ping time now estimated as: 410 ms
[2022-02-12T19:14:37Z DEBUG librespot_audio::fetch::receive] Ping time now estimated as: 354 ms
[2022-02-12T19:14:38Z DEBUG librespot_audio::fetch::receive] Ping time now estimated as: 408 ms
[2022-02-12T19:14:41Z DEBUG librespot_audio::fetch::receive] Ping time now estimated as: 411 ms
[2022-02-12T19:14:46Z DEBUG librespot_audio::fetch::receive] Ping time now estimated as: 407 ms
[2022-02-12T19:14:52Z DEBUG librespot_audio::fetch::receive] Ping time now estimated as: 406 ms
[2022-02-12T19:14:56Z DEBUG librespot_audio::fetch::receive] Ping time now estimated as: 408 ms
[2022-02-12T19:14:56Z WARN  librespot_playback::audio_backend::alsa] Error writing from AlsaSink buffer to PCM, trying to recover, ALSA function 'snd_pcm_writei' failed with error 'EPIPE: Broken pipe'
ALSA lib pcm.c:8526:(snd_pcm_recover) underrun occurred
[2022-02-12T19:14:58Z DEBUG librespot_audio::fetch::receive] Ping time now estimated as: 414 ms
[2022-02-12T19:15:01Z DEBUG librespot_audio::fetch::receive] Ping time now estimated as: 406 ms
[2022-02-12T19:15:28Z TRACE librespot_connect::spirc] ==> kPlayStatusPlay
[2022-02-12T19:15:28Z TRACE librespot_connect::spirc] Sending status to server: [kPlayStatusPlay]
[2022-02-12T19:15:28Z WARN  librespot_playback::audio_backend::alsa] Error writing from AlsaSink buffer to PCM, trying to recover, ALSA function 'snd_pcm_writei' failed with error 'EPIPE: Broken pipe'
ALSA lib pcm.c:8526:(snd_pcm_recover) underrun occurred
[2022-02-12T19:15:32Z DEBUG librespot_audio::fetch::receive] Ping time now estimated as: 409 ms
[2022-02-12T19:15:38Z DEBUG librespot_audio::fetch::receive] Ping time now estimated as: 409 ms
[2022-02-12T19:15:52Z DEBUG librespot_audio::fetch::receive] Ping time now estimated as: 408 ms
[2022-02-12T19:15:59Z WARN  librespot_audio::fetch::receive] Ping time 2516 ms exceeds maximum 1500, setting to maximum
[2022-02-12T19:16:05Z DEBUG librespot_core::session] Session strong=7 weak=7
[2022-02-12T19:16:12Z DEBUG librespot_audio::fetch::receive] Ping time now estimated as: 409 ms
[2022-02-12T19:16:17Z DEBUG librespot_audio::fetch::receive] Ping time now estimated as: 408 ms
[2022-02-12T19:16:19Z DEBUG librespot_audio::fetch] Downloading file 23cc19dfb217fcaebc2cd63ebdace8820b1f6661 complete

My connection speed is 100Mbps. The download speed with CDN is about 3-4Mbps.

2 replies

roderickvd Feb 13, 2022
Maintainer Author

What are you running this on and what is your CPU usage?

acid-sun Feb 14, 2022

Amlogic S905X SoC, Ubuntu 20.04.3 LTS (Focal Fossa), 4.19.55+ kernel, external USB-DAC
I don't think the CPU is the bottleneck. I calmly listen through mpd DSD256 and flaс 386kHz, while the files are in the NAS and transfers via NFS.
Maybe CDN limit speed with my host?

Today I tested some tracks with > 6 minutes duration and had always problem

[2022-02-14T08:54:41Z WARN  librespot_playback::audio_backend::alsa] Error writing from AlsaSink buffer to PCM, trying to recover, ALSA function 'snd_pcm_writei' failed with error 'EPIPE: Broken pipe'
ALSA lib pcm.c:8526:(snd_pcm_recover) underrun occurred
[2022-02-14T08:54:45Z WARN  librespot_core::spclient] Unable to complete API request, waiting 2 seconds before retrying...
[2022-02-14T08:54:45Z DEBUG librespot_core::spclient] Error was: Err(Error { kind: Unavailable, error: hyper::Error(Connect, ConnectError("tcp connect error", Os { code: 110, kind: TimedOut, message: "Connection timed out" })) })
[2022-02-14T08:54:47Z DEBUG librespot_core::http_client] Requesting https://gew1-spclient.spotify.com:443/storage-resolve/files/audio/interactive/453ecbd774b5f8be7403e68b0202f795690c150c?product=0

CDN ping

--- 199.232.138.248 ping statistics ---
25 packets transmitted, 25 received, 0% packet loss, time 24037ms
rtt min/avg/max/mdev = 41.338/41.382/41.446/0.027 ms

Snapshot when download track:

roderickvd · 2022-02-14T11:19:20Z

roderickvd
Feb 14, 2022
Maintainer Author

I don't know that SoC, what architecture is it, ARMv8? It seems more than powerful enough, yes, but still, a quick CPU check would be appreciated.

The logs clearly state that there is a TCP connection error, do you have any hypothesis why from your end?

I have one hypothesis: the CDN doesn't like connections that are too fast, and hit rate limiting. You may want to read #917 (comment) and try some of the suggestions I mentioned at the end.

Let me know how it goes. I do think we need to make some changes here.

8 replies

roderickvd Feb 14, 2022
Maintainer Author

Can you confirm it’s the same on dev?

acid-sun Feb 14, 2022

Yes

JasonLG1979 Feb 16, 2022

Is it the same on dev? Currently librespot writes downloads to a temp file, not to RAM. But that’s how it already was, not new to new-api.

I guess I never looked into that. I just assumed unless a cache location was set that tracks were stored in RAM? That should really be an option (the default IMHO) writing to disk that much can really kill micro sd cards and you shouldn't be forced to manually create a RAM disk just to cache to RAM.

In new-api you could create a RAM disk and configure to store temp files there.

You could have always done that. From an app's perspective tmpfs (in Linux anyway) is just another filesystem. It doesn't know the difference.

JasonLG1979 Feb 16, 2022

In my mind the value of on disk caching is so that you don't have to re-download the track. librespot should not be playing directly from the disk. That's just asking for I/O errors. Ideally even when files are cached the whole file should be read and played from memory.

roderickvd Feb 16, 2022
Maintainer Author

Feel free to work on it. For new-api make sure it’s somewhat flexible, because storing large FLAC files in RAM in the future won’t always be an option on headless gear.

JasonLG1979 · 2022-03-17T00:58:13Z

JasonLG1979
Mar 17, 2022

Looking at our command line options I have a couple thoughts.

Caching:

Currently we have a lot of caching options that I think can be simplified a bit. We have cache, system-cache, cache-size-limit, disable-audio-cache, and disable-credential-cache. It's also very possible to get into bad situations with those options. For example audio file caching is enabled by default if you provide a cache location but will fill your disk unless cache-size-limit is also set. cache and system-cache is also kinda strange names.

My thought is that:

system-cache should be re-named to just cache and we should have a audio-file-cache location, and that unless both audio-file-cache and a cache-size-limit was set audio files would not be cached.

Discovery, creds and cred caching:

Currently discovery is enabled by default and so is cred caching. It's mostly harmless but cred caching is completely unnecessary if discovery is working as intended. The flip side to that is that if you disable cred caching and provide your username and password you get nag emails from Spotify every time librespot logs in with your creds.

My thought is that:

Really there are 2 modes librespot can operate in. Discovery enabled and working, and discovery turned off and username and password provided. We can simplify this greatly. Remove disable-discovery, and disable-credential-cache. When a user provides their creds automatically disable discovery and enable cred caching otherwise with no creds, disable cred caching and enable discovery.

4 replies

AndreKR Mar 28, 2022

I just came across this while searching for something completely different and I didn't read the whole discussion but this last comment seems to propose making credentials and discovery mutually exclusive. This would break my use case so I wanted to chime in:

I'm running librespot on a Raspberry Pi in my kitchen.
I'm running it with credentials because that is necessary to control it via that horrible web API from the home automation system (wall tablet/voice control). Occasionally I also start playback for my wife while I'm out of the house, which also requires credentials.
However, when guests are over and someone wants to play a certain song from their phone, they need to be in the Wifi and use discovery to play on my Raspberry Pi because on their phone they have their own Spotify account of course, not mine.

JasonLG1979 Mar 28, 2022

Good to know. That's why I posted here, to get input. Thanks.

Sounds like a perfectly reasonable use case. May have to scrap or at least rethink that part.

Any thoughts about the Caching bit?

AndreKR Mar 28, 2022

I find the current set of caching options quite reasonable and straightforward:

Having a global cache path option makes sense for when you just want to get started.
Having the ability to move the audio cache separately, to an external drive or something like that, makes sense as well, because (1) it can grow quite large and (2) one might actually want to back it up if you're on a slow or metered connection.
Having the cache enabled by default makes sense as well, that's how Spotify does it and not doing it would be incredibly wasteful.
Not having a default cache size was never a problem for me. In fact I'd be slightly annoyed if librespot chose a (too small) size for me and started hogging my connection for files I believed to be cached. But I understand your reasoning as well and could definitely live with a default as long as it is mentioned in the list of command line options.

roderickvd Apr 7, 2022
Maintainer Author

I agree that the current caching seems to offer more bells and whistles than needed. Happy to accept simplifications to that.

BenJeau · 2022-04-21T22:06:13Z

BenJeau
Apr 21, 2022

Not sure if this was said (or if this is an issue), I'm trying out the new-api branch alongside swift-bridge and the async functions with that bridge needs to be Send. I am getting compilation errors that some futures are not Send (chinedufn/swift-bridge#50 (comment)).

For example, the connect() function is not Send

let credentials = Credentials::with_password("username", "password");
let session = Session::new(SessionConfig::default(), None);

session.connect(credentials).await.unwrap();

This is the first time I'm encountering errors like these, so I am unsure if it is a problem or not with the function or the swift bridge.

I am not getting these errors on version 0.3.1

1 reply

roderickvd Apr 22, 2022
Maintainer Author

In chinedufn/swift-bridge#50 (comment) I see that this is due to the new crypto libraries (digest) not being Send as well as rand_core. You would have to take that up with them.

roderickvd · 2022-07-29T21:51:01Z

roderickvd
Jul 29, 2022
Maintainer Author

Today the new-api branch was merged into dev. It's not done yet, so please focus the new API development efforts in dev and no longer in that feature branch.

0 replies

WIP: new Spotify API #917

roderickvd Dec 29, 2021 Maintainer

Required work

Optional work

Code quality

Connect

Core

Metadata

Networking

Player

Playlists

Fix issues

Earlier work

Replies: 23 comments · 123 replies

roderickvd Dec 30, 2021 Maintainer Author

roderickvd Jan 1, 2022 Maintainer Author

roderickvd Jan 3, 2022 Maintainer Author

roderickvd Dec 30, 2021 Maintainer Author

roderickvd Jan 1, 2022 Maintainer Author

roderickvd Jan 1, 2022 Maintainer Author

roderickvd Jan 3, 2022 Maintainer Author

roderickvd Jan 3, 2022 Maintainer Author

roderickvd Jan 4, 2022 Maintainer Author

roderickvd Jan 5, 2022 Maintainer Author

roderickvd Jan 6, 2022 Maintainer Author

roderickvd Jan 6, 2022 Maintainer Author

roderickvd Jan 6, 2022 Maintainer Author

roderickvd Jan 7, 2022 Maintainer Author

roderickvd Jan 9, 2022 Maintainer Author

roderickvd Jan 12, 2022 Maintainer Author

roderickvd Jan 10, 2022 Maintainer Author

roderickvd Jan 12, 2022 Maintainer Author

roderickvd Jan 9, 2022 Maintainer Author

roderickvd Jan 10, 2022 Maintainer Author

roderickvd Jan 10, 2022 Maintainer Author

roderickvd Jan 13, 2022 Maintainer Author

roderickvd Jan 12, 2022 Maintainer Author

roderickvd Jan 13, 2022 Maintainer Author

roderickvd Jan 16, 2022 Maintainer Author

roderickvd Jan 22, 2022 Maintainer Author

roderickvd Jan 22, 2022 Maintainer Author

roderickvd Jan 22, 2022 Maintainer Author

roderickvd Jan 22, 2022 Maintainer Author

roderickvd Jan 22, 2022 Maintainer Author

roderickvd Jan 23, 2022 Maintainer Author

roderickvd
Dec 29, 2021
Maintainer

Replies: 23 comments 123 replies

roderickvd
Dec 30, 2021
Maintainer Author

roderickvd Jan 1, 2022
Maintainer Author

roderickvd Jan 3, 2022
Maintainer Author

roderickvd
Dec 30, 2021
Maintainer Author

roderickvd Jan 1, 2022
Maintainer Author

roderickvd
Jan 1, 2022
Maintainer Author

roderickvd Jan 3, 2022
Maintainer Author

roderickvd Jan 3, 2022
Maintainer Author

roderickvd Jan 4, 2022
Maintainer Author

roderickvd Jan 5, 2022
Maintainer Author

roderickvd Jan 6, 2022
Maintainer Author

roderickvd Jan 6, 2022
Maintainer Author

roderickvd Jan 6, 2022
Maintainer Author

roderickvd Jan 7, 2022
Maintainer Author

roderickvd Jan 9, 2022
Maintainer Author

roderickvd Jan 12, 2022
Maintainer Author

roderickvd Jan 10, 2022
Maintainer Author

roderickvd Jan 12, 2022
Maintainer Author

roderickvd
Jan 9, 2022
Maintainer Author

roderickvd Jan 10, 2022
Maintainer Author

roderickvd Jan 10, 2022
Maintainer Author

roderickvd Jan 13, 2022
Maintainer Author

roderickvd Jan 12, 2022
Maintainer Author

roderickvd Jan 13, 2022
Maintainer Author

roderickvd
Jan 16, 2022
Maintainer Author

roderickvd Jan 22, 2022
Maintainer Author

roderickvd Jan 22, 2022
Maintainer Author

roderickvd
Jan 22, 2022
Maintainer Author

roderickvd Jan 22, 2022
Maintainer Author

roderickvd Jan 22, 2022
Maintainer Author

roderickvd Jan 23, 2022
Maintainer Author