JSON-RPC does not reach snapserver.

[matrix321321]

Hi @atoomic. I installed snapcast-volume-ui (0.12) and snapserver (0.12). So far so good. I was able to set the volumes with the UI for a short time. But now I can´t figure out to get it work again. I can reach the volume-ui at port 5000, set the volumes but the snapserver does not receive the RPC (nothing comes up at xxx.xxx.xxx:1705 and the volume does not change. When I recall the page the old unchanged values appear again. I tried to restart the whole chain (Snapclients, Snapserver, snapcast volume UI) without success. It is possible for me to set the volumes and mute all my clients with the android app but not with the UI.
I tailed "tail -f /var/log/syslog |grep -e snap" to see what´s going on @snapserver. Then I started ./devel-server
I attached the "log" below do you have any clue what I do wrong ?

user@wohnzimmer:~/snapcast-volume-ui$ ./devel-server
Watching . bin/lib bin/app.psgi for file updates.
HTTP::Server::PSGI: Accepting connections at http://0:5000/

[snapdance:11942] core @2018-02-03 19:23:13> looking for get / in /usr/local/share/perl/5.22.1/Dancer2/Core/App.pm l. 36
[snapdance:11942] core @2018-02-03 19:23:13> Entering hook core.app.before_request in (eval 172) l. 1

Feb 3 19:23:13 wohnzimmer snapserver[11332]: ControlServer::NewConnection: ::ffff:127.0.0.1
Feb 3 19:23:13 wohnzimmer snapserver[11332]: Exception in ControlSession::reader(): read_until: End of file
[snapdance:11942] core @2018-02-03 19:23:13> Entering hook core.app.after_request in (eval 172) l. 1

192.168.1.82 - - [03/Feb/2018:19:23:13 +0100] "GET / HTTP/1.1" 200 6798 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:58.0) Gecko/20100101 Firefox/58.0"

[snapdance:11942] core @2018-02-03 19:23:13> looking for get /img/sep-half.png in /usr/local/share/perl/5.22.1/Dancer2/Core/App.pm l. 36
[snapdance:11942] core @2018-02-03 19:23:13> Entering hook core.error.init in (eval 172) l. 1
[snapdance:11942] core @2018-02-03 19:23:13> Entering hook core.error.before in (eval 172) l. 1
[snapdance:11942] core @2018-02-03 19:23:13> Entering hook core.error.after in (eval 172) l. 1

192.168.1.82 - - [03/Feb/2018:19:23:13 +0100] "GET /img/sep-half.png HTTP/1.1" 404 445 "http://192.168.1.176:5000/css/main.css" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:58.0) Gecko/20100101 Firefox/58.0"

[snapdance:11942] core @2018-02-03 19:23:20> looking for get /api/setsound/badezimmer/25 in /usr/local/share/perl/5.22.1/Dancer2/Core/App.pm l. 36
[snapdance:11942] core @2018-02-03 19:23:20> Entering hook core.app.before_request in (eval 172) l. 1

Feb 3 19:23:20 wohnzimmer snapserver[11332]: ControlServer::NewConnection: ::ffff:127.0.0.1
Feb 3 19:23:20 wohnzimmer snapserver[11332]: Session inactive. Removing
Feb 3 19:23:20 wohnzimmer snapserver[11332]: Exception in ControlSession::reader(): read_until: End of file
[snapdance:11942] core @2018-02-03 19:23:20> Entering hook core.app.after_request in (eval 172) l. 1
192.168.1.82 - - [03/Feb/2018:19:23:20 +0100] "GET /api/setsound/badezimmer/25 HTTP/1.1" 200 42 "http://192.168.1.176:5000/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:58.0) Gecko/20100101 Firefox/58.0"
[snapdance:11942] core @2018-02-03 19:23:21> looking for get /api/setsound/badezimmer/62 in /usr/local/share/perl/5.22.1/Dancer2/Core/App.pm l. 36
[snapdance:11942] core @2018-02-03 19:23:21> Entering hook core.app.before_request in (eval 172) l. 1
Feb 3 19:23:21 wohnzimmer snapserver[11332]: ControlServer::NewConnection: ::ffff:127.0.0.1
Feb 3 19:23:21 wohnzimmer snapserver[11332]: Session inactive. Removing
Feb 3 19:23:21 wohnzimmer snapserver[11332]: Exception in ControlSession::reader(): read_until: End of file
[snapdance:11942] core @2018-02-03 19:23:21> Entering hook core.app.after_request in (eval 172) l. 1
192.168.1.82 - - [03/Feb/2018:19:23:21 +0100] "GET /api/setsound/badezimmer/62 HTTP/1.1" 200 42 "http://192.168.1.176:5 000/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:58.0) Gecko/20100101 Firefox/58.0"

My Config.yml:

...
snapcast:
  demo: 0
  server:
     host: 'localhost'
     port: 1705
  rooms:
    '[mac address 1]':
       color: '#0C0'
       name:  'Badezimmer'
    '[mac address 2]':
       color: '#C00'
       name:  'Kueche'
    '[mac address 3]':
       color: '#00C'
       name: 'Schlafzimmer'
    '[mac address 4]':
       color: '#e5c837'
       name: 'Wohnzimmer'
    '[mac address 5]':
       name: 'PiZero'
    '[mac address 6]':
       name: 'PiZero1'
  ignore:
     - '00:00:00:00:00:00'

[atoomic]

@matrix321321 I would first try replacing the hostname by its IP on your local network

[matrix321321]

@atoomic
you meant in the config.yml
instead of localhost (e.g. 192.168.1.176) ?
I tried but it does not help...

thank you.

[atoomic]

I mean try replacing 'localhost' for the server host entry
so this

snapcast:
  demo: 0
  server:
     host: 'localhost'

becomes

snapcast:
  demo: 0
  server:
     host: '192.168.1.176'

[matrix321321]

it does not work with replaced local ip insted of localhost..

[snapdance:2485] core @2018-02-03 21:04:31> looking for get /api/setsound/badezimmer/14 in /usr/local/share/perl/5.22.1/Dancer2/Core/App.pm l. 36
[snapdance:2485] core @2018-02-03 21:04:31> Entering hook core.app.before_request in (eval 172) l. 1
Feb 3 21:04:31 wohnzimmer snapserver[1507]: ControlServer::NewConnection: ::ffff:192.168.1.176
Feb 3 21:04:31 wohnzimmer snapserver[1507]: Session inactive. Removing
Feb 3 21:04:31 wohnzimmer snapserver[1507]: Exception in ControlSession::reader(): read_until: End of file
[snapdance:2485] core @2018-02-03 21:04:31> Entering hook core.app.after_request in (eval 172) l. 1
192.168.1.82 - - [03/Feb/2018:21:04:31 +0100] "GET /api/setsound/badezimmer/14 HTTP/1.1" 200 42 "http://192.168.1.176:5000/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:58.0) Gecko/20100101 Firefox/58.0"
[snapdance:2485] core @2018-02-03 21:04:33> looking for get / in /usr/local/share/perl/5.22.1/Dancer2/Core/App.pm l. 36
[snapdance:2485] core @2018-02-03 21:04:33> Entering hook core.app.before_request in (eval 172) l. 1
Feb 3 21:04:33 wohnzimmer snapserver[1507]: ControlServer::NewConnection: ::ffff:192.168.1.176
Feb 3 21:04:33 wohnzimmer snapserver[1507]: Session inactive. Removing
Feb 3 21:04:33 wohnzimmer snapserver[1507]: Exception in ControlSession::reader(): read_until: End of file
[snapdance:2485] core @2018-02-03 21:04:33> Entering hook core.app.after_request in (eval 172) l. 1
192.168.1.82 - - [03/Feb/2018:21:04:33 +0100] "GET / HTTP/1.1" 200 6798 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:58.0) Gecko/20100101 Firefox/58.0"
[snapdance:2485] core @2018-02-03 21:04:33> looking for get /img/sep-half.png in /usr/local/share/perl/5.22.1/Dancer2/Core/App.pm l. 36
[snapdance:2485] core @2018-02-03 21:04:33> Entering hook core.error.init in (eval 172) l. 1
[snapdance:2485] core @2018-02-03 21:04:33> Entering hook core.error.before in (eval 172) l. 1
[snapdance:2485] core @2018-02-03 21:04:33> Entering hook core.error.after in (eval 172) l. 1
192.168.1.82 - - [03/Feb/2018:21:04:33 +0100] "GET /img/sep-half.png HTTP/1.1" 404 445 "http://192.168.1.176:5000/css/main.css" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:58.0) Gecko/20100101 Firefox/58.0"

[matrix321321]

sudo netstat -ntlp | grep LISTEN
returns:
tcp6 0 0 :::1705 :::* LISTEN 1507/snapserver
but
tcp 0 0 0.0.0.0:5000 0.0.0.0:* LISTEN 3513/plackup

ipv6/ipv4 could this cause the problems ?

[matrix321321]

@atoomic I finally could figure out the problem:
My snapclients are Raspberry PIs (Unfortunately they have the same ID which causes problems with the Android app)
So I configured my snapclients with a forced hostID e.g. snapclient -d --hostID Badezimmer
The clients show up in the volume UI with e.g CLIENT FROM BADEZIMMER. In this case it is not possible to change the volume in the UI.
If I leave the original ID and make different instance numbers for every Rpi e.g. snapclient -d --instance 1 volume changes work with the UI. But the UI shows the ID

CLIENT FROM 98eb21b27607c4ea39cd2a315a0f0bc5#1

and not the name I would prefer

e.g. CLIENT FROM BADEZIMMER

Is there a way to get the name showing in the UI and not the ID ?
Thank you.

[atoomic]

this is strange, I m using snapcast v0.10 on raspberry pi, my client config only contains

START_SNAPCLIENT=true
SNAPCLIENT_OPTS="-d -h 10.0.0.1"

where 10.0.0.1 is the ip address of my server

You would probably need to understand why the raspberry pi have the same id.

I see have you tried using the ID instead of the mac address in the ui config?
This might work, if not I could try to have a look at it later this week, the change should be small and minimal.

[matrix321321]

I tried to replace the mac address with the ID in the config.yml and it didn´t work either.
But when trying these I found out that my forced hostIDs contained uppercase letters eg

"--hostID Badezimmer"

but in the server log snapdancer tries to change

"GET /api/setsound/badezimmer/50"

which did not work. So the fix is quite simple:
I replaced the Uppercase letters in the snapclient config to

snapclient -d --hostID badezimmer

and changing volumes works flawlessy with your UI and the Android APP ;-)
After that I tried to replace the mac address by the lowercase IDs in the config.yml and it works too ;-)

I think a change of this behaviour is not neccesary.... so we could close this issue or leave it if somebody runs into same troubles.....

@atoomic Thank you for your help and your great work again!

[atoomic]

Thanks for these informations, I think it's worth adding a new section FAQ explaining and maybe linking to this case. Other users might run in the same issue