Obtain spclient access token using login5 instead of keymaster (Fixes #1179 and #1245)

[lmore377]

This PR is a copy of #1220 as that one seems stale. This resolves the issue where authentication fails when spotify connect is started from a desktop client.

Fixes #1179 and #1245. Tested and works with clients from Android, iOS, Windows, Linux and macOS.

I still need to resolve the review comments from #1220, I'm just opening this now to keep track of changes.
I'm very inexperienced when it comes to rust so please be gentle 😆

Credits:
@kingosticks - Created the initial branch with the fix
@Gerrelt - Created the PR that this one is based on

[MarkParker5]

Hey @lmore377! I use this library in my project and faced the same issue. I really want this pull request to be merged ASAP. What's left to do? Maybe I can finish this.

[lmore377]

Hey @lmore377! I use this library in my project and faced the same issue. I really want this pull request to be merged ASAP. What's left to do? Maybe I can finish this.

The review comments on #1220 just need to be looked over and applied here. I've been pretty preoccupied with other things and haven't really gotten around to sitting down and looking at this. One quick note, I noticed that auth broke again the other day even with this patch so there might be something more going on at Spotify's end. I'll check real quick.

[lmore377]

Yeah it seems like all forms of auth (even passing username and password with -u and -p) are broken with this PR. Main still works but like before, it only works when starting playback from a mobile device or passing -u and -p. I really don't know at all how the auth system works but from reading the verbose logs, it seems like librespot is able to set up the connection for control but for some reason it's failing to auth for playback. Unfortunately this is way out of my skillset so someone else is going to need to take the lead. If anyone wants permissions to work on my fork just let me know. Here's a log of connecting via Spotify Connect and trying to press play a few times (please let me know if there's any sensitive info in here I really don't know lmao):

log.txt

[lmore377]

@roderickvd @kingosticks Do you guys have any idea about what could be going on here?

[roderickvd]

I don't know, I've been out of this for quite some time now.

I checked that log and could be totally wrong, but it seems that librespot is doing a hard fail (shutting down) because it cannot dispatch a "social-connect/v2/session_update" command. That command probably really does not matter, so it should soft fail and ignore.

Spotify server-side does different things depending on the type of platform connecting, type of authentication you're using, current visibility of the moon, and the amount of fairy dust in the air, so it could be that authenticating this way triggers a bug that was not visible in librespot before.

[MarkParker5]

AFAICS this error is being handled and shouldn't cause a hard fail:

if let Err(e) = session.dispatch(cmd, data) {
    debug!("could not dispatch command: {}", e);
}

in DispatchTask.poll:

struct DispatchTask<S>(S, SessionWeak)
where
    S: TryStream<Ok = (u8, Bytes)> + Unpin;

impl<S> Future for DispatchTask<S>
where
    S: TryStream<Ok = (u8, Bytes)> + Unpin,
    <S as TryStream>::Ok: std::fmt::Debug,
{
    type Output = Result<(), S::Error>;

    fn poll(mut self: Pin<&mut Self>, cx: &mut Context<'_>) -> Poll<Self::Output> {
        let session = match self.1.try_upgrade() {
            Some(session) => session,
            None => return Poll::Ready(Ok(())),
        };

        loop {
            let (cmd, data) = match ready!(self.0.try_poll_next_unpin(cx)) {
                Some(Ok(t)) => t,
                None => {
                    warn!("Connection to server closed.");
                    session.shutdown();
                    return Poll::Ready(Ok(()));
                }
                Some(Err(e)) => {
                    session.shutdown();
                    return Poll::Ready(Err(e));
                }
            };

            if let Err(e) = session.dispatch(cmd, data) {
                debug!("could not dispatch command: {}", e);
            }
        }
    }
}

https://github.com/lmore377/librespot/blob/5a322e70e15d4e442a2d681609bb38eec8b31dc8/core/src/session.rs#L602-L604

I also checked the flow DispatchTask.poll -> session.dispatch -> mercury.dispatch -> mercury.complete_request -> !found -> Err(MercuryError::Response(response).into()) and didn't find anything that looks like a reason for a hard fail. Meanwhile, I am not a rust developer and could have missed some details of the syntax, e.g. trailing "?" for ControlFlow::Break.

[gokberkkocak]

I'm also on linux and getting the same authentication problem. It's not a hard fail though, I think the log also includes the gracefully shutting via interruption as well. I believe the relevant part is:

[2024-01-31T23:04:40Z DEBUG librespot_core::spclient] Client token unavailable or expired, requesting new token.
[2024-01-31T23:04:40Z DEBUG librespot_core::spclient] Client token unavailable or expired, requesting new token.
[2024-01-31T23:04:40Z DEBUG librespot_core::http_client] Requesting https://clienttoken.spotify.com/v1/clienttoken
[2024-01-31T23:04:40Z DEBUG librespot_core::http_client] Requesting https://clienttoken.spotify.com/v1/clienttoken
[2024-01-31T23:04:40Z ERROR librespot_connect::spirc] ContextError: Error { kind: InvalidArgument, error: StatusCode(400) }

which I can provide the exact part with no-crash but in a non-playable state.

login5 client token:

important part of the image as text:

...
[2024-02-06T17:07:28Z DEBUG librespot_core::spclient] Client token unavailable or expired, requesting new token.
[2024-02-06T17:07:28Z DEBUG librespot_core::http_client] Requesting https://clienttoken.spotify.com/v1/clienttoken
[2024-02-06T17:07:28Z ERROR librespot_connect::spirc] ContextError: Error { kind: InvalidArgument, error: StatusCode(400) }
...

---

I don't know how the client token is relevant to this process but that's the part just before the error and we cannot see any outcome of the client token process.

Building main and using no-discover cached authentication, I can verify that the client token step warns (but playable state) via Unable to get client token. Trying to continue without... (see below image), so at least the Err is used. However in this new auth method, client token does not result positive (i.e. Got client token:) or any negative one. Some other part is eating that result somewhere and it might be some other Err which might be key to solve this.

main client token:

important part of the image as text:

...
[2024-02-06T17:13:26Z DEBUG librespot_core::spclient] Client token unavailable or expired, requesting new token.
[2024-02-06T17:13:26Z DEBUG librespot_core::http_client] Requesting https://clienttoken.spotify.com/v1/clienttoken
[2024-02-06T17:13:26Z WARN  librespot_core::spclient] Unable to get client token. Trying to continue without...
...

---

Lastly, I don't know it's relevant but the comment on client token logic indicates on linux the old keymaster id is used.

// on macOS and Windows. On Android and iOS we can send a platform-specific client ID and are
// then presented with a hash cash challenge. On Linux, we have to pass the old keymaster ID.

It might be possible that this new new login5 auth (that replaces keymaster auth) and mix usage of this old keymaster id on linux is causing issues.

Edit: Added the relevant part of the images as blocks as well for who are not able to see github images for various reasons.

[MarkParker5]

@gokberkkocak images are 404

[gokberkkocak]

Images are github hosted. I edited the comment to add the relevant parts as quote blocks if you are not able to load them.

[kingosticks]

I'll try take a look this week. Probably worth checking what the latest official clients are doing.

[MarkParker5]

Hello, any updates? @kingosticks did you have a chance to take a look?

[kingosticks]

I'm sorry, I didn't. I've had a backlog to get through but I'm basically done to the point where librespot is blocking me so I have to get into this again. Will try asap.

[hamishfagg]

@kingosticks don't want to be that guy but any updates?

[kingosticks]

It seems I am that other guy, the one who doesn't have any update. I did start looking at librespot again but I got distracted by something in gstreamer-rs and made no progress on this actual problems here. Over the next few weeks I'll either have a lot of free time or no free time and I'll have to wait and see where I land.

[hamishfagg]

No worries, i definitely understand how that goes 😅

It seems like (at least for me) librespot is completely broken now, where it was working intermittently for a while. I'd love to help but i dont know rust at all and I'm in the same boat of too many things to do.

I'd be willing to pitch in some money to get this fixed if anyone else can help. Maybe if a few others can do the same we can make it worth someone's time? I loved my multiroom spotify setup 😥

[kingosticks]

Just to clarify, is the master branch also not working?

[rohoog]

Master works, dev does not: error 403 for uri hm://keymaster/token/authenticated?....

[hamishfagg]

Oh shoot. I can't remember what caused me to switch over to dev, but master is working for now..

EDIT: There it is. For me sometimes master will only play for 0.5-1 songs before playback stops and I get this:
Note: some days it will do this constantly. Other days it will work fine

2024-05-21 06-10-59.779 [Error] (librespot_playback::player) Unable to load audio item: MercuryError
2024-05-21 06-10-59.779 [Error] (librespot_core::session) Connection reset by peer (os error 104)
2024-05-21 06-10-59.779 [Error] (librespot_connect::spirc) subscription terminated
2024-05-21 06-10-59.782 [Warn] (librespot) Spirc shut down unexpectedly
2024-05-21 06-11-00.054 [Warn] (librespot_core::apresolve) Ignoring blacklisted access point ap-gue1.spotify.com:4070
2024-05-21 06-11-00.054 [Warn] (librespot_core::apresolve) Ignoring blacklisted access point ap-gew4.spotify.com:80
2024-05-21 06-11-00.055 [Info] (librespot_core::session) Connecting to AP "ap-gae2.spotify.com:4070"

[MarkParker5]

The minimal build with spotify connect always worked for me, the problem appeared when building with dbus control activated, probably because playback control is on the server side and requires a different type of authorization.

[lmore377]

I've pretty much abandoned this PR and it seems like authentication from the mobile app works fine now

[MarkParker5]

@lmore377 did you try a build with dbus control enabled?

[lmore377]

What's the feature flag for it?

[MarkParker5]

Oh, several months have already passed since the last test. I've already forgotten many details. The flag is use_mpris = true in the spotifyd config file. Then the search for a solution led me to this PR as the end point, but now I’m starting to suspect that the reason is in spotifyd, and not in librespot.

[kingosticks]

Following Spotify's impending promised changes to authentication, I re-resurrected this into #1309