Sonos State not updating correctly

I have a problem similar to Inconsistent state reported by Sonos ‘State’ channels in that the state of Items representing my Sonos zone players aren’t updated as the zone players change state. I’ve tried a few versions of OpenHAB 3, including 3.4.0.M3. I’ve enabled TRACE level debugging and I can see messages coming back from the zone players, including the LED status, which seems to be correct. There never appear to be any messages related to playback state though. Any ideas?

As mentioned in the topic you linked, there was a fix in last August.

Please provide a detailed scenario to reproduce your (not working) case.

AFAIK, 3.4.0.M3 should include that fix, so it appears I have a similar, but different, problem.

I have 4 different Sonos devices all of which appear to have the same behavior of not notifying OpenHAB of playback state changes, so the corresponding items in OpenHAB appear NULL or UNDEF. Here’s some sample logging:

2022-10-25 08:14:58.318 [TRACE] [s.internal.handler.ZonePlayerHandler] - Received pair 'SoftwareVersion':'70.1-34112' (service 'DeviceProperties') for thing 'sonos:PLAY5:RINCON_949F3E52F9F801400'
2022-10-25 08:14:58.318 [TRACE] [s.internal.handler.ZonePlayerHandler] - Received pair 'DisplaySoftwareVersion':'14.18' (service 'DeviceProperties') for thing 'sonos:PLAY5:RINCON_949F3E52F9F801400'
2022-10-25 08:14:58.318 [TRACE] [s.internal.handler.ZonePlayerHandler] - Received pair 'MACAddress':'94:9F:3E:52:F9:F8' (service 'DeviceProperties') for thing 'sonos:PLAY5:RINCON_949F3E52F9F801400'
2022-10-25 08:14:58.318 [TRACE] [s.internal.handler.ZonePlayerHandler] - Received pair 'SerialNumber':'94-9F-3E-52-F9-F8:C' (service 'DeviceProperties') for thing 'sonos:PLAY5:RINCON_949F3E52F9F801400'
2022-10-25 08:14:58.318 [TRACE] [s.internal.handler.ZonePlayerHandler] - Received pair 'Flags':'0' (service 'DeviceProperties') for thing 'sonos:PLAY5:RINCON_949F3E52F9F801400'
2022-10-25 08:14:58.318 [TRACE] [s.internal.handler.ZonePlayerHandler] - Received pair 'IPAddress':'' (service 'DeviceProperties') for thing 'sonos:PLAY5:RINCON_949F3E52F9F801400'
2022-10-25 08:14:58.318 [TRACE] [s.internal.handler.ZonePlayerHandler] - Received pair 'HardwareVersion':'' (service 'DeviceProperties') for thing 'sonos:PLAY5:RINCON_949F3E52F9F801400'
2022-10-25 08:14:58.318 [TRACE] [s.internal.handler.ZonePlayerHandler] - Received pair 'CopyrightInfo':'© 2003-2021, Sonos, Inc. All rights reserved.' (service 'DeviceProperties') for thing 'sonos:PLAY5:RINCON_949F3E52F9F801400'
2022-10-25 08:14:58.319 [TRACE] [s.internal.handler.ZonePlayerHandler] - Received pair 'HTAudioIn':'0' (service 'DeviceProperties') for thing 'sonos:PLAY5:RINCON_949F3E52F9F801400'
2022-10-25 08:14:58.332 [TRACE] [s.internal.handler.ZonePlayerHandler] - Received pair 'CurrentZoneName':'Living Room' (service 'DeviceProperties') for thing 'sonos:PLAY5:RINCON_949F3E52F9F801400'
2022-10-25 08:14:58.334 [TRACE] [s.internal.handler.ZonePlayerHandler] - Received pair 'CurrentConfiguration':'1' (service 'DeviceProperties') for thing 'sonos:PLAY5:RINCON_949F3E52F9F801400'
2022-10-25 08:14:58.335 [TRACE] [s.internal.handler.ZonePlayerHandler] - Received pair 'CurrentIcon':'x-rincon-roomicon:living' (service 'DeviceProperties') for thing 'sonos:PLAY5:RINCON_949F3E52F9F801400'

which shows some information does come back from the Sonos. However, using tcpdump, no traffic is received while toggling playback from a Sonos controller app. Here’s the tcpdump command I’m using (IP address obfuscated):

tcpdump -n -p -i br0 host x.y.z.199 port 1400

Using a similar tcpdump with -s 0 -w to capture packets, I do see something suspicious, like this:

SUBSCRIBE /MediaRenderer/RenderingControl/Event HTTP/1.1
Accept-Encoding: gzip
User-Agent: Linux/5.15.5_p2-debian-sources UPnP/1.0 jUPnP/2.0
Connection: close
Timeout: Second-1800
Sid: uuid:RINCON_949F3E52F9F801400_sub0000004662
Host: x.y.z.199:1400

HTTP/1.1 412 Precondition Failed
Server: Linux UPnP/1.0 Sonos/70.1-34112 (ZPS6)
Connection: close

I’ve found some other reports (Lost connection after few hours of outage · Issue #163 · ebaauw/homebridge-zp · GitHub) of similar issues elsewhere. I did try power-cycling a zone player and restarting OpenHAB with no apparent improvement in behavior. Even at TRACE level, there doesn’t appear to be logging around this.

OK, a little more time with wireshark and I think I have a pretty good guess as to the root of the problem.

Frame 683: 415 bytes on wire (3320 bits), 415 bytes captured (3320 bits)
Ethernet II, Src: BIOSTARM_bf:a3:bf (00:30:67:x:y:z), Dst: Sonos_bb:12:5c (94:9f:3e:x:y:z)
Internet Protocol Version 4, Src: x.y.z.210, Dst: x.y.z.32
Transmission Control Protocol, Src Port: 45512, Dst Port: 1400, Seq: 1, Ack: 1, Len: 349
Hypertext Transfer Protocol
    SUBSCRIBE /MediaServer/ContentDirectory/Event HTTP/1.1\r\n
    Accept-Encoding: gzip\r\n
    User-Agent: Linux/5.15.5_p2-debian-sources UPnP/1.0 jUPnP/2.0\r\n
    Connection: close\r\n
    Nt: upnp:event\r\n
    Timeout: Second-1800\r\n
    Callback: <http://x.y.z.210:8080/upnpcallback/dev/RINCON_949F3EBB125C01400_MS/svc/upnp-org/ContentDirectory/event/cb>\r\n
    Host: x.y.z.32:1400\r\n
    [Full request URI: http://x.y.z.32:1400/MediaServer/ContentDirectory/Event]

Which isn’t going to work as I have OpenHAB bound to localhost, not the internal interface. It’s not obvious to me how to configure this securely in a straightforward manner. I don’t particularly want to expose the :8080/rest to the internal network.

So I understand it is not a binding problem but rather an unusual network setup you try to deploy.

You have the callback URL as a binding setting. Maybe (but not sure at all( it is what you need to adjust in your case?

Is there a callback URL in the binding settings? There’s “URL to use for playing notification sounds, e.g.” but I wouldn’t describe what I need as the “playing notification sounds” URL.

I don’t really have insight into how unusual my network config is or isn’t. I’m not comfortable having OpenHAB open without mTLS authentication in front of it which I provide with Apache HTTPD as a reverse proxy. I think this wanders more into architecture than a bug… it isn’t ideal for how I’d like to set things up that the REST API and the upnpcallback are listening on the same port… maybe there’s a way to adjust that inside OpenHAB although I’m handling it with another reverse proxy configuration in Apache.

As for the binding itself, in a perfect world the TRACE logging would produce enough clues that I wouldn’t resort to wireshark to debug this, but we don’t live in a perfect world.

For posterity, here’s the Apache reverse proxy config I used:

Listen x.y.z.210:8080

<VirtualHost x.y.z.210:8080>
    ErrorLog /var/log/apache2/upnpcallback.log
    DocumentRoot /dev/null
    ProxyPass "/upnpcallback/"

which seems to work for me.

I’m comfortable marking this resolved, although I think the security issues this architecture promotes are significant (and moderately difficult to address).

This topic was automatically closed 41 days after the last reply. New replies are no longer allowed.