Connection problems when requesting client token

[dbischof90]

Description

A cross-compiled librespot client for bullseye doesn't successfully run with a zeroconf backend.

Version

librespot 0.6.0-dev 7003e98 on armhf

How to reproduce

Steps to reproduce the behavior in librespot e.g.

1. Clone the repository
2. Replace all occurrences of bookwork in contrib/Dockerfile with bullseye and remove armsel
3. Compile with any zeroconf-backend
4. Launch ./librespot --name "MyLibrespotPlayer" --backend alsa --zeroconf-backend avahi --verbose

Log

[2025-01-11T16:20:36Z INFO  librespot] librespot 0.6.0-dev 7003e98 (Built on 2025-01-11, Build ID: KBltLc71, Profile: release)
[2025-01-11T16:20:36Z TRACE librespot] Command line argument(s):
[2025-01-11T16:20:36Z TRACE librespot] 		name "MyLibrespotPlayer"
[2025-01-11T16:20:36Z TRACE librespot] 		backend "alsa"
[2025-01-11T16:20:36Z TRACE librespot] 		zeroconf-backend "avahi"
[2025-01-11T16:20:36Z TRACE librespot] 		verbose
[2025-01-11T16:20:36Z DEBUG librespot_core::session] new Session
[2025-01-11T16:20:36Z DEBUG librespot_discovery::server] Zeroconf server listening on 0.0.0.0:37947
[2025-01-11T16:20:36Z INFO  librespot_playback::mixer::softmixer] Mixing with softvol and volume control: Log(60.0)
[2025-01-11T16:20:36Z DEBUG librespot_playback::player] new Player [0]
[2025-01-11T16:20:36Z INFO  librespot_playback::convert] Converting with ditherer: tpdf
[2025-01-11T16:20:36Z INFO  librespot_playback::audio_backend::alsa] Using AlsaSink with format: S16
[2025-01-11T16:20:36Z DEBUG librespot_discovery] Pinged Avahi: Available
[2025-01-11T16:20:36Z TRACE librespot_discovery] Connected to Avahi
[2025-01-11T16:20:36Z DEBUG librespot_discovery] Commited zeroconf service with name MyLibrespotPlayer
[2025-01-11T16:20:36Z INFO  librespot_discovery] Published zeroconf service
[2025-01-11T16:20:48Z DEBUG librespot_discovery::server] POST "/" {}
[2025-01-11T16:20:48Z DEBUG librespot_core::session] Shutdown: Invalidating session
[2025-01-11T16:20:48Z DEBUG librespot::component] new MercuryManager
[2025-01-11T16:20:48Z DEBUG librespot::component] new ChannelManager
[2025-01-11T16:20:48Z DEBUG librespot_core::session] new Session
[2025-01-11T16:20:48Z DEBUG librespot_connect::spirc] new Spirc[0]
[2025-01-11T16:20:48Z DEBUG librespot_playback::player] command=SetSession
[2025-01-11T16:20:48Z DEBUG librespot_core::session] drop Session
[2025-01-11T16:20:48Z DEBUG librespot::component] drop ChannelManager
[2025-01-11T16:20:48Z DEBUG librespot::component] new DealerManager
[2025-01-11T16:20:48Z DEBUG librespot::component] drop MercuryManager
[2025-01-11T16:20:48Z DEBUG librespot::component] new SpClient
[2025-01-11T16:20:48Z DEBUG librespot_core::spclient] Client token unavailable or expired, requesting new token.
[2025-01-11T16:20:48Z DEBUG librespot_core::http_client] Requesting https://clienttoken.spotify.com/v1/clienttoken

Nothing happens afterwards.

Host (what you are running librespot on):

• OS: Debian Bullseye (armhf)
• Platform: Vero V (OSMC)

Additional context

The error persists with all zeroconf backends. The speaker can be found without problems. The internet is reachable from the device.

[photovoltex]

Does librespot work on a different device in your network? And could you alternatively try to use oauth as authentication? (see here for help on the topic https://github.com/librespot-org/librespot/wiki/Options#authentication)

[dbischof90]

I installed it on my laptop via cargo and ran librespot --cache ./librespot_cache --enable-oauth --oauth-port 0 --verbose. On my laptop that worked! On my other device the output was

[2025-01-12T20:18:52Z INFO  librespot] librespot 0.6.0-dev 7003e98 (Built on 2025-01-11, Build ID: KBltLc71, Profile: release)
[2025-01-12T20:18:52Z TRACE librespot] Command line argument(s):
[2025-01-12T20:18:52Z TRACE librespot] 		cache "./librespot_cache"
[2025-01-12T20:18:52Z TRACE librespot] 		enable-oauth
[2025-01-12T20:18:52Z TRACE librespot] 		oauth-port "0"
[2025-01-12T20:18:52Z TRACE librespot] 		verbose
[2025-01-12T20:18:52Z DEBUG librespot_core::session] new Session
[2025-01-12T20:18:52Z DEBUG librespot_discovery::server] Zeroconf server listening on 0.0.0.0:40655
Browse to: https://accounts.spotify.com/authorize?response_type=code&client_id=65b708073fc0480e233ca87bd&state=0QaCXnmc-lakjsdfkajdsf&code_challenge=1y2ZAzFGkSwXa7vDcqA3zd3dDvFku7Y8pUl80&code_challenge_method=S256&redirect_uri=http%3A%2F%2F127.0.0.1%2Flogin&scope=app-remote-control+playlist-modify+playlist-modify-private+playlist-modify-public+playlist-read+playlist-read-collaborative+playlist-read-private+streaming+ugc-image-upload+user-follow-modify+user-follow-read+user-library-modify+user-library-read+user-modify+user-modify-playback-state+user-modify-private+user-personalized+user-read-birthdate+user-read-currently-playing+user-read-email+user-read-play-history+user-read-playback-position+user-read-playback-state+user-read-private+user-read-recently-played+user-top-read
Provide redirect URL
http://127.0.0.1/login?code=AQA0xMdxVqYEFI9xVDsIQLngnm0YOasu7tSWixj4dg_y1s3JTI77bk15QX5lGgnX4I9qUm7YqyHHb_oxqdfN4ty3t846W64lP-LwMonoJdnNlrLOoduZAF1Qk4klPKvgRwWKgd6dYPKcEnakVpKpb56bUadhDNOvx9PmVBqy9ii_LIyOF0_1wMCsNoQl_P_6ghzTyITiEynWusbT1q8SM1LdBs6fjj4ufflt3LKcLaaen3tCxDK7-dbNgKu0cfWkAMW8-w1K2gHpI979ZHjibIWp-bR8kRIFRfmQCxKd8qjvGLChli7MwMLxQJmMf7d18ZJ7vakFM2NFtXOewcNhsXniLbIgrjasjfdölkjdsaölkfjö-u2JAMXIkNNC0aMxfRIvpfs1MYtOh4CaYPMBkmsUqtLvK3bn2sTQ1ttI07zvG__wM1tbIR5R37rtOX7uxwTAn0pYIzbspg8tjp0mvQsetQAX6NwzKF5--5bavwgWx6fBu6fqKENzxdZI87hA7B4SW0G9CAkr-P6e84hLsb9NtpSpDBCaFVQss0ZmiZRg03BpdS_z7pKUHhTA_cI2cYsy8_Tmw6_R6STMkNolDxBSJsXlXRx-ctw-K3X-u4lmIr9Nsg2p3iUcPKJjE9lfgUYGRyiTH1IU-RN4Y4vxDscUAjnjJBmvfwWh9Htqwh2jf_iCTkJvLOSMQkmTjVmcefAaJW1eWUEcwQ6YKAAKj3hTw4WZ5ogVSpElIdy-SpXPOFbtCIFH2EDVoHkkxWuaj2Qy6T7rMXNZHRWRSbup6mcskDk1XmGvF2TMuJgrragmasdfmaskdflkasjd-C4L5oCrhvPFUTYZsMlywrkeCN6VgFT8h6t3aWA_WrYRpzZ_kJtjaeBg8GekCXva2UzPByqHImp9N0y1Y_cfB2-i9TWgewoyCCQHgFam-a8BdHaFPish1Cio1qGEJw-g&state=0QaCXnmc-dcPiwVY1BBYGw
[2025-01-12T20:19:09Z TRACE librespot_oauth] Exchange AuthorizationCode([redacted]) for access token

and then nothing. It seems it can't connect to the server but doesn't log that...

[photovoltex]

What a weird behavior... Did a different version of librespot work before or is your first time using librespot on that device?

Could you ping spotify.com on the device and see what happens?

[dbischof90]

Sure!
I think I used librespot years ago, only now I wanted to pick it up again and try it on my media computer - there it's the first time.

osmc@TV:~$ ping spotify.com
PING spotify.com (2600:1901:1:7c5::): 56 data bytes
64 bytes from 2600:1901:1:7c5::: seq=0 ttl=119 time=5.589 ms
64 bytes from 2600:1901:1:7c5::: seq=1 ttl=119 time=5.148 ms
64 bytes from 2600:1901:1:7c5::: seq=2 ttl=119 time=5.515 ms
64 bytes from 2600:1901:1:7c5::: seq=3 ttl=119 time=5.908 ms
64 bytes from 2600:1901:1:7c5::: seq=4 ttl=119 time=5.408 ms
[...]

So that works too. I can also ping clienttoken.spotify.com.

Is my release method maybe wrong and I am missing some dynamic libs whose output is dropped silently? I compiled via docker as written in the notes and then just copied the binary over to my device.

The (I think only relevant) other big difference is that the Vero V is still running on Bullseye, not Bookworm, but I'd be surprised if libc6 had changed that much.

[kingosticks]

What's your CPU usage like when it seems to get stuck? I had an issue reported in my downstream project which looks a bit like this and it seemingly came down to the version of gcc used but we never really got to the bottom of it.

[dbischof90]

Oh you're onto something there! The process brings a single core to run at a constant 100% once I try to connect to librespot from a Spotify client!

[kingosticks]

mopidy/mopidy-spotify#402 is this issue in question. I provide armv6 compatible armhf builds using the raspberry pi toolchain. This binary seems to hang, similarly to yours, when run via arm32v7/Bullseye Docker on a CoreElec system (armlogic??).

Instead, if it's compiled using that same Docker container with normal gcc then the problem goes away. I think we concluded it wasn't a Docker issue because my provided binary works fine under Docker on a different armhf machine. So perhaps a compiler compatibility problem with the hardware. One other thing maybe relevant to you is this is also with Bullseye.

[dbischof90]

This is interesting - thank you for the input. I'm not so sure it's worth the deep dive - I know that the migration to >=bookwork in OSMC should start soon so in ~6-12 months that might not be so relevant anymore. I'll glue together a Docker image and virtualize until I can run native then.

[kingosticks]

Fair enough. Just to confirm and for anyone else that finds themselves here

• @dbischof90 had
  • Cross-compiled for armv7 using gcc-arm-linux-gnueabihf (v10.2.1 from Bullseye)
  • Running natively on Bullseye OSMC with Amlogic S905X4-O
• @mczerski had
  • Cross-compiled for armv6 using arm-rpi-4.9.3-linux-gnueabihf
  • Running under Bullseye Docker on CoreElec with Amlogic S905X3

[dbischof90]

Just to mention, not that I wouldn't want to, it's just that I feel I'm neither familiar enough with the hardware nor the compiler to provide more than uneducated guesses - if there is an interest in debugging and solving that I am very happy to play the tool for the job. The current guess seems to be that it is not too unlikely that it could be Bullseye on that hardware.

That factor should go away if I use a Bookworm base image on Docker, right. I'll report the result of that here.

[kingosticks]

That factor should go away if I use a Bookworm base image on Docker, right

I have no idea!