Sonos problems with Docker

Hi all

Sonos has been working flawlessly in OH2 and OH3 for a long time. Since about two weeks, all Sonos things are offline:

COMMUNICATION_ERROR
The UPnP device RINCON_3xxxxx is not registered.

I’m trying to remember if something has changed in my network, but can’t think of anything.
I currently don’t use the SamsungTV binding, saw a few posts that mention problems there.

Is anyone else facing problems with the Sonos binding?
How do I setup debugging again? Maybe I can provide more information with a debug log.

Thanks

Unfortunately, the problem has not changed. I switched on DEBUG log but I pretty much get the same messages here, i.e. when disabling and enabling a speaker again:

13:20:36.126 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'sonos:zoneplayer:RINCON_347E5CD0220B11400' changed from OFFLINE (COMMUNIC
ATION_ERROR): The UPnP device RINCON_347E5CD0220B11400 is not yet registered. to UNINITIALIZED                                                  
13:20:36.129 [DEBUG] [os.internal.handler.ZonePlayerHandler] - Handler disposed for thing sonos:zoneplayer:RINCON_347E5CD0220B11400             
13:20:36.131 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'sonos:zoneplayer:RINCON_347E5CD0220B11400' changed from UNINITIALIZED to
UNINITIALIZED (DISABLED)                                                                                                                        
13:20:38.277 [DEBUG] [ng.sonos.internal.SonosHandlerFactory] - Creating a ZonePlayerHandler for thing 'sonos:zoneplayer:RINCON_347E5CD0220E0140
0' with UDN 'RINCON_347E5CD0220B11400'
13:20:38.278 [DEBUG] [os.internal.handler.ZonePlayerHandler] - Creating a ZonePlayerHandler for thing 'sonos:zoneplayer:RINCON_347E5CD0220E0140
0'
13:20:38.281 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'sonos:zoneplayer:RINCON_347E5CD0220B11400' changed from UNINITIALIZED (DI
SABLED) to INITIALIZING                                                                                                                         
13:20:38.283 [DEBUG] [os.internal.handler.ZonePlayerHandler] - initializing handler for thing sonos:zoneplayer:RINCON_347E5CD0220B11400         
13:20:38.284 [DEBUG] [os.internal.handler.ZonePlayerHandler] - Polling job
13:20:38.284 [DEBUG] [os.internal.handler.ZonePlayerHandler] - UPnP device RINCON_347E5CD0220B11400 not yet registered

And then periodically:

13:23:38.289 [DEBUG] [os.internal.handler.ZonePlayerHandler] - Polling job 
13:23:38.290 [DEBUG] [os.internal.handler.ZonePlayerHandler] - UPnP device RINCON_347E5CD0220B11400 not yet registered

Any ideas?

One thing that comes to mind that has changed recently:
I switched my router to a Ubiquiti USG. For that, I installed the Unifi Controller on the same server where my OH3 is running in docker.

Looking at a few other posts about UPNP issues, port 1900 is mentioned. Checking netstat, I see port 1900 is open quite a few times including this entry:
udp 0 0 unifi:1900 0.0.0.0:*

Looking at the Unifi forum, port 1900 should only be used if you activate Make controller discoverable on L2 network which I haven’t.

Could that be the problem?
I tried stopping the Unifi controller, restarting OH3 which didn’t help.

As mentioned in another post, I moved the unifi controller to docker and don’t expose port 1900.
But still, Sonos things won’t come online :angry:
I’m out of ideas at the moment…

I would try running openhab in a VM because if you have other services running they might interfere with openhab. Even if the services run in docker the can use network_mode: host which exposes all networking to the container. I used virtualbox to run a VM under ubuntu server. I used phpvirtualbox installed in a docker container to administer virtualbox. I recomend using VM because docker can not isolate openhab because of how networking works in docker.

I don’t really have any other containers running in Host mode. Running a VM would probably solve it (as there’s nothing else running), but I really don’t want to go back that path.

I just create an openhab container on another computer. Same network, same docker-compose file. Did basic setup but only with Sonos binding (3.0.1) and Sonos is working.

This proves that it has something to do with my server, something else is running or blocking communication.

Looks like I really need to fire up Wireshark or analyze the network traffic to Sonos speakers to find the culprit.

I experience the same issue. Sonos binding has been working flawless for years. Running 2.5.5 on Raspberry PI 3 (Openhabian Jessie)

Recently I shutdown my pi to make a backup image. When I started to see the issues with Sonos, I discovered that v2.5.12 of the binding was installed, no idea how come. As I was worried that there might be a conflict with a older OpenHAB core, I ran an update to 2.5.12 via openhabian-config.

Sonos binding was ok right after the update, but now suddenly the devices are offline. I stopped and started the bundle via karaf and see this in the log. Not certain of this was always the case befor

2021-03-07 19:19:58.172 [ERROR] [org.openhab.binding.sonos           ] - bundle org.openhab.binding.sonos:2.5.12 (252)[org.openhab.binding.sonos.internal.SonosHandlerFactory] :  Cannot register component

java.lang.IllegalStateException: BundleContext is no longer valid

	at org.eclipse.osgi.internal.framework.BundleContextImpl.checkValid(BundleContextImpl.java:989) ~[org.eclipse.osgi-3.12.100.jar:?]

	at org.eclipse.osgi.internal.framework.BundleContextImpl.getBundle(BundleContextImpl.java:129) ~[org.eclipse.osgi-3.12.100.jar:?]

	at org.apache.felix.scr.impl.ComponentRegistry.checkComponentName(ComponentRegistry.java:226) ~[bundleFile:?]

	at org.apache.felix.scr.impl.BundleComponentActivator.loadDescriptor(BundleComponentActivator.java:442) [bundleFile:?]

	at org.apache.felix.scr.impl.BundleComponentActivator.initialize(BundleComponentActivator.java:314) [bundleFile:?]

	at org.apache.felix.scr.impl.BundleComponentActivator.<init>(BundleComponentActivator.java:269) [bundleFile:?]

	at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:380) [bundleFile:?]

etc etc etc

Will do some more troubleshooting this week and try to isolate the issue.

Still not solved. I’m actually considering setting up a small virtual machine running OH3 with only the Sonos binding for the sole purpose of updating my main OH3 instance through the new remote binding.
I tested it quickly: on other machines in docker or in a new VM using OH3 as system service, Sonos is working without any issues. I still don’t see where the difference on my server is.

Very ugly solution, but I don’t see any other solution right now… :nauseated_face:

Did someone change the title of this topic? I am quite sure it was not referring to docker at the moment I posted my reply.

Further to my previous post:

  • Based on the error message, I was thinking that probably some interaction issue between core and the binding. So I reinstalled the Sonos binding. No effect.
  • I flashed my backup image to a new card and rebooted: problem is gone. So, it seems like any (update?) activity in openhabian-config is triggering the issue.

I am not planning to do further investigations on my current version, since I am planning to move to OH3.

Ah yes, I did. Sorry, didn’t want to confuse. Wanted to make it a bit clearer as I’m pretty sure it is related to Docker in my case. Reading your answers again, you do seem to have to same problem but not related to Docker.

I was able to get it working again by shutting down the Unifi Docker container running on the same host although I still don’t see a clear connection. It even worked some time after restarting that, but the Things started flapping from ON to OFF and back again a few times.

I’m curious if the JUPNP bugfix mentioned here will solve my problem. Might give the 3.1 milestone a try for that. Unfortunately, I don’t think there’s going to be a backport for 2.X. I’ll report back if it works, then you’ll have a reason to upgrade to OH3 :wink:

No problem @pgruetter . From what I read over the past weeks, I also had started thinking in the direction of upnp. Since my setup is stable now, I will keep it like that for now. Good to know that 3.1 might have a bugfix. I will keep an eye on the release notes and then decide when/if I make the jump. Thanks for mentioning.

Unfortunately, upgrading to 3.1.0M2 did not solve it for me.

Turned on some more logs for JUPNP and see the following messages:


2021-03-16 13:14:33.323 [INFO ] [org.jupnp.transport.spi.StreamClient] - Timeout of 10 seconds while waiting for HTTP request to complete, aborting: (StreamRequestMessage) GET http://192.168.1.203:1400/xml/device_description.xml
2021-03-16 13:14:33.324 [WARN ] [p.protocol.RetrieveRemoteDescriptors] - Device descriptor retrieval failed, no response: http://192.168.1.203:1400/xml/device_description.xml

So it looks like OH3 is requesting details about the Sonos speaker, but doesn’t get a response.
Calling the URL with wget on the same machine returns the XML in a few milliseconds.
That’s very strange, I’m running OH3 with net=host.

Found a few related messages, especially concerning the Unifi Controller but they didn’t solve it for me :unamused: