search

devgianlu / go-librespot

Yet another open source Spotify client, written in Go.
GNU General Public License v3.0
75 stars 15 forks source link

Support "discovery mode" like in librespot #14

Closed phts closed 7 months ago

phts commented 10 months ago

https://github.com/plietar/librespot/blob/master/README.md#discovery-mode

This mode allows to connect to the device by any user, not only currently logged in. So everybody in the netwrok can use the device.

devgianlu commented 10 months ago

This mode is already supported and is called zeroconf. It can be used with a configuration like this one: 

device_name: go-librespot
credentials:
  type: zeroconf

I realise that a lot of documentation is still missing!

phts commented 10 months ago

Is it possible to have it simultaneously with normal authentification?

Use case: I logged in on the device with spotify integration and get token, and this device uses my token to show my content in its UI, e.g. I can see my artists,albums, etc. And in the same time, "connect" is available for any device in the network, because in fact my token not required to make "connect" available for any device.

librespot I believe has this option separatelly from main authentification

devgianlu commented 10 months ago

Having one instance handle two sessions simultaneously seems a very specific and uncommon case. Perhaps you could have two instances of go-librespot: one that handles the UI and is logged in and one that does the playback and uses Spotify Connect. What do you think? A reasonable change would be to allow go-librespot to run without showing up as a connectable device.

phts commented 10 months ago

Actually not quite uncommon.

There is community page regarding volumio's new spotify plugin which was migrated from rust librespot to go-librespot, users complaining about this missing feature, now it requires to log out to allow other users to use "connect". Then log in to use UI. Which is quite inconvenient.

phts commented 10 months ago

What do you think? A reasonable change would be to allow go-librespot to run without showing up as a connectable device.

yes, theoretically could work 👍

devgianlu commented 8 months ago

This is being worked on with https://github.com/devgianlu/go-librespot/commit/8a2cb3b5a4d47ed386fee6e83dd005dea130d11f, I have tested it somewhat, but not extensively.

phts commented 8 months ago

@devgianlu great,! thanks Please create a new version to be able test it

Cc @volumio

volumio commented 8 months ago

@phts synced with @devgianlu let's test by compiling and testing it, so then we can provide feebdacks to @devgianlu if that works. Note, to make it work we shall always keep zeroconf_enabled = true

phts commented 8 months ago

@devgianlu

still need new release to try it 🙏

devgianlu commented 8 months ago

I have released v0.0.13 with some other features and fixes: https://github.com/devgianlu/go-librespot/releases/tag/v0.0.13

phts commented 7 months ago

With 0.13.0 version:

Playing using signed in mode, stopped, and after some time of inactivity (I tried half of day) app does not play anymore, after sending /player/play it does not produce any events:

Screenshot_20240211-110556~2

Need to restart consumer app (means ws connection) to make it work.

With 0.12.0 it never happened :

Screenshot_20240211-112639

devgianlu commented 7 months ago

Did you try playing from the Spotify app (via Connect)? Also, do you have the logs from go-librespot?

phts commented 7 months ago

How to make it producing log file and where to find it?

devgianlu commented 7 months ago

With SSH access you can do journalctl -u go-librespot-daemon --since today -f, not sure how to do it from the dev page. @volumio

phts commented 7 months ago

No worries, I have access to ssh 😸

phts commented 7 months ago

Logs and my comments inside

Feb 11 18:21:26 phts-np-01 go-librespot[26608]: time="2024-02-11T18:21:26+01:00" level=info msg="loaded track \"Nasze Słońce\" (uri: spotify:track:5iprUHzH3rdcCDs6IT2D97, paused: false, position: 0ms, duration: 225484ms)"
Feb 11 18:21:26 phts-np-01 go-librespot[26608]: time="2024-02-11T18:21:26+01:00" level=debug msg="fetched chunk 1/19, size: 524288"
Feb 11 18:21:26 phts-np-01 go-librespot[26608]: time="2024-02-11T18:21:26+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 11 18:21:26 phts-np-01 go-librespot[26608]: time="2024-02-11T18:21:26+01:00" level=trace msg="emitting websocket event: metadata"
Feb 11 18:21:26 phts-np-01 go-librespot[26608]: time="2024-02-11T18:21:26+01:00" level=debug msg="fetched chunk 3/19, size: 524288"
Feb 11 18:21:26 phts-np-01 go-librespot[26608]: time="2024-02-11T18:21:26+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 11 18:21:26 phts-np-01 go-librespot[26608]: time="2024-02-11T18:21:26+01:00" level=trace msg="emitting websocket event: playing"
Feb 11 18:21:26 phts-np-01 go-librespot[26608]: time="2024-02-11T18:21:26+01:00" level=debug msg="fetched chunk 2/19, size: 524288"
Feb 11 18:21:30 phts-np-01 go-librespot[26608]: time="2024-02-11T18:21:30+01:00" level=debug msg="pause track at 6916ms"
Feb 11 18:21:30 phts-np-01 go-librespot[26608]: time="2024-02-11T18:21:30+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 11 18:21:30 phts-np-01 go-librespot[26608]: time="2024-02-11T18:21:30+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 11 18:21:30 phts-np-01 go-librespot[26608]: time="2024-02-11T18:21:30+01:00" level=trace msg="emitting websocket event: paused"

// here I paused and just didnt do anything....

Feb 11 18:44:16 phts-np-01 go-librespot[26608]: time="2024-02-11T18:44:16+01:00" level=debug msg="put connect state inactive"
Feb 11 18:44:16 phts-np-01 go-librespot[26608]: time="2024-02-11T18:44:16+01:00" level=trace msg="emitting websocket event: inactive"
Feb 11 18:44:16 phts-np-01 go-librespot[26608]: time="2024-02-11T18:44:16+01:00" level=error msg="failed receiving dealer message" error="failed to get reader: received close frame: status = StatusGoingAway and reason = \"\""
Feb 11 18:44:16 phts-np-01 go-librespot[26608]: time="2024-02-11T18:44:16+01:00" level=error msg="failed receiving packet" error="failed reading packet header: read tcp 192.168.0.102:58150->104.199.65.124:4070: use of closed network connection"

// at 18:48 I tried to play - and it didnt play anymore, and seems to not produce any logs anymore regarding those events.
// So there are logs above which where shown during innactivity. 
// You can see that it is reproducable even after 25 min of innactivity

// After I tried Connect, and it works:

Feb 11 18:49:33 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:33+01:00" level=debug msg="obtained new client token: AACAH/xxx="
Feb 11 18:49:33 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:33+01:00" level=debug msg="completed keyexchange"
Feb 11 18:49:33 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:33+01:00" level=debug msg="completed challenge"
Feb 11 18:49:33 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:33+01:00" level=debug msg="authenticated as xxx"
Feb 11 18:49:33 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:33+01:00" level=debug msg="authenticated as xxx"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=debug msg="dealer connection opened"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=info msg="accepted zeroconf user xxx from Pixel 6a"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=debug msg="received connection id: xxx="
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=debug msg="put connect state because NEW_DEVICE"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=debug msg="handling transfer player command from 5fefda75fbc1e24848cceb417a660b861bc2da09"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=trace msg="fetched new page 0 with 5 items (list: 5)"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=trace msg="fetched new page 1 with 19 items (list: 24)"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=debug msg="loading track spotify:track:2r3Od6LuCNMJM0wlILTLXW (paused: false, position: 2813ms)"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=trace msg="emitting websocket event: will_play"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:2r3Od6LuCNMJM0wlILTLXW"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=debug msg="requested aes key for file eb49513d840b98560894c6f49c6f1035ae6ef3eb, gid: 2r3Od6LuCNMJM0wlILTLXW"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=debug msg="fetched first chunk of 21, total size is 10765920 bytes"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=trace msg="seek to 2813ms (diff: 124ms, samples: 124053, bytes: 85694)"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=info msg="loaded track \"Karłowate\" (uri: spotify:track:2r3Od6LuCNMJM0wlILTLXW, paused: false, position: 2813ms, duration: 260785ms)"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=debug msg="fetched chunk 2/20, size: 524288"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=debug msg="fetched chunk 1/20, size: 524288"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=trace msg="emitting websocket event: metadata"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=trace msg="emitting websocket event: active"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=debug msg="sending successful reply for delaer request"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=debug msg="fetched chunk 3/20, size: 524288"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 11 18:49:34 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:34+01:00" level=trace msg="emitting websocket event: playing"
Feb 11 18:49:39 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:39+01:00" level=debug msg="handling pause player command from 5fefda75fbc1e24848cceb417a660b861bc2da09"
Feb 11 18:49:39 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:39+01:00" level=debug msg="pause track at 8659ms"
Feb 11 18:49:39 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:39+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 11 18:49:39 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:39+01:00" level=debug msg="sending successful reply for delaer request"
Feb 11 18:49:39 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:39+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 11 18:49:39 phts-np-01 go-librespot[26608]: time="2024-02-11T18:49:39+01:00" level=trace msg="emitting websocket event: paused"

// paused by connect

// After, played in signed-in mode again - works:

Feb 11 18:53:36 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:36+01:00" level=debug msg="pause track at 10566ms"
Feb 11 18:53:37 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:37+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 11 18:53:37 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:37+01:00" level=debug msg="pause track at 10566ms"
Feb 11 18:53:37 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:37+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 11 18:53:37 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:37+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Feb 11 18:53:37 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:37+01:00" level=debug msg="loading track spotify:track:1ysyXgakIuQWmmeLYArPEG (paused: false, position: 0ms)"
Feb 11 18:53:37 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:37+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 11 18:53:37 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:37+01:00" level=trace msg="emitting websocket event: will_play"
Feb 11 18:53:37 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:37+01:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:1ysyXgakIuQWmmeLYArPEG"
Feb 11 18:53:37 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:37+01:00" level=debug msg="requested aes key for file 734f105d0c02e49660057e4e9e73d798e1bf3f07, gid: 1ysyXgakIuQWmmeLYArPEG"
Feb 11 18:53:37 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:37+01:00" level=debug msg="fetched first chunk of 16, total size is 8172236 bytes"
Feb 11 18:53:37 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:37+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)"
Feb 11 18:53:37 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:37+01:00" level=info msg="loaded track \"Elektryczny prąd\" (uri: spotify:track:1ysyXgakIuQWmmeLYArPEG, paused: false, position: 0ms, duration: 175714ms)"
Feb 11 18:53:37 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:37+01:00" level=debug msg="fetched chunk 1/15, size: 524288"
Feb 11 18:53:37 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:37+01:00" level=debug msg="fetched chunk 3/15, size: 524288"
Feb 11 18:53:37 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:37+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 11 18:53:37 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:37+01:00" level=trace msg="emitting websocket event: metadata"
Feb 11 18:53:37 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:37+01:00" level=debug msg="fetched chunk 2/15, size: 524288"
Feb 11 18:53:37 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:37+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 11 18:53:37 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:37+01:00" level=trace msg="emitting websocket event: paused"
Feb 11 18:53:37 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:37+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 11 18:53:37 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:37+01:00" level=trace msg="emitting websocket event: paused"
Feb 11 18:53:37 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:37+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 11 18:53:37 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:37+01:00" level=trace msg="emitting websocket event: playing"
Feb 11 18:53:48 phts-np-01 go-librespot[26608]: time="2024-02-11T18:53:48+01:00" level=debug msg="fetched chunk 4/15, size: 524288"
devgianlu commented 7 months ago

I think what's happening is that when the device goes inactive and zerconf_enabled is true the account will be logged out which is fine when playing from Connect because it'll re-authenticate, but for volumio it'll break since it expects a session to be there.

This could be fixed by not ever logging out the account that has been logged in with "signed-in" mode from the configuration file. This would also require to re-login that account after another Zeroconf account leaves.

I'll think about whether there could be other side effects and possibly implement it tomorrow.

devgianlu commented 7 months ago

@phts I have released v0.0.14 with a fix for this and some other improvements.

devgianlu commented 7 months ago

Closing this, if any problem comes around please open another issue.

phts commented 7 months ago

Working so far, thanks