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…
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
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
Are there any updates?
I faced the same issues with OH 3.1.
I‘ve set the network mode to host.
Scan does not return any item.
Adding manually does not work too.
The UPNP Browser on my phone Show the devices properly.
I’m a step closer. am i right with that logfile that the Discovery works but only the receiving of the device_description.xml is not working?
Could it be that JUPNP is using the wrong network card?
2021-11-17 12:40:24.220 [TRACE] [org.jupnp.transport.spi.StreamClient] - Preparing HTTP request: (StreamRequestMessage) GET http://192.168.3.1:49000/igd2desc.xml
2021-11-17 12:40:24.223 [TRACE] [org.jupnp.transport.spi.StreamClient] - Creating HTTP request. URI: 'http://192.168.3.1:49000/igd2desc.xml' method: 'GET'
2021-11-17 12:40:24.226 [TRACE] [org.jupnp.transport.spi.StreamClient] - Waiting 10 seconds for HTTP request to complete: (StreamRequestMessage) GET http://192.168.3.1:49000/igd2desc.xml
2021-11-17 12:40:24.227 [TRACE] [org.jupnp.transport.spi.StreamClient] - Preparing HTTP request: (StreamRequestMessage) GET http://192.168.3.1:49000/fboxdesc.xml
2021-11-17 12:40:24.230 [TRACE] [org.jupnp.transport.spi.StreamClient] - Creating HTTP request. URI: 'http://192.168.3.1:49000/fboxdesc.xml' method: 'GET'
2021-11-17 12:40:24.234 [TRACE] [org.jupnp.transport.spi.StreamClient] - Waiting 10 seconds for HTTP request to complete: (StreamRequestMessage) GET http://192.168.3.1:49000/fboxdesc.xml
2021-11-17 12:40:24.237 [TRACE] [org.jupnp.transport.spi.StreamClient] - Preparing HTTP request: (StreamRequestMessage) GET http://192.168.3.1:49000/l2tpv3.xml
2021-11-17 12:40:24.243 [TRACE] [org.jupnp.transport.spi.StreamClient] - Preparing HTTP request: (StreamRequestMessage) GET http://192.168.3.1:49000/igddesc.xml
2021-11-17 12:40:24.245 [TRACE] [org.jupnp.transport.spi.StreamClient] - Creating HTTP request. URI: 'http://192.168.3.1:49000/igddesc.xml' method: 'GET'
2021-11-17 12:40:24.245 [TRACE] [org.jupnp.transport.spi.StreamClient] - Creating HTTP request. URI: 'http://192.168.3.1:49000/l2tpv3.xml' method: 'GET'
2021-11-17 12:40:24.249 [TRACE] [org.jupnp.transport.spi.StreamClient] - Waiting 10 seconds for HTTP request to complete: (StreamRequestMessage) GET http://192.168.3.1:49000/l2tpv3.xml
2021-11-17 12:40:24.256 [TRACE] [org.jupnp.transport.spi.StreamClient] - Waiting 10 seconds for HTTP request to complete: (StreamRequestMessage) GET http://192.168.3.1:49000/igddesc.xml
2021-11-17 12:40:24.256 [TRACE] [org.jupnp.transport.spi.StreamClient] - Preparing HTTP request: (StreamRequestMessage) GET http://192.168.3.1:49000/avmnexusdesc.xml
2021-11-17 12:40:24.258 [TRACE] [org.jupnp.transport.spi.StreamClient] - Creating HTTP request. URI: 'http://192.168.3.1:49000/avmnexusdesc.xml' method: 'GET'
2021-11-17 12:40:24.260 [TRACE] [org.jupnp.transport.spi.StreamClient] - Waiting 10 seconds for HTTP request to complete: (StreamRequestMessage) GET http://192.168.3.1:49000/avmnexusdesc.xml
2021-11-17 12:40:24.372 [TRACE] [org.jupnp.transport.spi.StreamClient] - Preparing HTTP request: (StreamRequestMessage) GET http://192.168.3.35:1400/xml/device_description.xml
2021-11-17 12:40:24.374 [TRACE] [org.jupnp.transport.spi.StreamClient] - Creating HTTP request. URI: 'http://192.168.3.35:1400/xml/device_description.xml' method: 'GET'
2021-11-17 12:40:24.376 [TRACE] [org.jupnp.transport.spi.StreamClient] - Waiting 10 seconds for HTTP request to complete: (StreamRequestMessage) GET http://192.168.3.35:1400/xml/device_description.xml
2021-11-17 12:40:24.395 [TRACE] [org.jupnp.transport.spi.StreamClient] - Preparing HTTP request: (StreamRequestMessage) GET http://192.168.3.34:1400/xml/device_description.xml
2021-11-17 12:40:24.396 [TRACE] [org.jupnp.transport.spi.StreamClient] - Creating HTTP request. URI: 'http://192.168.3.34:1400/xml/device_description.xml' method: 'GET'
2021-11-17 12:40:24.398 [TRACE] [org.jupnp.transport.spi.StreamClient] - Waiting 10 seconds for HTTP request to complete: (StreamRequestMessage) GET http://192.168.3.34:1400/xml/device_description.xml
2021-11-17 12:40:24.426 [TRACE] [org.jupnp.transport.spi.StreamClient] - Preparing HTTP request: (StreamRequestMessage) GET http://192.168.3.36:1400/xml/device_description.xml
2021-11-17 12:40:24.427 [TRACE] [org.jupnp.transport.spi.StreamClient] - Creating HTTP request. URI: 'http://192.168.3.36:1400/xml/device_description.xml' method: 'GET'
2021-11-17 12:40:24.430 [TRACE] [org.jupnp.transport.spi.StreamClient] - Waiting 10 seconds for HTTP request to complete: (StreamRequestMessage) GET http://192.168.3.36:1400/xml/device_description.xml
2021-11-17 12:40:24.555 [TRACE] [org.jupnp.transport.spi.StreamClient] - Preparing HTTP request: (StreamRequestMessage) GET http://192.168.3.37:1400/xml/device_description.xml
2021-11-17 12:40:24.557 [TRACE] [org.jupnp.transport.spi.StreamClient] - Creating HTTP request. URI: 'http://192.168.3.37:1400/xml/device_description.xml' method: 'GET'
2021-11-17 12:40:24.559 [TRACE] [org.jupnp.transport.spi.StreamClient] - Waiting 10 seconds for HTTP request to complete: (StreamRequestMessage) GET http://192.168.3.37:1400/xml/device_description.xml
2021-11-17 12:40:24.593 [TRACE] [org.jupnp.transport.spi.StreamClient] - Preparing HTTP request: (StreamRequestMessage) GET http://192.168.3.33:1400/xml/device_description.xml
2021-11-17 12:40:24.594 [TRACE] [org.jupnp.transport.spi.StreamClient] - Creating HTTP request. URI: 'http://192.168.3.33:1400/xml/device_description.xml' method: 'GET'
2021-11-17 12:40:24.597 [TRACE] [org.jupnp.transport.spi.StreamClient] - Waiting 10 seconds for HTTP request to complete: (StreamRequestMessage) GET http://192.168.3.33:1400/xml/device_description.xml
2021-11-17 12:40:24.718 [TRACE] [org.jupnp.transport.spi.StreamClient] - Preparing HTTP request: (StreamRequestMessage) GET http://192.168.3.20:62667/
2021-11-17 12:40:24.720 [TRACE] [org.jupnp.transport.spi.StreamClient] - Creating HTTP request. URI: 'http://192.168.3.20:62667/' method: 'GET'
2021-11-17 12:40:24.721 [TRACE] [org.jupnp.transport.spi.StreamClient] - Waiting 10 seconds for HTTP request to complete: (StreamRequestMessage) GET http://192.168.3.20:62667/
2021-11-17 12:40:25.271 [TRACE] [org.jupnp.transport.spi.StreamClient] - Preparing HTTP request: (StreamRequestMessage) GET http://192.168.3.31:80/description.xml
2021-11-17 12:40:25.273 [TRACE] [org.jupnp.transport.spi.StreamClient] - Creating HTTP request. URI: 'http://192.168.3.31:80/description.xml' method: 'GET'
2021-11-17 12:40:25.276 [TRACE] [org.jupnp.transport.spi.StreamClient] - Waiting 10 seconds for HTTP request to complete: (StreamRequestMessage) GET http://192.168.3.31:80/description.xml
2021-11-17 12:40:32.222 [TRACE] [org.jupnp.transport.spi.StreamClient] - Preparing HTTP request: (StreamRequestMessage) GET http://192.168.3.36:1400/xml/group_description.xml
2021-11-17 12:40:32.226 [TRACE] [org.jupnp.transport.spi.StreamClient] - Creating HTTP request. URI: 'http://192.168.3.36:1400/xml/group_description.xml' method: 'GET'
2021-11-17 12:40:32.229 [TRACE] [org.jupnp.transport.spi.StreamClient] - Waiting 10 seconds for HTTP request to complete: (StreamRequestMessage) GET http://192.168.3.36:1400/xml/group_description.xml
2021-11-17 12:40:34.230 [INFO ] [org.jupnp.transport.spi.StreamClient] - Timeout of 10 seconds while waiting for HTTP request to complete, aborting: (StreamRequestMessage) GET http://192.168.3.1:49000/igd2desc.xml
2021-11-17 12:40:34.244 [INFO ] [org.jupnp.transport.spi.StreamClient] - Timeout of 10 seconds while waiting for HTTP request to complete, aborting: (StreamRequestMessage) GET http://192.168.3.1:49000/fboxdesc.xml
2021-11-17 12:40:34.254 [INFO ] [org.jupnp.transport.spi.StreamClient] - Timeout of 10 seconds while waiting for HTTP request to complete, aborting: (StreamRequestMessage) GET http://192.168.3.1:49000/l2tpv3.xml
2021-11-17 12:40:34.260 [INFO ] [org.jupnp.transport.spi.StreamClient] - Timeout of 10 seconds while waiting for HTTP request to complete, aborting: (StreamRequestMessage) GET http://192.168.3.1:49000/igddesc.xml
2021-11-17 12:40:34.262 [INFO ] [org.jupnp.transport.spi.StreamClient] - Timeout of 10 seconds while waiting for HTTP request to complete, aborting: (StreamRequestMessage) GET http://192.168.3.1:49000/avmnexusdesc.xml
2021-11-17 12:40:34.377 [INFO ] [org.jupnp.transport.spi.StreamClient] - Timeout of 10 seconds while waiting for HTTP request to complete, aborting: (StreamRequestMessage) GET http://192.168.3.35:1400/xml/device_description.xml
2021-11-17 12:40:34.400 [INFO ] [org.jupnp.transport.spi.StreamClient] - Timeout of 10 seconds while waiting for HTTP request to complete, aborting: (StreamRequestMessage) GET http://192.168.3.34:1400/xml/device_description.xml
2021-11-17 12:40:34.432 [INFO ] [org.jupnp.transport.spi.StreamClient] - Timeout of 10 seconds while waiting for HTTP request to complete, aborting: (StreamRequestMessage) GET http://192.168.3.36:1400/xml/device_description.xml
2021-11-17 12:40:34.561 [INFO ] [org.jupnp.transport.spi.StreamClient] - Timeout of 10 seconds while waiting for HTTP request to complete, aborting: (StreamRequestMessage) GET http://192.168.3.37:1400/xml/device_description.xml
2021-11-17 12:40:34.599 [INFO ] [org.jupnp.transport.spi.StreamClient] - Timeout of 10 seconds while waiting for HTTP request to complete, aborting: (StreamRequestMessage) GET http://192.168.3.33:1400/xml/device_description.xml
2021-11-17 12:40:34.724 [INFO ] [org.jupnp.transport.spi.StreamClient] - Timeout of 10 seconds while waiting for HTTP request to complete, aborting: (StreamRequestMessage) GET http://192.168.3.20:62667/
2021-11-17 12:40:35.278 [INFO ] [org.jupnp.transport.spi.StreamClient] - Timeout of 10 seconds while waiting for HTTP request to complete, aborting: (StreamRequestMessage) GET http://192.168.3.31:80/description.xml
2021-11-17 12:40:35.975 [TRACE] [org.jupnp.transport.spi.StreamClient] - Preparing HTTP request: (StreamRequestMessage) GET http://192.168.3.37:1400/xml/device_description.xml
2021-11-17 12:40:35.977 [TRACE] [org.jupnp.transport.spi.StreamClient] - Creating HTTP request. URI: 'http://192.168.3.37:1400/xml/device_description.xml' method: 'GET'
2021-11-17 12:40:35.980 [TRACE] [org.jupnp.transport.spi.StreamClient] - Waiting 10 seconds for HTTP request to complete: (StreamRequestMessage) GET http://192.168.3.37:1400/xml/device_description.xml
pi@raspi:~ $ sudo docker exec -it openhab3_openhab_1 bash
root@raspi:/openhab# curl -v http://192.168.3.35:1400/xml/device_description.xml | head -10
* Expire in 0 ms for 6 (transfer 0x1c9e8b0)
* Trying 192.168.3.35...
* TCP_NODELAY set
* Expire in 200 ms for 4 (transfer 0x1c9e8b0)
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0* Connected to 192.168.3.35 (192.168.3.35) port 1400 (#0)
> GET /xml/device_description.xml HTTP/1.1
> Host: 192.168.3.35:1400
> User-Agent: curl/7.64.0
> Accept: */*
>
< HTTP/1.1 200 OK
< Content-Type: text/xml
< Transfer-Encoding: chunked
< Server: Linux UPnP/1.0 Sonos/65.1-21040 (ANVIL)
< Connection: close
<
{ [1309 bytes data]
<?xml version="1.0" encoding="utf-8" ?>
<root xmlns="urn:schemas-upnp-org:device-1-0">
<specVersion>
<major>1</major>
<minor>0</minor>
</specVersion>
<device>
<deviceType>urn:schemas-upnp-org:device:ZonePlayer:1</deviceType>
<friendlyName>192.168.3.35 - Sonos Sub</friendlyName>
<manufacturer>Sonos, Inc.</manufacturer>
100 5192 0 5192 0 0 241k 0 --:--:-- --:--:-- --:--:-- 253k
* Closing connection 0
(23) Failed writing body
root@raspi:/openhab# exit
exit
pi@raspi:~ $ curl -v http://192.168.3.35:1400/xml/device_description.xml | head -10
* Expire in 0 ms for 6 (transfer 0x133a8b0)
* Trying 192.168.3.35...
* TCP_NODELAY set
* Expire in 200 ms for 4 (transfer 0x133a8b0)
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0* Connected to 192.168.3.35 (192.168.3.35) port 1400 (#0)
> GET /xml/device_description.xml HTTP/1.1
> Host: 192.168.3.35:1400
> User-Agent: curl/7.64.0
> Accept: */*
>
< HTTP/1.1 200 OK
< Content-Type: text/xml
< Transfer-Encoding: chunked
< Server: Linux UPnP/1.0 Sonos/65.1-21040 (ANVIL)
< Connection: close
<
{ [1309 bytes data]
<?xml version="1.0" encoding="utf-8" ?>
<root xmlns="urn:schemas-upnp-org:device-1-0">
<specVersion>
<major>1</major>
<minor>0</minor>
</specVersion>
<device>
<deviceType>urn:schemas-upnp-org:device:ZonePlayer:1</deviceType>
<friendlyName>192.168.3.35 - Sonos Sub</friendlyName>
<manufacturer>Sonos, Inc.</manufacturer>
100 5192 0 5192 0 0 144k 0 --:--:-- --:--:-- --:--:-- 153k
* Closing connection 0
(23) Failed writing body
so now I’m a bit lost to be honest overall i guess I have the same issue as @pgruetter.
It seems I can detect the devices but when then StreamClient tries to get the description it fails. (As shown below).
2021-11-17 13:34:27.331 [DEBUG] [org.jupnp.transport.Router ] - Sending via TCP unicast stream: (StreamRequestMessage) GET http://192.168.3.31:80/description.xml
2021-11-17 13:34:27.332 [TRACE] [org.jupnp.transport.spi.StreamClient] - Preparing HTTP request: (StreamRequestMessage) GET http://192.168.3.31:80/description.xml
2021-11-17 13:34:27.334 [TRACE] [org.jupnp.transport.spi.StreamClient] - Creating HTTP request. URI: 'http://192.168.3.31:80/description.xml' method: 'GET'
2021-11-17 13:34:27.336 [TRACE] [org.jupnp.transport.spi.StreamClient] - Waiting 10 seconds for HTTP request to complete: (StreamRequestMessage) GET http://192.168.3.31:80/description.xml
2021-11-17 13:34:27.372 [DEBUG] [org.jupnp.transport.Router ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2021-11-17 13:34:27.422 [DEBUG] [org.jupnp.transport.Router ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2021-11-17 13:34:27.472 [DEBUG] [org.jupnp.transport.Router ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2021-11-17 13:34:27.521 [DEBUG] [org.jupnp.transport.Router ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2021-11-17 13:34:27.571 [DEBUG] [org.jupnp.transport.Router ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2021-11-17 13:34:37.338 [INFO ] [org.jupnp.transport.spi.StreamClient] - Timeout of 10 seconds while waiting for HTTP request to complete, aborting: (StreamRequestMessage) GET http://192.168.3.31:80/description.xml
@Kai : is there a way to Specifiy the interface that should be used to resolve this description.xml?
Unfortunately, no update from my side. I ended up installing a very small virtual machine (VirtualBox) with a second OH3 installation only for the Sonos things
I then use the remote binding to connect the two OH3 instances. Works perfectly, but obviously a huge overkill.
Since I’m trying to get rid of the VM, I’ll probably install the same thing on a raspberry pi.
Strangely enough, on my main OH3 installation, the Sonos speakers did turn up in the inbox. So at least at some point in time, they were detected by OH3.
The funny thing is, if i comment the influx db (so that it will not startup) the whole system is working without any issues.
I still think that too many Network Interfaces in the System cause this behaviour.
The JUPNP used is listening and broadcasting on all interfaces even if I’ve specified the interface in the OpenHabUI.
OK, thought maybe you have used another port but that’s the default and I still can’t see how that interferes with UPNP.
Anyway, to get rid of my virtual machine, I now installed the second openhab instance on a raspberry pi. I have one running pihole and I just installed openhab on that one. I only have the Sonos things / items and connect to the main openhab installation via the remote binding. Solves it for me.
xxxxxx and yyyyy are the IP addresses of a DLNA MediaServer and a Sonos device. From within the openhab container, I can successfully curl to both this urls.
In my case, running influxdb with network_mode host vs with port 8086 exposed doesn’t make a difference.
I’m using pfSense as router and I’ve added a LAN rule to specifically allow LAN 1400 and 8200 ports, just in case.
The only difference in my case is that I added a nginx reverse proxy to the stack.
@FranzS - Do you have this working by just setting the influxdb network mode to host?
EDIT: @pgruetter - I’ll have to implement your workaround for now. Thanks.