Problem with installation on Raspberry Pi 3

Jan Potters

unread,

Oct 1, 2017, 10:45:04 AM10/1/17

to sonosp...@googlegroups.com

Hi,

I followed Martin Pergler instruction on how to install and run Sonospy on a Raspeberry Pi...Everything went well, the db is fine, the logs seems fine, no error... I tried with only 1 folder with 12 song first, the proxy server seems to be running... But Sonos controler will just not show the Sonospy. I tried both as WMP Mode and SMAPI.

I then tried the Windows version of Sonospy, and it works fine in both mode, Sonos shows 'Sonospy Music Service' in SMAPI mode, and I can play music.

But with the Raspberry Pi version, the 'Sonospy Music Service', always shows: "Unable to browse music - there was a problem connection to Sonospy".

My guess is that either:

1- The Raspberry Pi is not really running the Server, but how can I check ?

I see those line with 'sudo netstat -lptu':

Active Internet connections (only servers)

Proto Recv-Q Send-Q Local Address Foreign Address State PID/Program name

tcp 0 0 0.0.0.0:50118 0.0.0.0:* LISTEN 955/python

tcp 0 0 0.0.0.0:5900 0.0.0.0:* LISTEN 6400/vncserver-x11-

tcp 0 0 0.0.0.0:ssh 0.0.0.0:* LISTEN 416/sshd

tcp 0 0 192.168.2.75:50114 0.0.0.0:* LISTEN 955/python

tcp6 0 0 [::]:5900 [::]:* LISTEN 6400/vncserver-x11-

tcp6 0 0 [::]:ssh [::]:* LISTEN 416/sshd

udp 0 0 0.0.0.0:7900 0.0.0.0:* 955/python

udp 0 0 0.0.0.0:mdns 0.0.0.0:* 337/avahi-daemon: r

udp 0 0 0.0.0.0:1900 0.0.0.0:* 25251/python

udp 0 0 0.0.0.0:1900 0.0.0.0:* 955/python

udp 0 0 0.0.0.0:59788 0.0.0.0:* 25251/python

udp 0 0 0.0.0.0:bootpc 0.0.0.0:* 370/dhcpcd

udp 0 0 0.0.0.0:2149 0.0.0.0:* 25251/python

udp 0 0 0.0.0.0:2149 0.0.0.0:* 955/python

udp 0 0 0.0.0.0:54905 0.0.0.0:* 337/avahi-daemon: r

udp 0 0 0.0.0.0:35991 0.0.0.0:* 955/python

udp6 0 0 [::]:mdns [::]:* 337/avahi-daemon: r

udp6 0 0 [::]:38799 [::]:* 337/avahi-daemon: r

2- Maybe for some reason SONOS does not 'see' the Raspberry Pi... but they are on the same router.

Anyone can help please ?

Thanks

Jan

Jan Potters

unread,

Oct 1, 2017, 11:25:22 AM10/1/17

to sonosp...@googlegroups.com

Hi,

Maybe this can help, what I know so far, by trying to debug:

The service seems to be running correctly:

root@raspberrypi:~# ps au

USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND

root 474 0.0 0.3 5876 2876 tty1 Ss Sep30 0:00 /bin/login -f

root 489 0.0 3.8 138060 36072 tty7 Ssl+ Sep30 0:38 /usr/lib/xorg/Xorg :0 -seat seat0 -auth /var/run/lightdm/root/:0 -nolisten tcp vt7 -

pi 598 0.0 0.4 6180 4056 tty1 S+ Sep30 0:00 -bash

pi 850 0.0 0.4 6200 4272 pts/0 Ss Sep30 0:05 -bash

root 4474 0.0 0.3 7232 3344 pts/0 S 00:59 0:00 sudo -i

root 4478 0.0 0.4 6040 3996 pts/0 S 00:59 0:00 -bash

root 18775 0.0 0.3 7740 2892 pts/0 R+ 10:48 0:00 ps au

pi 32644 1.2 2.6 256600 25372 pts/0 Sl 00:45 7:37 python pycpoint.py -p -sSonospy=JanSonospy,Sonospy.db -r

The scan use to create the database did not create any errors or warnings:

./scan.py -v -d Sonospy.db /home/pi/Synology/music/flac/Adele > Test.log

Test.log is:

Database: /home/pi/Synology/raspberry/sspy/sonospy/Sonospy.db
Scanning: /home/pi/Synology/music/flac/Adele
Scannumber: 2
New file found: 01....
.... [List of all the files in the folder and subfolder]
Processing tags
Tags processed
./gettags.py -d Sonospy.db -v /home/pi/Synology/music/flac/Adele
./movetags.py -s Sonospy.db -d Sonospy.db -v

Mark Henkelis

unread,

Oct 1, 2017, 7:17:45 PM10/1/17

to sonosp...@googlegroups.com

It does appear that Sonospy is running on the pi.

You could stop it and start it from the command line to check whether it gives any error either on startup or when you try to access it from Sonos.

I don't have a Pi 3 - I guess the first thing to check is whether any defaults have changed in the OS. Martin noted that he didn't have to open any ports on the Pi, presumably because there wasn't a firewall running, is that still the case?

Are you able to access ports other than 80, 23 etc on the Pi from your computer?

Mark.

--
You received this message because you are subscribed to the Google Groups "Sonospy Development" group.
To unsubscribe from this group and stop receiving emails from it, send an email to sonospy-deve...@googlegroups.com.
To post to this group, send email to sonosp...@googlegroups.com.
Visit this group at https://groups.google.com/group/sonospy-devel.
For more options, visit https://groups.google.com/d/optout.

Jan Potters

unread,

Oct 1, 2017, 9:18:36 PM10/1/17

to sonosp...@googlegroups.com

New info...

I don't know exactly what made it, but I installed gstreamer and gmediarender, I don't know why one of them would be needed, but now the -w (WMP Server) shows in the SONOS Controler... The list and everything is there... the music is not added and not playing...

But I'm getting near, I feel it !

Jan Potters

unread,

Oct 1, 2017, 9:23:26 PM10/1/17

to Sonospy Development

Hi Mark,

Thanks for the reply.

Like I said in the previous comments, All the ports seems open, and I checked and double-check, there is no Firewall running also in this version of the RPi.

I did not find any errors in the log I checked...

Thanks,

Jan

Message has been deleted

Jan Potters

unread,

Oct 1, 2017, 9:56:51 PM10/1/17

to Sonospy Development

-s option still does not work... 'Unable to browse music - there was a problem connecting to Sonospy' !

-w option getting better, but getting 'An error occurred while adding songs to the Queue (701)'

running with -s in pycpoint.log

The server couldn't fulfil the request. Error code: 400, Reason: Bad Request

customsd call success: False, args: {'containerType': 'MService', 'secureUri': 'http://192.168.2.75:50114/smapi/control', 'authType': 'Anonymous', 'name': 'Argent', 'sid': '240', 'presentationMapVersion': '8', 'presentationMapUri': u'http://192.168.2.75:50114/5e0fc086-1c37-4648-805c-ec2aba2b0b27.xml', 'pollInterval': '30', 'uri': 'http://192.168.2.75:50114/smapi/control', 'caps': ['search', 'trFavorites', 'alFavorites', 'arFavorites', 'ucPlaylists']}

running with -w in pycpoint.log, nothing special in this file

Mark Henkelis

unread,

Oct 2, 2017, 7:18:43 PM10/2/17

to sonosp...@googlegroups.com

"customsd call success: False" after the 400 error says that the Pi can't register with the first ZP it finds.

It's trying to call http://<ZPIP>:1400/customsd - if you look in the customsd.py module you could add:

print zpip

underneath line 24 to see what IP it thinks it found (I'm assuming you truncated the log, I would expect it to log the ZPs it finds).

You can also point your PC browser to the presentationMapUri to check that the Pi is serving files and you can access it.

Jan Potters

unread,

Oct 3, 2017, 12:03:28 AM10/3/17

to Sonospy Development

Ok, some friend of mine told me to check if the iptables is set to maybe block something... From what I understant, it ain't:

root@raspberrypi:~# iptables -L -v

Chain INPUT (policy ACCEPT 4238 packets, 2700K bytes)

pkts bytes target prot opt in out source destination

Chain FORWARD (policy ACCEPT 0 packets, 0 bytes)

pkts bytes target prot opt in out source destination

Chain OUTPUT (policy ACCEPT 16918 packets, 5155K bytes)

pkts bytes target prot opt in out source destination

So clearly all ports are open and they have traffic on them...

I also checked with darkstatand I have in and out traffic from port 50119

I don't understand why there are no traffic on any other port of the pycpoint.ini list:

controlpoint_port=50111

proxy_port=50112

comms_port=50113

smapi_port=50114

wmp_proxy_port=50118

wmp_internal_port=50119

internal_proxy_udn=uuid:5e0fc086-1c37-4648-805c-ec2aba2b0b27

Jan Potters

unread,

Oct 3, 2017, 12:34:11 AM10/3/17

to Sonospy Development

Hi,

Thanks for the reply... Yes I had truncated the log... Here is the complete log, once I add the print zpip:

Args:

option.proxyonly: True

option.register: True

Music service: Sonospy=Argent,Argent.db

Proxy. Name: Argent

>>>> new device (from controller): Synology (DS216j) at http://192.168.2.44:5000 udn: uuid:73796E6F-6473-6D00-0000-0011326509a1

>>>> new device (from controller): MyBookLive at http://192.168.2.48:49152 udn: uuid:73656761-7465-7375-636b-0090a9b9dc6f

>>>> new device (from controller): Plex Media Server: JanSalon at http://192.168.2.20:32469 udn: uuid:65a9d652-719c-6b6f-b457-567119fb2060

>>>> new device (from controller): Home Hub 2000 Internet Gateway Device at http://192.168.2.1:49155 udn: uuid:75802409-bccb-40e7-8e6c-fa095ecce13e

>>>> new device (from controller): WPS Access Point at http://192.168.2.1:49152 udn: uuid:e57639d5-9fe8-5059-9ca5-073ace867622

>>>> new device (from controller): Home Hub 2000 at http://192.168.2.1:9000 udn: uuid:7076436f-6e65-1063-8074-4065a3a89288

>>>> new device (from controller): 192.168.2.13 - Sonos PLAY:1 at http://192.168.2.13:1400 udn: uuid:RINCON_000E58CA52EC01400

>>>> new device (from controller): 192.168.2.17 - Sonos BRIDGE at http://192.168.2.17:1400 udn: uuid:RINCON_000E58EEAB9601400

192.168.2.13

The server couldn't fulfil the request. Error code: 400, Reason: Bad Request

customsd call success: False, args: {'name': '', 'sid': '240'}

>>>> new device (from controller): WPS Access Point at http://192.168.2.1:49153 udn: uuid:f3dac14d-af2c-53f0-b300-07d0e7e9ece8

>>>> new device (from controller): Linksys00878 at http://192.168.2.24:49152 udn: uuid:31270056-1dd2-11b2-b5b6-c056270a1767

>>>> new device (from controller): 192.168.2.18 - Sonos PLAY:3 at http://192.168.2.18:1400 udn: uuid:RINCON_000E58FD905601400

>>>> new device (from controller): SALON-PC: Salon: at http://192.168.2.20:2869 udn: uuid:7c695ed2-f804-4d65-bb20-009fe58471d6

>>>> new device (from controller): 192.168.2.28 - Sonos CONNECT:AMP at http://192.168.2.28:1400 udn: uuid:RINCON_B8E937A740E001400

>>>> new device (from controller): 192.168.2.19 - Sonos PLAY:1 at http://192.168.2.19:1400 udn: uuid:RINCON_000E58CA9B2601400

The server couldn't fulfil the request. Error code: 400, Reason: Bad Request

customsd call success: False, args: {'containerType': 'MService', 'secureUri': 'http://192.168.2.75:50114/smapi/control', 'authType': 'Anonymous', 'name': 'Argent', 'sid': '240', 'presentationMapVersion': '10', 'presentationMapUri': u'http://192.168.2.75:50114/5e0fc086-1c37-4648-805c-ec2aba2b0b27.xml', 'pollInterval': '30', 'uri': 'http://192.168.2.75:50114/smapi/control', 'caps': ['search', 'trFavorites', 'alFavorites', 'arFavorites', 'ucPlaylists']}

Exception in thread Thread-198 (most likely raised during interpreter shutdown):Exception in thread Thread-192 (most likely raised during interpreter shutdown):Exception in thread Thread-199 (most likely raised during interpreter shutdown):Exception in thread Thread-195 (most likely raised during interpreter shutdown):Exception in thread Thread-197 (most likely raised during interpreter shutdown):Exception in thread Thread-202 (most likely raised during interpreter shutdown):

Exception in thread Thread-191 (most likely raised during interpreter shutdown):

I don't know if it has anything todo, but 192.168.2.13 (PLAY:1) is 'linked/attached' to 192.168.2.19 (also a PLAY:1) to form a stereo pair...

As for the 'presentationMapUri', this is what I get for http://192.168.2.75:50114/5e0fc086-1c37-4648-805c-ec2aba2b0b27.xml

<?xml version="1.0"?>

<Match>

</browseIconSizeMap>

</Match>

</PresentationMap>

<Match>

</SearchCategories>

</Match>

</PresentationMap>

</Presentation>

Mark Henkelis

unread,

Oct 3, 2017, 7:30:30 PM10/3/17

to sonosp...@googlegroups.com

To make sure it isn't the pair, you can give it an IP to use on the command line:

-z 192.168.2.28

The presentation map shows that Sonospy is serving requests.

Mark Henkelis

unread,

Oct 3, 2017, 7:31:54 PM10/3/17

to sonosp...@googlegroups.com

Some ports are only used for WMP, some for SMAPI.

Reply all

Reply to author

Forward