[SOLVED] [OH3.1] Sonos binding: COMMUNICATION_ERROR/not registered with latest sonos firmware

rafael_09 · September 21, 2021, 8:20am

Hey!
Recently my Sonos Play1 is in the state “COMMUNICATION_ERROR/not registered”. Most recently, the Sonos (with ip 192.168.1.84) has made a firmware update to “64.3-19080” (S2).
I have now spent days to get it back online (eg Sonos - broadcasting between different subnets - #42 by csi_oh), but unfortunately without success.
My system is as follows:

All devices (eg OH and Sonos) are on the same network (192.168.1.X).
Everything works with the Sonos Controller App (Android)
the Openhab Sonos binding no longer recognizes the Sonos (Discovery also does not work)
i have a unifi AP installed

What I did:

sonos play1 complete reset

PING 192.168.1.84 (192.168.1.84) 56(84) bytes of data.
64 bytes from 192.168.1.84: icmp_seq=1 ttl=64 time=2.07 ms
64 bytes from 192.168.1.84: icmp_seq=2 ttl=64 time=2.21 ms
64 bytes from 192.168.1.84: icmp_seq=3 ttl=64 time=1.51 ms
64 bytes from 192.168.1.84: icmp_seq=4 ttl=64 time=1.63 ms

openhab>  bundle:list -s | grep -i jupnp
265 x Active x  80 x 2.6.0                 x org.jupnp
openhab> bundle:list -s | grep -i sonos
324 x Active x  80 x 3.1.0                 x org.openhab.binding.sonos

SoftwareVersion	64.3-19080
SWGen	2
SoftwareDate	2021-07-08 13:39:20.232255

http://192.168.1.84:1400/xml/device_description.xml → output is generated

tcpdump: verbose output suppressed, use -v[v]... for full protocol decode
listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes
    1  IP 192.168.1.84.33728 > 239.255.255.250.1900: UDP, length 502
    2  IP 192.168.1.84.33728 > 255.255.255.255.1900: UDP, length 502
    3  IP 192.168.1.84.33728 > 239.255.255.250.1900: UDP, length 555
    4  IP 192.168.1.84.33728 > 255.255.255.255.1900: UDP, length 555
    5  IP 192.168.1.84.33728 > 239.255.255.250.1900: UDP, length 505
    6  IP 192.168.1.84.49022 > 239.255.255.250.1900: UDP, length 232
6 packets captured
10 packets received by filter
0 packets dropped by kernel

as you can see, I can use the device completely and read all the info. However, it is no longer recognized by OH.
@epicurean @pstoermer @csi_oh @Lolodomo do you have any ideas?

Lolodomo · September 21, 2021, 10:53am

Reboot your Sonos device (unplug it and plug it again).
Restart also OH and wait for few minutes.
Thing should then be ONLINE.

rafael_09 · September 22, 2021, 7:24am

does not work, still offline …

rafael_09 · September 27, 2021, 12:10pm

here is my jupnp log:

13:48:19.065 [DEBUG] [org.jupnp.transport.Router           ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
13:48:20.578 [DEBUG] [jupnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.84:44319 on local interface: eth0 and address: 192.168.1.100
13:48:20.579 [DEBUG] [jupnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.84:44319 on local interface: veth8497ead and address: 192.168.1.100
13:48:20.579 [DEBUG] [jupnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.84:44319 on local interface: vethc7e52c4 and address: 192.168.1.100
13:48:20.581 [DEBUG] [jupnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.84:44319 on local interface: hassio and address: 192.168.1.100
13:48:20.582 [DEBUG] [org.jupnp.transport.Router           ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
13:48:20.579 [DEBUG] [jupnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.84:44319 on local interface: vethb051af7 and address: 192.168.1.100
13:48:20.584 [DEBUG] [org.jupnp.transport.Router           ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
13:48:20.585 [DEBUG] [org.jupnp.transport.Router           ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
13:48:20.581 [DEBUG] [org.jupnp.transport.Router           ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
13:48:20.579 [DEBUG] [jupnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.84:44319 on local interface: vetha415ce4 and address: 192.168.1.100
13:48:20.592 [DEBUG] [org.jupnp.transport.Router           ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
13:48:20.589 [DEBUG] [jupnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.84:44319 on local interface: veth1999760 and address: 192.168.1.100
13:48:20.585 [DEBUG] [org.jupnp.transport.Router           ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
13:48:20.596 [DEBUG] [org.jupnp.transport.Router           ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
13:48:20.592 [DEBUG] [np.protocol.RetrieveRemoteDescriptors] - Sending device descriptor retrieval message: (StreamRequestMessage) GET http://192.168.1.84:1400/xml/device_description.xml
13:48:20.603 [DEBUG] [jupnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.84:44319 on local interface: eth0 and address: 192.168.1.100
13:48:20.608 [DEBUG] [org.jupnp.transport.Router           ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
13:48:20.604 [DEBUG] [org.jupnp.transport.Router           ] - Sending via TCP unicast stream: (StreamRequestMessage) GET http://192.168.1.84:1400/xml/device_description.xml
13:48:20.829 [DEBUG] [jupnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.84:44319 on local interface: eth0 and address: 192.168.1.100
13:48:20.830 [DEBUG] [jupnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.84:44319 on local interface: hassio and address: 192.168.1.100
13:48:20.830 [DEBUG] [jupnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.84:44319 on local interface: veth1999760 and address: 192.168.1.100
13:48:20.830 [DEBUG] [jupnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.84:44319 on local interface: vethb051af7 and address: 192.168.1.100
13:48:20.830 [DEBUG] [jupnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.84:44319 on local interface: vethc7e52c4 and address: 192.168.1.100
13:48:20.830 [DEBUG] [jupnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.84:44319 on local interface: veth8497ead and address: 192.168.1.100
13:48:20.831 [DEBUG] [jupnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.84:44319 on local interface: vetha415ce4 and address: 192.168.1.100
13:48:20.834 [DEBUG] [org.jupnp.transport.Router           ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
13:48:20.840 [DEBUG] [org.jupnp.transport.Router           ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
13:48:20.846 [DEBUG] [org.jupnp.transport.Router           ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
13:48:20.847 [DEBUG] [org.jupnp.transport.Router           ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
13:48:20.849 [DEBUG] [jupnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.84:44319 on local interface: eth0 and address: 192.168.1.100
13:48:20.845 [DEBUG] [org.jupnp.transport.Router           ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
13:48:20.841 [DEBUG] [org.jupnp.transport.Router           ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
13:48:20.838 [DEBUG] [org.jupnp.transport.Router           ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
13:48:20.853 [DEBUG] [org.jupnp.transport.Router           ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
13:48:21.080 [DEBUG] [jupnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.84:44319 on local interface: eth0 and address: 192.168.1.100
13:48:21.083 [DEBUG] [org.jupnp.transport.Router           ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
13:48:21.080 [DEBUG] [jupnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.84:44319 on local interface: hassio and address: 192.168.1.100
13:48:21.087 [DEBUG] [jupnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.84:44319 on local interface: eth0 and address: 192.168.1.100
13:48:21.083 [DEBUG] [jupnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.84:44319 on local interface: vetha415ce4 and address: 192.168.1.100
13:48:21.082 [DEBUG] [jupnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.84:44319 on local interface: veth1999760 and address: 192.168.1.100
13:48:21.082 [DEBUG] [jupnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.84:44319 on local interface: vethb051af7 and address: 192.168.1.100
13:48:21.091 [DEBUG] [org.jupnp.transport.Router           ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
13:48:21.082 [DEBUG] [jupnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.84:44319 on local interface: veth8497ead and address: 192.168.1.100
13:48:21.082 [DEBUG] [jupnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.84:44319 on local interface: vethc7e52c4 and address: 192.168.1.100
13:48:21.091 [DEBUG] [org.jupnp.transport.Router           ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
13:48:30.615 [INFO ] [org.jupnp.transport.spi.StreamClient ] - Timeout of 10 seconds while waiting for HTTP request to complete, aborting: (StreamRequestMessage) GET http://192.168.1.84:1400/xml/device_description.xml
13:48:30.618 [WARN ] [np.protocol.RetrieveRemoteDescriptors] - Device descriptor retrieval failed, no response: http://192.168.1.84:1400/xml/device_description.xml

the url of my speaker (http://192.168.1.84:1400/xml/device_description.xml) is working…
the same problem is also here: Sonos, no players found - #13 by madboo
any idea why it’s failing?

rafael_09 · September 29, 2021, 8:56am

ok, i have found the problem:
i had a old installation of home assistant running. home assistant blocks the discovery function from other home systems.
i thought i stopped home assistant with systemctl, however home assistant continues to run in a docker container.
So I stopped all docker containers with “docker kill $(docker ps -q)”.
Now all upnp devices like sonos are found by OH again.
so if someone gets the error “COMMUNICATION_ERROR/not registered” again and the sonos device is in the same subnet, please check if other systems are running on the same host with upnp functionality and stop if necessary.