Delayed interactions since librespot 0.4

[honza]

I'm using Fedora 41. Stable rust to compile myself.

My config is simple:

[global]
device_name = "..."
device = "front:CARD=Generic_1,DEV=0"
zeroconf_port = 1234

Since https://github.com/Spotifyd/spotifyd/commit/f53deb9b877126b956a5e233fb743b639232232b, starting/stopping playback, changing songs, and changing volume takes a long time. Volume especially (I change the volume on my phone and it takes 10s to react on the server where before it's instant).

I tried updating librespot to 0.4.2 and even trying @davidgauch librespot 0.5 PR https://github.com/Spotifyd/spotifyd/pull/1309 and those are unchanged.

What can I do to debug this?

[eladyn]

Maybe you can retry with the branch in #1317? I assume you're talking about controlling playback via one of the official apps?

[honza]

Unfortunately, it doesn't resolve my problem.

[eladyn]

That's unfortunate. Just to make sure, you're controlling spotifyd from an official app? If you run spotifyd with the --verbose flag, it's probably going to dump out a lot of things, but maybe you can try that and see, when the command to play/pause arrives on the device by waiting for new logs after pressing the button?

[honza]

That's unfortunate. Just to make sure, you're controlling spotifyd from an official app?

Yes, iOS client.

I'll have another look at the logs.

[honza]

There don't seem to be any errors in the logs that I can see. :(

[eladyn]

I didn't expect errors to appear but just general log messages. So when spotifyd receives the command it will print things to the console and you can maybe examine how long it takes from pressing the button to new logs appearing.

[honza]

The output is extremely busy so it's impossible to correlate. I'll have to hack around and decrease the amount of stuff logged.

[honza]

Removing the --verbose flag, I see that tracks are found and loaded immediately but take several seconds to actually start playing:

Jan 07 15:34:16 yoda spotifyd[8139]: Loading <All These People> with Spotify URI <spotify:track:5gKEJxGeBpyztwPAWp3mRd>
Jan 07 15:34:17 yoda spotifyd[8139]: <All These People> (232466 ms) loaded

Volume changes aren't logged.

[eladyn]

Thank you for looking into this. That behaviour indeed sounds strange. My next guess would be that it might be related to playback things? I'm assuming you're using the alsa backend and softvol as volume control?

[honza]

This issue is still present on latest master.

[honza]

I'm assuming you're using the alsa backend and softvol as volume control?

The only settings I have changed are above.