balbuze / volumio-plugins

volumio's plugins from balbuze
190 stars 60 forks source link

Problem with multi-user support #267

Closed AaronPower closed 4 years ago

AaronPower commented 4 years ago

Hi, here to report another problem with multi-user settings. When connected using my credentials, everything works fine both in W10 and Android but when I turn on multi user, it is not possible to connect for anybody. Any quick tips? Any logs I can provide? Volspotconnect 1.0.1.

ashthespy commented 4 years ago

The multi-user aka discovery mode uses mdns and requires your network to be compatible. You can try launching the client with verbose logging to confirm that it's up and running.

cd /data/plugins/music_service/volspotconnect2/
RUST_LOG=libmdns=debug,librespot=debug,vollibrespot=trace ./vollibrespot -c volspotify.toml
AaronPower commented 4 years ago
```shell
RUST_LOG=libmdns=debug,librespot=debug,vollibrespot=trace ./vollibrespot -c volspotify.toml

Ash, thanks a lot for your support!
So, first of all I reboot volumio bunch of times and it became even more insteresting. 
A bit of background:
I actually have two volumio sessions running on two Rpis and I am trying to make them visible to Spotify on one PC and two Android phones. Now I can see one volumio on the PC and both phones even with Multi-user turned on (that is new). The other session is visible only to the devices where same Spotify credentials are used as were used on volumio when multi-user was off. 
Both instances should be set identically and running on identical devices with the exception of the malfunctioning one being equipped with WiFi dongle and running on WiFi. 
As it somehow works now I guess it is obvious that mdns is running.
But I assume that when I have two devices with one working and the other not, it should be relatively easy to find out the problem comparing the logs, isn't that so? If you're willing to walk me through creating them, I am happy to post them.
ashthespy commented 4 years ago

Some ideas

  1. Are both the devices in the same subnet?
  2. I some times have time out errors on the Windows client, and connecting once from an Android client fixes it for me.

As for the logs, you'll have to enable ssh, and connect to your device and run the command..

AaronPower commented 4 years ago

They are both hooked up to the same router, static IPs assigned by the router. Only one subnet on the router. For a while I thought it might be because one of them had static IP set in Volumio, the other one assigned by the router but the same behaviour remains even after correcting. I can't connect using Android client. I plan to fire up another pc tomorrow to see whether Windows client using different credentials will manage to connect. SSH is not an issue (Managed the verbose logging a while ago, right?). I just dunno how to pull the logs.

AaronPower commented 4 years ago

Thinking about it, I probably should try to connect the WiFied RPi using Ethernet as well. Another thing to test tomorrow.

ashthespy commented 4 years ago

Not sure what you mean by pull the logs, you can just select and copy it from the terminal.. More info on enabling ssh can be found in the Volumio docs Recommend you disable the running daemon (either by disabling the plugin from the WebUI or stopping the service) before running the previous command for the verbose logs.

Another quick test you could do is to use an mdns browser on your pc/phone and confirm if the daemon's broadcast is making it through your network..

AaronPower commented 4 years ago

Ok, i Will try mdns browser as well as running those commands after disabling the plugin in UI. What I mean is that I simply don't know where are the log files located. Seems I forgot to mention in my first post I am total noob in all things Linux. I have SSH enabled, I can run the terminal and I "might" manage to open the log to copy contents but that's where my experience ends. I have no idea about the file structure and where to look for those logs.

ashthespy commented 4 years ago

What I mean is that I simply don't know where are the log files located. Seems I forgot to mention in my first post I am total noob in all things Linux. I have SSH enabled, I can run the terminal and I "might" manage to open the log to copy contents but that's where my experience ends. I have no idea about the file structure and where to look for those logs.

Ah, the logs in this case is just the output the daemon writes to your terminal when you run those commands ;-) no files involved..

And don't worry, we all start in the same boat :-)

AaronPower commented 4 years ago

Got it! I thought there's bunch of parameters in those logs you had me run so they're probably somehow "tailored" just to check mdns or some such. Never occurred to me you want those and nothing else. They include my Spotify credentials as well as names of my devices. And themselves are probably useless to anyone dealing with the same issue in the future, only what you find out from them is relevant. Is there a way to send them to you directly (yeah, never used GitHub either) or should I post them here after clean-up?

ashthespy commented 4 years ago

I believe there still some confusion, the commands shouldn't involve your credentials or any sensitive information.. The first cd /data line just moves you to the right folder where the plugin is, and the second one starts the daemon, with some verbose logs. This should spit out a few lines on the terminal about the mdns server and incoming connections and such. You can then select them, copy it and past it here inside the code tags..

AaronPower commented 4 years ago

Which means all the following lines regarding connections which keep on appearing after that are normal functioning of the daemon, not the result of the commands you listed. Because if I keep the terminal window opened for an hour after executing the command, I will still be receiving messages about questions from the various devices in my network.

ashthespy commented 4 years ago

Which means all the following lines regarding connections which keep on appearing after that are normal functioning of the daemon, not the result of the commands you listed.

The command only toggles the log verbosity level for the internal modules of the daemon, doesn't alter the functionality of the daemon in anyway. It loads the config from the corresponding file. Try searching for RUST_LOG to get a better idea of what is going on in that command..

Because if I keep the terminal window opened for an hour after executing the command, I will still be receiving messages about questions from the various devices in my network.

I could imagine then it is functioning fine, but I wouldn't know without actually looking at the log.. The main question is what happens when you try and connect to it/list it in your Spotify client..

AaronPower commented 4 years ago

I will post the logs as soon as I get home. Unfortunately my router is not set up for SSH from the outside. You're right, it sure looks like mdns is running. But it's confusing like hell. I can identify most of the devices sending questions by their names but I can't see the phone which can't connect to one of Volumios. Funny thing is I can't see it even in the terminal of Volumio to which it can connect! Is there e.g. a way to list the names of the devices with their corresponding IP or physical address? My phone lists with it's Bluetooth name, the other one (the problematic one ) under something less obvious.

Dne st 6. 5. 2020 8:44 uživatel Ash notifications@github.com napsal:

Which means all the following lines regarding connections which keep on appearing after that are normal functioning of the daemon, not the result of the commands you listed.

The command only toggles the log verbosity level for the internal modules of the daemon, doesn't alter the functionality of the daemon in anyway. It loads the config from the corresponding file. Try searching for RUST_LOG to get a better idea of what is going on in that command..

Because if I keep the terminal window opened for an hour after executing the command, I will still be receiving messages about questions from the various devices in my network.

I could imagine then it is functioning fine, but I wouldn't know without actually looking at the log.. The main question is what happens when you try and connect to it/list it in your Spotify client..

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/balbuze/volumio-plugins/issues/267#issuecomment-624471360, or unsubscribe https://github.com/notifications/unsubscribe-auth/AH2GAANIILHA4OS3QOB72E3RQEBMLANCNFSM4MZECL4Q .

AaronPower commented 4 years ago

And because messages keep popping up, it's hard to pinpoint which appears right when I try to connect with this problematic phone. It was kind of obvious so I tried that already (what exactly appears on the terminal the moment I open the devices window in Spotify) but I couldn't see anything, to be honest.

Dne st 6. 5. 2020 8:56 uživatel Aaron aaronpower@gmail.com napsal:

I will post the logs as soon as I get home. Unfortunately my router is not set up for SSH from the outside. You're right, it sure looks like mdns is running. But it's confusing like hell. I can identify most of the devices sending questions by their names but I can't see the phone which can't connect to one of Volumios. Funny thing is I can't see it even in the terminal of Volumio to which it can connect! Is there e.g. a way to list the names of the devices with their corresponding IP or physical address? My phone lists with it's Bluetooth name, the other one (the problematic one ) under something less obvious.

Dne st 6. 5. 2020 8:44 uživatel Ash notifications@github.com napsal:

Which means all the following lines regarding connections which keep on appearing after that are normal functioning of the daemon, not the result of the commands you listed.

The command only toggles the log verbosity level for the internal modules of the daemon, doesn't alter the functionality of the daemon in anyway. It loads the config from the corresponding file. Try searching for RUST_LOG to get a better idea of what is going on in that command..

Because if I keep the terminal window opened for an hour after executing the command, I will still be receiving messages about questions from the various devices in my network.

I could imagine then it is functioning fine, but I wouldn't know without actually looking at the log.. The main question is what happens when you try and connect to it/list it in your Spotify client..

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/balbuze/volumio-plugins/issues/267#issuecomment-624471360, or unsubscribe https://github.com/notifications/unsubscribe-auth/AH2GAANIILHA4OS3QOB72E3RQEBMLANCNFSM4MZECL4Q .

AaronPower commented 4 years ago

Sorry, I am just guessing where the contents of the requested log end. I copied everything above the first "received question" line. This is the Volumio where Spotify Connect works correctly: vollibrespot v0.2.0 0c51076 2020-04-17 (librespot 8d65d82 2020-03-10) -- Built On 2020-04-17 Reading Config from "volspotify.toml" [Vollibrespot] : Using Alsa backend with device: plughw:0 [Vollibrespot] librespot_connect::discovery: Zeroconf server listening on 0.0.0.0:46591 [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" } [Vollibrespot] : Connecting to AP "gew1-accesspoint-b-fmt6.ap.spotify.com:443" [Vollibrespot] : Authenticated as "xxxxx" ! [Vollibrespot] librespot_core::session: new Session[0] [Vollibrespot] : Setting up new mixer: card:hw:0 mixer:PCM index:0 [Vollibrespot] : Alsa Mixer info min: -10239 (MilliBel(-9999999)[dB]) -- max: 400 (MilliBel(400)[dB]) HW: true [Vollibrespot] librespot_connect::spirc: new Spirc[0] [Vollibrespot] librespot_core::mercury: new MercuryManager [Vollibrespot] librespot_playback::player: new Player[0] [Vollibrespot] : Using alsa sink [Vollibrespot] librespot_connect::spirc: linear volume: 32767 [Vollibrespot] librespot_playback::player: command=AddEventSender [Vollibrespot] librespot_playback::mixer::alsamixer: Mapping volume [49.999%] 32767 [u16] ->> Alsa [83.015%] -14.07 [dB] - -1407 [i64] [Vollibrespot] librespot_playback::player: command=VolumeSet(32767) [Vollibrespot] vollibrespot::meta_pipe: Starting new MetaPipe[0] [Vollibrespot] : Metadata pipe established [Vollibrespot] vollibrespot: PlayerEvent:: VolumeSet { volume: 32767 } [Vollibrespot] : Event: Volume { volume_to_mixer: 32767 } [Vollibrespot] librespot_core::session: Session[0] strong=5 weak=2 [Vollibrespot] vollibrespot::meta_pipe: Event::Volume(49.999237048905165) [Vollibrespot] : Country: "XX" [Vollibrespot] librespot_core::mercury: subscribed uri=hm://remote/user/XXX/ count=0 [Vollibrespot] librespot_connect::spirc: kMessageTypeNotify "XXXX" 27c4c94171ecdf921288abafeda72995f9b36c39 1798867177 1588789282310 kPlayStatusPause And this is the other one: vollibrespot v0.2.0 0c51076 2020-04-17 (librespot 8d65d82 2020-03-10) -- Built On 2020-04-17 Reading Config from "volspotify.toml" [Vollibrespot] : Using Alsa backend with device: plughw:0 [Vollibrespot] librespot_connect::discovery: Zeroconf server listening on 0.0.0.0:38955 [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" } [Vollibrespot] libmdns::fsm: received question: IN _spotify-connect._tcp.local [Vollibrespot] : Connecting to AP "gew1-accesspoint-b-d8j9.ap.spotify.com:443" [Vollibrespot] : Authenticated as "xxxx" ! [Vollibrespot] librespot_core::session: new Session[0] [Vollibrespot] : Setting up new mixer: card:hw:0 mixer:PCM index:0 [Vollibrespot] : Alsa Mixer info min: -10239 (MilliBel(-9999999)[dB]) -- max: 400 (MilliBel(400)[dB]) HW: true [Vollibrespot] librespot_connect::spirc: new Spirc[0] [Vollibrespot] librespot_core::mercury: new MercuryManager [Vollibrespot] librespot_playback::player: new Player[0] [Vollibrespot] : Using alsa sink [Vollibrespot] librespot_connect::spirc: linear volume: 0 [Vollibrespot] librespot_playback::player: command=AddEventSender [Vollibrespot] librespot_playback::mixer::alsamixer: Toggling mute::True [Vollibrespot] librespot_playback::player: command=VolumeSet(0) [Vollibrespot] vollibrespot::meta_pipe: Starting new MetaPipe[0] [Vollibrespot] vollibrespot: PlayerEvent:: VolumeSet { volume: 0 } [Vollibrespot] : Metadata pipe established [Vollibrespot] librespot_core::session: Session[0] strong=5 weak=2 [Vollibrespot] : Country: "XX" [Vollibrespot] : Event: Volume { volume_to_mixer: 0 } [Vollibrespot] vollibrespot::meta_pipe: Event::Volume(0) [Vollibrespot] librespot_core::mercury: subscribed uri=hm://remote/user/aaronpower-10/ count=0 [Vollibrespot] librespot_connect::spirc: kMessageTypeNotify "XXXX" 27c4c94171ecdf921288abafeda72995f9b36c39 1798868284 1588789283417 kPlayStatusPause [Vollibrespot] librespot_connect::spirc: kMessageTypeNotify "xxxxxx" 14fd3e3356688b6b1f1c38cd7c85abd7533cff2c 1798868284 1588789283417 kPlayStatusStop

AaronPower commented 4 years ago

OK, I tried to connect the other RPi via Ethernet instead of WiFi and it popped up on all devices immediately. So the issue is somewhere around WiFi. Weird.

WalterBorgstein commented 4 years ago

Just to pitch in. Decided to update the package from 0.9.9 to the most recent. Removed package via UI, installed via SSH. Couldn't connect. Reset Volumio, disabled/enabled plugin. nothing. Entered user and pwd instead of multi user. Nothing. Than I thought let's try everything.

All is working including the Multi user device. I wasn't aware the UI install was working again?

If you need anything like logs let me know, willing to test this much used piece of software!

AaronPower commented 4 years ago

Hey, bumped into something what might be relevant: like I said repeatedly, I do have two Volumio devices in the same network. Despite that, Audio Outputs and Zones button in Volumio UI is greyed out.

ashthespy commented 4 years ago

@AaronPower From the logs, it seems like it is working fine: Here it looks like it uses pre-cached credentials..

vollibrespot v0.2.0 0c51076 2020-04-17 (librespot 8d65d82 2020-03-10) -- Built On 2020-04-17 Reading Config from "volspotify.toml" 
[Vollibrespot] : Using Alsa backend with device: plughw:0 [Vollibrespot] librespot_connect::discovery: Zeroconf server listening on 0.0.0.0:46591 
[Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" }
[Vollibrespot] : Connecting to AP "gew1-accesspoint-b-fmt6.ap.spotify.com:443" 
[Vollibrespot] : Authenticated as "xxxxx" ! 

Whereas the second one seems to be using the "multi-user" mode..

[Vollibrespot] libmdns::fsm: received question: IN _spotify-connect._tcp.local [Vollibrespot] 

OK, I tried to connect the other RPi via Ethernet instead of WiFi and it popped up on all devices immediately. So the issue is somewhere around WiFi. Weird.

devices in the same network. Despite that, Audio Outputs and Zones button in Volumio UI is greyed out.

I would take a look at your AP to see the mdns packets are making it through..

@WalterBorgstein

All is working including the Multi user device. I wasn't aware the UI install was working again?

The UI version is synced whenever there is a stable change. The git version is more a testing ground usually.. That being said, your install, uninstall issues normally occur cause Volumio doesn't sync config files to disk immediately, thus causing erratic issues b/w reinstalls sometimes. Its a good idea to do a volumio vrestart to restart the back end b/w a reinstall.

AaronPower commented 4 years ago

The "Authenticated as..." lines are in both logs, whatever that means. Any way of clearing the cache and making sure multi-user mode is really on?

I installed mdns browser as per your advice and I see both RPis right there with running services _Volumio, _http, _raop, _workstation._tcp. My router FW unfortunately doesn't support detailed traffic logging.

ashthespy commented 4 years ago

The "Authenticated as..." lines are in both logs, whatever that means. Any way of clearing the cache and making sure multi-user mode is really on?

Yep, the discovery and credentials are just one of the multiple method of authenticating your account to Spotify's servers. The discovery just passes tokens directly from one authenticated client to the daemon. Restart the daemon - if it show "Authenticated as.." without you actively connecting, then it has logged you in automatically.

AaronPower commented 4 years ago

OK. When RPi connected via Ethernet, multi-user works. When on WiFi, it doesn't. Volumio isn't visible for Spotify until I turn it multi-user off and insert my credentials. Is that consistent with mdns packets flow issue? How could I check whether mdns packets are going through the network properly? Like I said, I installed mdns browser plugin for Chrome and I see the IP of Volumio and four services listed. I see the same for the other Volumio where multi-user works properly. Is there any other way of doing this?

ashthespy commented 4 years ago

I assume your on windows?

> dns-sd -B _spotify-connect._tcp
AaronPower commented 4 years ago

I assume your on windows?

> dns-sd -B _spotify-connect._tcp

Sorry, probably don't know what to do with that. Is that a command? I just get: dns-sd: command not found.

ashthespy commented 4 years ago

You'll have to install Bonjour then.. https://developer.apple.com/bonjour/

AaronPower commented 4 years ago

You'll have to install Bonjour then.. https://developer.apple.com/bonjour/

Bonjour seems to be a dead end for me, I have no idea what to do with either Bonjour or Bonjour PPS. Anyway, I dug a bit deeper and found a router log confirming that not a single multicast packet went through my WiFi unlike through my LAN. That's it, isn't it? Proof that it's the router blocking the mDNS on my WiFi for som reason?

ashthespy commented 4 years ago

Bonjour should have dns-sd among other things..

But either way, looks like it's an issue with your network, it should be hopefully straight forward to look up your router and figure out what settings you have to adjust to fix it. Your router probably lets through only _http._tcp requests, which wont work in this case.. Good luck! :-)

AaronPower commented 4 years ago

Unfortunately it seems there will be an issue with my Sagemcom F@st 5655v2 AC. Proprietary FW and practically no available settings. I will see what ISP support tells me. Anyway, thank you for your patience and willingness to help, Ash. Great work!