Comments (61)
lolodomo
commented on June 24, 2024
I can confirm that audio and voice stuff is working well in OH 4.1.1.
So this was broken after 4.1 was released.
from openhab-core.
lolodomo
commented on June 24, 2024
from openhab-core.
openhab-bot
commented on June 24, 2024
This issue has been mentioned on openHAB Community. There might be relevant details there:
https://community.openhab.org/t/openhab-4-2-milestone-discussion/154316/36
from openhab-core.
GiviMAD
commented on June 24, 2024
Hello @lolodomo, I think it should be related to #4116 because I have the 4.2.0 snapshot running without it and voice features seems to work fine. I will try to take a look these afternoon.
from openhab-core.
GiviMAD
commented on June 24, 2024
Taking a quick look, I think this line in #4116 is incorrect:
Integer bitRate = Math.round(format.getFrameRate() * format.getSampleSizeInBits() * format.getChannels());
It should be:
Integer bitRate = Math.round(format.getSampleRate() * format.getSampleSizeInBits() * format.getChannels());
I don't know if that could be the problem.
from openhab-core.
GiviMAD
commented on June 24, 2024
I've also reviewed #3960 and I don't think I have broken this with it. The only one I think can affect these is the change in the AudioStream::equal method but I think it's ok and I don't see any other thing suspicious.
from openhab-core.
lolodomo
commented on June 24, 2024
@openhab/core-maintainers : am I alone to not be able to use OH 4.2 due to this critical issue ?
@GiviMAD : is audio working for you ?
How can we progress ? Do you need I enable some logs ?
from openhab-core.
GiviMAD
commented on June 24, 2024
Hello @lolodomo
I installed the 4.2.0M1 and audio is working fine for me. I don't have a Sonos device but I tested with the pulseaudiobinding and also with the MainUI webaudiosink and both text-to-speech and sounds seems to work. Can you check if it works for you using the webaudiosink? Maybe the problem is at the Sonos binding.
from openhab-core.
lolodomo
commented on June 24, 2024
The Sonos audio sink and more generally the Sonos binding was not changed in 4.2.
I will try the WEB audio sink.
from openhab-core.
lolodomo
commented on June 24, 2024
Audio and voice is working when using the WEB audio sink.
So that means something was changed in the core framework breaking only certain audio sinks.
There was no change in the Sonos audio sink in OH 4.2.
from openhab-core.
lolodomo
commented on June 24, 2024
I got these strange DEBUG logs from the Sonos audio sink !
12:46:29.531 [DEBUG] [os.internal.handler.ZonePlayerHandler] - playNotificationSoundURI: currentURI null metadata null
12:46:29.564 [DEBUG] [os.internal.handler.ZonePlayerHandler] - Notification feature not yet implemented while the current media is being played
from openhab-core.
lolodomo
commented on June 24, 2024
The Sonos binding seems to be broken in 4.2, I do not receive anymore some of the important messages from UPnP subscriptions. Channels are no more updated.
@wborn : OH 4.2 is packaged with a new version of JUPnP for which you made a lot of changes. It could be the origin of the problem. Does one of your changes in JUPnP require a change in the bindings ?
bundle:list -s | grep upnp
259 x Active x 80 x 3.0.0 x org.jupnp
260 x Active x 80 x 4.2.0.M1 x org.openhab.core.config.discovery.addon.upnp
261 x Active x 80 x 4.2.0.M1 x org.openhab.core.config.jupnp
287 x Active x 80 x 4.2.0.M1 x org.openhab.core.config.discovery.upnp
288 x Active x 80 x 4.2.0.M1 x org.openhab.core.io.transport.upnp
from openhab-core.
lolodomo
commented on June 24, 2024
In OH 4.1.1, JUPnP library is in version 2.7.1.OH1 and the Sonos binding is working well.
I am now convinced that the problem is not the audio stuff in general (sorry to ping you @GiviMAD ) but the new version of the JUPnP library that broke the Sonos binding (and probably other bindings) .
from openhab-core.
lolodomo
commented on June 24, 2024
I could try to install the old version of JUPnP library in OH 4.2M1 to confirm what I suspect but I am not yet sure how I can retrieve this old version (or build it).
Edit: ok, I can simply find the jar at this place runtime/system/org/jupnp/org.jupnp/2.7.1.OH1/org.jupnp-2.7.1.OH1.jar in my OH 4.1.1 installation.
from openhab-core.
GiviMAD
commented on June 24, 2024
I am now convinced that the problem is not the audio stuff in general (sorry to ping you @GiviMAD ) but the new version of the JUPnP library that broke the Sonos binding (and probably other bindings) .
No worries, happy to help!
from openhab-core.
wborn
commented on June 24, 2024
Does one of your changes in JUPnP require a change in the bindings ?
Not that I know of but there were many changes so there could also be regressions. The changes were mostly cleanup, upgrades and switching the build from tycho to bnd.
from openhab-core.
lolodomo
commented on June 24, 2024
Unfortunately; if I install the 2.7.1 version of the JUPnP bundle in OH 4.2M1, bundles including the Sonos binding are no more running. So I cannot prove that the problem is the new version of JUPnP but I am almost certain that it is.
from openhab-core.
lolodomo
commented on June 24, 2024
I don't know how to proceed now ?
from openhab-core.
lolodomo
commented on June 24, 2024
What is happening is that events from Sonos devices are no more arriving to the binding even if I see in logs that subscriptions to UPnP services are mentioned as succeeded.
from openhab-core.
lolodomo
commented on June 24, 2024
@wborn : if I can't simply update the jupnp bundle to another version like in the past, is it due to the bundle org.openhab.core.config.jupnp you introduced in PR #4098 ?
in addition to the update of the jupnp bundle itself, what should I do to switch to previous version of jupnp in my OH 4.2M1 ?
from openhab-core.
wborn
commented on June 24, 2024
The addon/core bundles will now have 3.0.0 as lowerbound in the jUPnP compatible version range so bundles will not properly resolve unless you recompile them or change the manifest manually.
from openhab-core.
lolodomo
commented on June 24, 2024
or change the manifest manually
You mean I should update manually the bundle version to 3.0.0 in the manifest of the old jupnp jar file ?
Would worth testing that.
from openhab-core.
wborn
commented on June 24, 2024
Yes that may be a quick way to find out if it is due to the upgrade.
from openhab-core.
lolodomo
commented on June 24, 2024
I tried.
I patched the manifest naming my version 3.0.0.OH42
I used "3.0.0..OH42" to differentiate with the official version which is "3.0.0".
When I update the bundle, some bundles remains in Waiting state.
openhab> bundle:list -s | grep upnp
259 x Active x 80 x 3.0.0.OH42 x org.jupnp
260 x Waiting x 80 x 4.2.0.M1 x org.openhab.core.config.discovery.addon.upnp
261 x Active x 80 x 4.2.0.M1 x org.openhab.core.config.jupnp
287 x Waiting x 80 x 4.2.0.M1 x org.openhab.core.config.discovery.upnp
288 x Waiting x 80 x 4.2.0.M1 x org.openhab.core.io.transport.upnp
openhab> bundle:list -s | grep sonos
283 x Waiting x 80 x 4.2.0.M1 x org.openhab.binding.sonos
If I restart OH, in a very first time, I can catch that
openhab> bundle:list -s | grep upnp
259 x Resolved x 80 x 3.0.0.OH42 x org.jupnp
260 x Installed x 80 x 4.2.0.M1 x org.openhab.core.config.discovery.addon.upnp
261 x Installed x 80 x 4.2.0.M1 x org.openhab.core.config.jupnp
287 x Installed x 80 x 4.2.0.M1 x org.openhab.core.config.discovery.upnp
288 x Installed x 80 x 4.2.0.M1 x org.openhab.core.io.transport.upnp
openhab> bundle:list -s | grep sonos
283 x Installed x 80 x 4.2.0.M1 x org.openhab.binding.sonos
but when the startup process ends, finally my jupnp bundle is automatically replaced by the official one having version 3.0.0.
openhab> bundle:list -s | grep upnp
259 x Active x 80 x 3.0.0 x org.jupnp
260 x Active x 80 x 4.2.0.M1 x org.openhab.core.config.discovery.addon.upnp
261 x Active x 80 x 4.2.0.M1 x org.openhab.core.config.jupnp
287 x Active x 80 x 4.2.0.M1 x org.openhab.core.config.discovery.upnp
288 x Active x 80 x 4.2.0.M1 x org.openhab.core.io.transport.upnp
openhab> bundle:list -s | grep sonos
283 x Active x 80 x 4.2.0.M1 x org.openhab.binding.sonos
Why my bundle is overwritten at startup ?
from openhab-core.
lolodomo
commented on June 24, 2024
I found something interesting in the logs at startup with the packaged JUPnP library (3.0.0), several lines of this kind:
21:00:02.381 [WARN ] [f.transport.servlet.ServletController] - Can't find the request for http://192.168.x.xxx:8080/upnpcallback/dev/RINCON_000E588EAE6601400_MR/svc/upnp-org/AVTransport/event/cb's Observer
This IP is the Wifi IP of my RPI, not the LAN IP.
In OH settings, I can see these two IP in the network settings but I selected the LAN IP as main network interface, not the Wifi interface.
I assume "f.transport.servlet.ServletController" is a class from JUPnP ? Why is my Wifi IP used ?
from openhab-core.
lolodomo
commented on June 24, 2024
Making slow progress with installation of the old JUPnP library.
Finally, I believe I found the culpit which was replacing my JUPnP bundle at startup. It was because I setup to not use suggestions !
Ok, I can see that the resolution is still failing for the other bundles. Maybe I should try with "3.0.1" rather than "3.0.0.OH42".
from openhab-core.
lolodomo
commented on June 24, 2024
Even with version "3.0.1", I still have problems:
21:47:40.116 [ERROR] [Events.Framework ] - FrameworkEvent ERROR
org.osgi.framework.BundleException: Could not resolve module: org.openhab.core.config.discovery.addon.upnp [260]
Unresolved requirement: Import-Package: org.jupnp; version="[3.0.0,4.0.0)"
at org.eclipse.osgi.container.Module.start(Module.java:463) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel$2.run(ModuleContainer.java:1847) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor$1$1.execute(EquinoxContainerAdaptor.java:136) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1840) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1783) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1745) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1667) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) [org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:345) [org.eclipse.osgi-3.18.0.jar:?]
21:47:40.165 [ERROR] [Events.Framework ] - FrameworkEvent ERROR
org.osgi.framework.BundleException: Could not resolve module: org.openhab.core.config.jupnp [261]
Unresolved requirement: Import-Package: org.jupnp; version="[3.0.0,4.0.0)"
at org.eclipse.osgi.container.Module.start(Module.java:463) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel$2.run(ModuleContainer.java:1847) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor$1$1.execute(EquinoxContainerAdaptor.java:136) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1840) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1783) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1745) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1667) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) [org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:345) [org.eclipse.osgi-3.18.0.jar:?]
Let's make a last try using 3.0.0 as version.
from openhab-core.
lolodomo
commented on June 24, 2024
Even with the jar manifest patched to version "3.0.0", the resolution is still failing:
21:55:33.398 [ERROR] [Events.Framework ] - FrameworkEvent ERROR
org.osgi.framework.BundleException: Could not resolve module: org.openhab.core.config.discovery.addon.upnp [260]
Unresolved requirement: Import-Package: org.jupnp; version="[3.0.0,4.0.0)"
at org.eclipse.osgi.container.Module.start(Module.java:463) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel$2.run(ModuleContainer.java:1847) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor$1$1.execute(EquinoxContainerAdaptor.java:136) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1840) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1783) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1745) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1667) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) [org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:345) [org.eclipse.osgi-3.18.0.jar:?]
21:55:33.447 [ERROR] [Events.Framework ] - FrameworkEvent ERROR
org.osgi.framework.BundleException: Could not resolve module: org.openhab.core.config.jupnp [261]
Unresolved requirement: Import-Package: org.jupnp; version="[3.0.0,4.0.0)"
at org.eclipse.osgi.container.Module.start(Module.java:463) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel$2.run(ModuleContainer.java:1847) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor$1$1.execute(EquinoxContainerAdaptor.java:136) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1840) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1783) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1745) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1667) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) [org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:345) [org.eclipse.osgi-3.18.0.jar:?]
21:55:35.633 [ERROR] [Events.Framework ] - FrameworkEvent ERROR
org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.hue [273]
Unresolved requirement: Import-Package: org.jupnp.model.meta; version="[3.0.0,4.0.0)"
Unresolved requirement: Import-Package: org.openhab.core.config.discovery.upnp
-> Export-Package: org.openhab.core.config.discovery.upnp; bundle-symbolic-name="org.openhab.core.config.discovery.upnp"; bundle-version="4.2.0.M1"; version="4.2.0"; uses:="org.jupnp.model.meta,org.openhab.core.config.discovery,org.openhab.core.thing"
org.openhab.core.config.discovery.upnp [287]
Unresolved requirement: Import-Package: org.jupnp; version="[3.0.0,4.0.0)"
at org.eclipse.osgi.container.Module.start(Module.java:463) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel$2.run(ModuleContainer.java:1847) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor$1$1.execute(EquinoxContainerAdaptor.java:136) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1840) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1783) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1745) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1667) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) [org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:345) [org.eclipse.osgi-3.18.0.jar:?]
21:55:35.714 [ERROR] [Events.Framework ] - FrameworkEvent ERROR
org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.lgwebos [274]
Unresolved requirement: Import-Package: org.jupnp.model.meta; version="[3.0.0,4.0.0)"
Unresolved requirement: Import-Package: org.openhab.core.config.discovery.upnp
-> Export-Package: org.openhab.core.config.discovery.upnp; bundle-symbolic-name="org.openhab.core.config.discovery.upnp"; bundle-version="4.2.0.M1"; version="4.2.0"; uses:="org.jupnp.model.meta,org.openhab.core.config.discovery,org.openhab.core.thing"
org.openhab.core.config.discovery.upnp [287]
Unresolved requirement: Import-Package: org.jupnp; version="[3.0.0,4.0.0)"
at org.eclipse.osgi.container.Module.start(Module.java:463) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel$2.run(ModuleContainer.java:1847) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor$1$1.execute(EquinoxContainerAdaptor.java:136) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1840) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1783) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1745) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1667) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) [org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:345) [org.eclipse.osgi-3.18.0.jar:?]
21:55:38.076 [ERROR] [Events.Framework ] - FrameworkEvent ERROR
org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.sonos [283]
Unresolved requirement: Import-Package: org.jupnp.model.meta; version="[3.0.0,4.0.0)"
Unresolved requirement: Import-Package: org.openhab.core.config.discovery.upnp
-> Export-Package: org.openhab.core.config.discovery.upnp; bundle-symbolic-name="org.openhab.core.config.discovery.upnp"; bundle-version="4.2.0.M1"; version="4.2.0"; uses:="org.jupnp.model.meta,org.openhab.core.config.discovery,org.openhab.core.thing"
org.openhab.core.config.discovery.upnp [287]
Unresolved requirement: Import-Package: org.jupnp; version="[3.0.0,4.0.0)"
Unresolved requirement: Import-Package: org.openhab.core.io.transport.upnp
-> Export-Package: org.openhab.core.io.transport.upnp; bundle-symbolic-name="org.openhab.core.io.transport.upnp"; bundle-version="4.2.0.M1"; version="4.2.0"
org.openhab.core.io.transport.upnp [288]
Unresolved requirement: Import-Package: org.jupnp; version="[3.0.0,4.0.0)"
at org.eclipse.osgi.container.Module.start(Module.java:463) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel$2.run(ModuleContainer.java:1847) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor$1$1.execute(EquinoxContainerAdaptor.java:136) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1840) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1783) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1745) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1667) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) [org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:345) [org.eclipse.osgi-3.18.0.jar:?]
org.osgi.framework.BundleException: Could not resolve module: org.openhab.core.config.discovery.upnp [287]
Unresolved requirement: Import-Package: org.jupnp; version="[3.0.0,4.0.0)"
at org.eclipse.osgi.container.Module.start(Module.java:463) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel$2.run(ModuleContainer.java:1847) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor$1$1.execute(EquinoxContainerAdaptor.java:136) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1840) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1783) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1745) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1667) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) [org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:345) [org.eclipse.osgi-3.18.0.jar:?]
21:55:38.977 [ERROR] [Events.Framework ] - FrameworkEvent ERROR
org.osgi.framework.BundleException: Could not resolve module: org.openhab.core.io.transport.upnp [288]
Unresolved requirement: Import-Package: org.jupnp; version="[3.0.0,4.0.0)"
at org.eclipse.osgi.container.Module.start(Module.java:463) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel$2.run(ModuleContainer.java:1847) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor$1$1.execute(EquinoxContainerAdaptor.java:136) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1840) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1783) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1745) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1667) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1) ~[org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234) [org.eclipse.osgi-3.18.0.jar:?]
at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:345) [org.eclipse.osgi-3.18.0.jar:?]
openhab> bundle:list -s | grep upnp
259 x Active x 80 x 3.0.0 x org.jupnp
260 x Installed x 80 x 4.2.0.M1 x org.openhab.core.config.discovery.addon.upnp
261 x Installed x 80 x 4.2.0.M1 x org.openhab.core.config.jupnp
287 x Installed x 80 x 4.2.0.M1 x org.openhab.core.config.discovery.upnp
288 x Installed x 80 x 4.2.0.M1 x org.openhab.core.io.transport.upnp
@wborn : any idea ? I only updated one line in META-INF/MANIFEST.MF:
Bundle-Version: 3.0.0
from openhab-core.
lolodomo
commented on June 24, 2024
In the following days, I will try again with the packaged jupnp library but I will try to disable my Wifi on the RPI in case the library is no more working well when several network interfaces are on. Unfortunately, this is the only idea I have.
When I enabled DEBUG logs for org.jupnp today, I got no logs at all, don't know if this is expected.
from openhab-core.
lolodomo
commented on June 24, 2024
I found something interesting in the logs at startup with the packaged JUPnP library (3.0.0), several lines of this kind:
21:00:02.381 [WARN ] [f.transport.servlet.ServletController] - Can't find the request for http://192.168.x.xxx:8080/upnpcallback/dev/RINCON_000E588EAE6601400_MR/svc/upnp-org/AVTransport/event/cb's ObserverThis IP is the Wifi IP of my RPI, not the LAN IP.
I just discovered I have sometimes these warnings also in 4.1.1 but UPnP and the Sonos binding are working.
This is probably not the cause of the problem.
from openhab-core.
lolodomo
commented on June 24, 2024
Finally, I believe I found the culpit which was replacing my JUPnP bundle at startup. It was because I setup to not use suggestions !
I have reset the 3 settings to true.
Maybe there is something wrong with the handling of these settings and UPnP is in fact "disabled" ( even if I see the bundle active).
I will probably retry a full install of OH 4.2M1 in the next days, keeping the default values for the 3 suggestions settings.
from openhab-core.
lolodomo
commented on June 24, 2024
I just tried a new OH installation, this time keeping default for all suggestions bundles. No change, the Sonos binding is still not working.
from openhab-core.
lolodomo
commented on June 24, 2024
Interesting: if I disable my wifi interface, then the Sonos binding seems to be alive again, now channels are initialized.
from openhab-core.
lolodomo
commented on June 24, 2024
@wborn : to summarize: I found that we have a problem when several IP v4 interfaces are up on the server (in my case a LAN interface and a wifi interface). If I disable the wifi interface, then it works well when I restart OH.
I never encountered this problem before 4.2, I don't know if this by chance or if the new JUPnP library (or any other component in OH 4.2 involved in UPnP stuff) has suddenly a problem to handle several IP interfaces.
from openhab-core.
lolodomo
commented on June 24, 2024
Enabling logging for Sonos binding + core.io.transport.upnp and comparing logs when WiFi interface is up or down, I can see in both cases that the Sonos is requesting GENA subscriptions and get a positive feedback for all. Then UPnP actions invoked from the OH server are also working in both cases but no events are received by the binding from the Sonos devices in the case both interfaces are up.
I will have now to go deeply in the JUPnP library (and adds logs) but here is my current hypothesis : the JUPnP library registered the OH server to the Sonos devices with a feedback URL built from my WiFi interface rather than my LAN interface. These HTTP URLs when invoked by the Sonos devices would then be rejected by the OH server that only listen to HTTP URLs based on my OH LAN server IP.
@wborn : do you remember to have changed the way the library handles the different interfaces ? I do not remember how the library is handling when there are several interfaces but it should normally also considered how the network settings are setup in the OH server.
from openhab-core.
lolodomo
commented on June 24, 2024
Making small progress. The JUPnP library is searching devices on all interfaces that are up and store found devices. Discovered devices are probably in the order they notified their existence.
When a binding wants to register to events delivered by a UPnP device/service, the first UPnP device in the registry matching the UDN is returned, this device can be sometimes the one discovered through the LAN interface, sometimes the WiFi interface. Depending on that, the callback URL setup when subscribing to events is either the one for the LAN interface or the one for the WiFi interface. It seems to be a problem for Sonos (I even see sometimes HTTP subscribe requests failing in timeout). I still do not understand why it does not work but I will try to force the retrieval of the right UPnP device in the registry so that the LAN IP is preferred and I will see if at least it solves the problem with Sonos.
from openhab-core.
wborn
commented on June 24, 2024
Maybe you ran into jupnp/jupnp#73?
from openhab-core.
lolodomo
commented on June 24, 2024
Maybe you ran into jupnp/jupnp#73?
Not really but that is also very interesting because if getDevice is returning a different result during the time, it may explain why the core framework is not distributing events to bindings due to this test:
https://github.com/openhab/openhab-core/blob/main/bundles/org.openhab.core.io.transport.upnp/src/main/java/org/openhab/core/io/transport/upnp/internal/UpnpIOServiceImpl.java#L157
Here is the getDevice method I am talking about:
https://github.com/openhab/openhab-core/blob/main/bundles/org.openhab.core.io.transport.upnp/src/main/java/org/openhab/core/io/transport/upnp/internal/UpnpIOServiceImpl.java#L218
I have not yet verified but I expect several devices stored in the registry for the same UPnP device.
Maybe there is only one per UPnP device, alternating.
from openhab-core.
lolodomo
commented on June 24, 2024
I quickly checked the implementation of equals and it is mainly a comparison of the UDN in the objects. So it should not be a problem even if getDevice returns a different object, because UDN will be the same.
from openhab-core.
openhab-bot
commented on June 24, 2024
This issue has been mentioned on openHAB Community. There might be relevant details there:
https://community.openhab.org/t/openhab-4-2-milestone-discussion/154316/66
from openhab-core.
lolodomo
commented on June 24, 2024
In fact, there is only one RemoteDevice in registry per UPnP device. If the same device is discovered through different network interfaces, the object in registry is not duplicated but only updated.
The local IP of the machine that started the discovery is part of this object. It is then used when creating the subscribe message to build the callback URL for transmitting events.
Depending on the order of UPnP devices responding to SEARCH request on the different network interfacers, the event subscriptions will use as callback URL either the OH server LAN IP or the OH server WiFi IP. In practice, in my case with RPI and Sonos devices, it is often the WiFi IP that is selected.
When WiFi IP is used, either Sonos devices are sending no events or the JUPnP library is just ignoring them.
The most probable is a bug in the JUPnP library because no events are also received when some Sonos devices should use the LAN IP and others the WiFi IP.
I imagine there is code in the library that registers HTTP services for each local IP, I should check and log this part of the code.
from openhab-core.
lolodomo
commented on June 24, 2024
The JUPnP library is finally registering only one HTTP service on /upnpcallback whatever the number of interfaces. This service should work whatever valid host in URL is used (LAN IP or WiFi IP). I enabled new logs and I can confirm that no event subscribed is received on this service.
That looks good to me in the library.
Maybe the problem is on Sonos...
Next step will be to hardcode the callback URL with a specific IP to see if it solves the problem.
from openhab-core.
lolodomo
commented on June 24, 2024
I am now suspecting this line:
https://github.com/jupnp/jupnp/blob/261787b3ad5b322c68baae4822150a14657b523b/bundles/org.jupnp/src/main/java/org/jupnp/OSGiUpnpServiceConfiguration.java#L245
from openhab-core.
lolodomo
commented on June 24, 2024
I am now suspecting this line: https://github.com/jupnp/jupnp/blob/261787b3ad5b322c68baae4822150a14657b523b/bundles/org.jupnp/src/main/java/org/jupnp/OSGiUpnpServiceConfiguration.java#L245
@wborn : BINGO ! If I comment this line, the problem is solved !
In case you have several interfaces, createStreamServer is called for each interface. For each of them, this will finally lead to the call of the method registerServlet that will attach a servlet to the context path /upnpcallback:
https://github.com/jupnp/jupnp/blob/261787b3ad5b322c68baae4822150a14657b523b/bundles/org.jupnp/src/main/java/org/jupnp/transport/impl/osgi/HttpServiceServletContainerAdapter.java#L81
The context patch is the same at each call, so the second and next calls will do nothing due to a check at the beginning of the method.
I do not understand what was the logic to unregister the HTTP service at the second call to createStreamServer.
WDYT @wborn ?
PS: This is not something that was apparently changed recently so I still do not understand why it does not occur in OH 4.1.1.
from openhab-core.
lolodomo
commented on June 24, 2024
I found the commit that introduced this code, it was in June 2015 !
The commit message is:
Added support for the upnpcallback servlet to work with both Servlet 2.4 (Synchronously) and Servlet 3.0 (Asynchronously).
Made sure the upnpcallback servlet does not use the default HttpContext which may be secured, but instead always an unsecured one.Whenever HttpService disappears/appears shutdown is performed
synchronously and startup asynchronously after a delay of 1500 ms in order
to properly reinitialize jupnp.
from openhab-core.
jlaur
commented on June 24, 2024
The commit message is
For reference: jupnp/jupnp@c988925 (I also went looking for it 😉)
from openhab-core.
lolodomo
commented on June 24, 2024
What could make a difference between 4.2 and 4.1.1 is if ServiceReference serviceReference = context.getServiceReference(HttpService.class.getName()); was returning null in 4.1.1 while not null in 4.2.
@wborn : I am not enough expert in OSGi to understand where in the code HttpService is registered.
from openhab-core.
wborn
commented on June 24, 2024
Is it also null in OH 4.1.1 if you restart the jupnp bundle after everything is started? If not it maybe timing related.
from openhab-core.
lolodomo
commented on June 24, 2024
Is it also null in OH 4.1.1 if you restart the jupnp bundle after everything is started?
I can't verify, I don't think I can build the old JUPnP library. Is it possible ?
If so it maybe timing related.
Maybe.
Does the context.ungetService(httpServiceReference); make any sense to you ?
from openhab-core.
lolodomo
commented on June 24, 2024
The difference in code when the HTTP service is there or not seems to be mainly the computation of the listen port.
Maybe all this block could be ignored but I am not yet sure at all:
if (serviceReference != null) {
if (httpServiceReference != null) {
// context.ungetService(httpServiceReference);
}
httpServiceReference = serviceReference;
HttpService httpService = (HttpService) context.getService(serviceReference);
if (httpService != null) {
logger.debug("call new ServletStreamServerImpl {} {}", httpProxyPort,
callbackURI.getBasePath().getPort());
return new ServletStreamServerImpl(new ServletStreamServerConfigurationImpl(
HttpServiceServletContainerAdapter.getInstance(httpService, context),
httpProxyPort != -1 ? httpProxyPort : callbackURI.getBasePath().getPort()));
}
}
to finally run that
return transportConfiguration.createStreamServer(networkAddressFactory.getStreamListenPort());
from openhab-core.
lolodomo
commented on June 24, 2024
JUPnP main bundle is referencing the HttpService bundle but apparently the HttpService can be started after and in this case the code seems to restart JUPnP:
https://github.com/jupnp/jupnp/blob/261787b3ad5b322c68baae4822150a14657b523b/bundles/org.jupnp/src/main/java/org/jupnp/UpnpServiceImpl.java#L135
So the block I was talking about in my previous message is necessary. In fact, two cases are supported, when an HttpService bundle is started and it is not. It probably allows JUPnP to work even without an HttpService bundle ?
from openhab-core.
wborn
commented on June 24, 2024
It probably allows JUPnP to work even without an HttpService bundle ?
Yes the HttpService only exists when using OSGi and JUPnP also supports OSGi-less Java stacks and Android Apps.
from openhab-core.
lolodomo
commented on June 24, 2024
@wborn: I have a doubt about required/mandatory OSGi reference. In our case, we have:
@Component(configurationPid = "org.jupnp.upnpservice")
@Designate(ocd = UpnpServiceImpl.Config.class)
public class UpnpServiceImpl implements UpnpService {
@ObjectClassDefinition(id = "org.jupnp.upnpservice", name = "jUPnP service configuration", description = "Configuration for jUPnP OSGi service")
public @interface Config {
@AttributeDefinition(name = "initialSearchEnabled", description = "Enable initial search when starting jUPnP service.")
boolean initialSearchEnabled() default true;
}
public UpnpServiceImpl() {
}
public UpnpServiceImpl(UpnpServiceConfiguration configuration) {
this.configuration = configuration;
}
@Activate
public void activate(Config config) {
scheduledFuture = null;
scheduledExecutorService = createExecutor();
isInitialSearchEnabled = config.initialSearchEnabled();
startup();
}
@Deactivate
public void deactivate() {
if (scheduledFuture != null) {
scheduledFuture.cancel(true);
}
scheduledExecutorService.shutdownNow();
shutdown();
}
@Reference
public void setUpnpServiceConfiguration(UpnpServiceConfiguration configuration) {
this.configuration = configuration;
if (isRunning) {
restart(true);
}
}
public void unsetUpnpServiceConfiguration(UpnpServiceConfiguration configuration) {
this.configuration = null;
}
@Reference
public void setHttpService(HttpService httpService) {
// Only need to restart jupnp after/if HttpService appears
if (isRunning) {
shutdown(false);
delayedStartup(1500);
}
}
public void unsetHttpService(HttpService httpService) {
// Only need to restart jupnp after/if HttpService disappears
if (isRunning) {
shutdown(false);
delayedStartup(1500);
}
}
}
Are references to UpnpServiceConfiguration and HttpService required or optional ? I mean, will setUpnpServiceConfiguration and setHttpService always be called before activate is called ?
If it was a mandatory reference, I don't understand the comment "Only need to restart jupnp after/if HttpService appears".
What is sure is that there is no reference defined between OSGiUpnpServiceConfiguration and HttpService
from openhab-core.
lolodomo
commented on June 24, 2024
Maybe an attribute configurationPolicy is missing to set it to REQUIRED ? I am searching what is the default value...
from openhab-core.
lolodomo
commented on June 24, 2024
The default would be OPTIONAL (to be confirmed by someone who knows well OSGi).
In that case, I would understand the code restarting everything when the HttpService is injected.
My current feeling is that we should define a REQUIRED policy to activate the bundle only once OSGiUpnpServiceConfiguration and HttpService are injected.
WDYT @wborn ?
from openhab-core.
lolodomo
commented on June 24, 2024
On my RPI with snapshot 4012 and a patched version of JUPnP, here is the order at startup:
11:50:00.466 [DEBUG] [rg.jupnp.OSGiUpnpServiceConfiguration] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.OSGiUpnpServiceConfiguration] : BundleComponentActivator : ComponentHolder created.
11:50:00.489 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl] : BundleComponentActivator : ComponentHolder created.
11:50:00.513 [DEBUG] [rg.jupnp.OSGiUpnpServiceConfiguration] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.OSGiUpnpServiceConfiguration] : ConfigurableComponentHolder configuration updated for pid org.jupnp with change count 2
11:50:00.542 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl] : Dependency Manager created HttpServiceinterface=org.osgi.service.http.HttpService, filter=null, policy=static, cardinality=1..1, bind=setHttpService, unbind=unsetHttpService, updated=null, field=null, field-option=null, collection-type=null, parameter=null
11:50:00.561 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl] : Dependency Manager created UpnpServiceConfigurationinterface=org.jupnp.UpnpServiceConfiguration, filter=null, policy=static, cardinality=1..1, bind=setUpnpServiceConfiguration, unbind=unsetUpnpServiceConfiguration, updated=null, field=null, field-option=null, collection-type=null, parameter=null
11:50:00.582 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl] : Dependency Manager created osgi.ds.satisfying.conditioninterface=org.osgi.service.condition.Condition, filter=(osgi.condition.id=true), policy=dynamic, cardinality=1..1, bind=null, unbind=null, updated=null, field=null, field-option=null, collection-type=null, parameter=null
11:50:00.601 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl] : Component created: DS=DS13, implementation=org.jupnp.UpnpServiceImpl, immediate=false, default-enabled=true, factory=null, configuration-policy=optional, activate=activate, deactivate=deactivate, modified=null configuration-pid=[org.jupnp.upnpservice]
11:50:00.621 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl] : Component Services: scope=singleton, services=[org.jupnp.UpnpService]
11:50:00.634 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl] : Component Properties: {initialSearchEnabled=true, osgi.ds.satisfying.condition.target=(osgi.condition.id=true)}
11:50:00.649 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl] : Querying state disabled
11:50:00.661 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl] : Querying state disabled
11:50:00.673 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl] : Component can not be activated since it is in state disabled
11:50:00.686 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl] : Querying state disabled
11:50:00.697 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Updating target filters
11:50:00.709 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : No change in target property for dependency HttpService: currently registered: false
11:50:00.723 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : No existing service listener to unregister for dependency HttpService
11:50:00.737 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Setting target property for dependency HttpService to null
11:50:00.749 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : New service tracker for HttpService, initial active: false, previous references: {}, classFilter: (objectClass=org.osgi.service.http.HttpService), initialReferenceFilter (objectClass=org.osgi.service.http.HttpService)
11:50:00.767 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : dm HttpService tracker reset (closed)
11:50:00.780 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : dm HttpService tracking 1 SingleStatic added {org.osgi.service.http.HttpService, org.ops4j.pax.web.service.WebContainer}={org.ops4j.pax.web.log.ncsa.extended=true, org.ops4j.pax.web.ssl.keystore.password=********, service.scope=bundle, org.ops4j.pax.web.ssl.key.password=********, org.ops4j.pax.web.session.cookie.name=JSESSIONID, org.osgi.service.http.connector.name=default, org.ops4j.pax.web.enc.iterationcount=1000, org.ops4j.pax.web.log.ncsa.file=yyyy_mm_dd.request.log, org.ops4j.pax.web.server.eventDispatcherThreadCount=1, org.osgi.service.http.checkForwardedHeaders=false, org.ops4j.pax.web.enc.suffix=), org.ops4j.pax.web.digestAuth.maxNonceAge=60000, org.ops4j.pax.web.ssl.ciphersuites.included=, org.ops4j.pax.web.session.url=jsessionid, org.ops4j.pax.web.formAuth.errorRedirect=false, org.ops4j.pax.web.ssl.ciphersuites.excluded=^.*_(MD5|SHA|SHA1)$,^TLS_RSA_.*$,^SSL_.*$,^.*_NULL_.*$,^.*_anon_.*, org.ops4j.pax.web.enc.prefix=ENC(, org.ops4j.pax.web.server.maxThreads=50, org.ops4j.pax.web.validatePeerCerts=false, service.id=163, org.ops4j.pax.web.session.cookie.maxAge=-1, org.ops4j.pax.web.ssl.truststore.password=********, org.ops4j.pax.web.ssl.session.cacheSize=-1, org.ops4j.pax.web.ssl.truststore.type=JKS, org.ops4j.pax.web.ssl.keystore.type=JKS, org.ops4j.pax.web.ssl.session.enabled=true, org.ops4j.pax.web.ssl.protocol=TLSv1.3, org.osgi.service.http.port=8080, org.ops4j.pax.web.log.ncsa.file.date.format=yyyy-MM-dd, org.ops4j.pax.web.ssl.renegotiationLimit=-1, org.osgi.service.http.secure.enabled=true, org.osgi.service.http.enabled=true, org.ops4j.pax.web.server.idleTimeout=300000, org.ops4j.pax.web.log.ncsa.retaindays=90, org.ops4j.pax.web.log.ncsa.logtimezone=GMT, org.ops4j.pax.web.enc.algorithm=PBEWithHmacSHA256AndAES_128, org.ops4j.pax.web.validateCerts=false, org.ops4j.pax.web.config.files=/home/pi/openhab/runtime/etc/jetty.xml, org.ops4j.pax.web.ssl.renegotiationAllowed=true, org.ops4j.pax.web.digestAuth.maxNonceCount=1024, org.ops4j.pax.web.enableOCSP=false, org.ops4j.pax.web.ssl.clientauth.needed=false, org.ops4j.pax.web.enc.enabled=false, org.osgi.service.http.port.secure=8443, javax.servlet.context.tempdir=/home/pi/openhab/userdata/tmp, org.ops4j.pax.web.enableCRLDP=false, org.ops4j.pax.web.server.connector.idleTimeout=30000, org.ops4j.pax.web.session.timeout=10, org.ops4j.pax.web.ssl.clientauth.wanted=false, org.ops4j.pax.web.ssl.protocols.excluded=SSL,SSLv2,SSLv2Hello,SSLv3, service.bundleid=233, org.ops4j.pax.web.server.minThreads=2, org.ops4j.pax.web.session.cookie.secure=false, org.ops4j.pax.web.enc.masterpassword=********, org.ops4j.pax.web.log.ncsa.append=true, org.osgi.service.http.secure.connector.name=secureDefault, org.ops4j.pax.web.ssl.session.timeout=-1, org.ops4j.pax.web.listening.addresses=0.0.0.0, org.ops4j.pax.web.log.ncsa.buffered=true, org.ops4j.pax.web.session.cookie.sameSite=unset, org.ops4j.pax.web.log.ncsa.enabled=false, org.ops4j.pax.web.ssl.protocols.included=, org.ops4j.pax.web.session.cookie.httpOnly=true, org.ops4j.pax.web.server.showStacks=false} (enter)
11:50:00.885 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : dm HttpService tracking 1 SingleStatic active: false trackerOpened: false optional: false
11:50:00.899 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : dm HttpService tracking 1 SingleStatic added {org.osgi.service.http.HttpService, org.ops4j.pax.web.service.WebContainer}={org.ops4j.pax.web.log.ncsa.extended=true, org.ops4j.pax.web.ssl.keystore.password=********, service.scope=bundle, org.ops4j.pax.web.ssl.key.password=********, org.ops4j.pax.web.session.cookie.name=JSESSIONID, org.osgi.service.http.connector.name=default, org.ops4j.pax.web.enc.iterationcount=1000, org.ops4j.pax.web.log.ncsa.file=yyyy_mm_dd.request.log, org.ops4j.pax.web.server.eventDispatcherThreadCount=1, org.osgi.service.http.checkForwardedHeaders=false, org.ops4j.pax.web.enc.suffix=), org.ops4j.pax.web.digestAuth.maxNonceAge=60000, org.ops4j.pax.web.ssl.ciphersuites.included=, org.ops4j.pax.web.session.url=jsessionid, org.ops4j.pax.web.formAuth.errorRedirect=false, org.ops4j.pax.web.ssl.ciphersuites.excluded=^.*_(MD5|SHA|SHA1)$,^TLS_RSA_.*$,^SSL_.*$,^.*_NULL_.*$,^.*_anon_.*, org.ops4j.pax.web.enc.prefix=ENC(, org.ops4j.pax.web.server.maxThreads=50, org.ops4j.pax.web.validatePeerCerts=false, service.id=163, org.ops4j.pax.web.session.cookie.maxAge=-1, org.ops4j.pax.web.ssl.truststore.password=********, org.ops4j.pax.web.ssl.session.cacheSize=-1, org.ops4j.pax.web.ssl.truststore.type=JKS, org.ops4j.pax.web.ssl.keystore.type=JKS, org.ops4j.pax.web.ssl.session.enabled=true, org.ops4j.pax.web.ssl.protocol=TLSv1.3, org.osgi.service.http.port=8080, org.ops4j.pax.web.log.ncsa.file.date.format=yyyy-MM-dd, org.ops4j.pax.web.ssl.renegotiationLimit=-1, org.osgi.service.http.secure.enabled=true, org.osgi.service.http.enabled=true, org.ops4j.pax.web.server.idleTimeout=300000, org.ops4j.pax.web.log.ncsa.retaindays=90, org.ops4j.pax.web.log.ncsa.logtimezone=GMT, org.ops4j.pax.web.enc.algorithm=PBEWithHmacSHA256AndAES_128, org.ops4j.pax.web.validateCerts=false, org.ops4j.pax.web.config.files=/home/pi/openhab/runtime/etc/jetty.xml, org.ops4j.pax.web.ssl.renegotiationAllowed=true, org.ops4j.pax.web.digestAuth.maxNonceCount=1024, org.ops4j.pax.web.enableOCSP=false, org.ops4j.pax.web.ssl.clientauth.needed=false, org.ops4j.pax.web.enc.enabled=false, org.osgi.service.http.port.secure=8443, javax.servlet.context.tempdir=/home/pi/openhab/userdata/tmp, org.ops4j.pax.web.enableCRLDP=false, org.ops4j.pax.web.server.connector.idleTimeout=30000, org.ops4j.pax.web.session.timeout=10, org.ops4j.pax.web.ssl.clientauth.wanted=false, org.ops4j.pax.web.ssl.protocols.excluded=SSL,SSLv2,SSLv2Hello,SSLv3, service.bundleid=233, org.ops4j.pax.web.server.minThreads=2, org.ops4j.pax.web.session.cookie.secure=false, org.ops4j.pax.web.enc.masterpassword=********, org.ops4j.pax.web.log.ncsa.append=true, org.osgi.service.http.secure.connector.name=secureDefault, org.ops4j.pax.web.ssl.session.timeout=-1, org.ops4j.pax.web.listening.addresses=0.0.0.0, org.ops4j.pax.web.log.ncsa.buffered=true, org.ops4j.pax.web.session.cookie.sameSite=unset, org.ops4j.pax.web.log.ncsa.enabled=false, org.ops4j.pax.web.ssl.protocols.included=, org.ops4j.pax.web.session.cookie.httpOnly=true, org.ops4j.pax.web.server.showStacks=false} (exit)
11:50:01.003 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : dm HttpService tracker opened
11:50:01.014 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : registering service listener for dependency HttpService
11:50:01.027 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : No change in target property for dependency UpnpServiceConfiguration: currently registered: false
11:50:01.041 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : No existing service listener to unregister for dependency UpnpServiceConfiguration
11:50:01.054 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Setting target property for dependency UpnpServiceConfiguration to null
11:50:01.067 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : New service tracker for UpnpServiceConfiguration, initial active: false, previous references: {}, classFilter: (objectClass=org.jupnp.UpnpServiceConfiguration), initialReferenceFilter (objectClass=org.jupnp.UpnpServiceConfiguration)
11:50:01.085 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : dm UpnpServiceConfiguration tracker reset (closed)
11:50:01.098 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : dm UpnpServiceConfiguration tracker opened
11:50:01.110 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : registering service listener for dependency UpnpServiceConfiguration
11:50:01.124 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : No existing service listener to unregister for dependency osgi.ds.satisfying.condition
11:50:01.137 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Setting target property for dependency osgi.ds.satisfying.condition to (osgi.condition.id=true)
11:50:01.151 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : New service tracker for osgi.ds.satisfying.condition, initial active: false, previous references: {}, classFilter: (objectClass=org.osgi.service.condition.Condition), initialReferenceFilter (&(objectClass=org.osgi.service.condition.Condition)(osgi.condition.id=true))
11:50:01.170 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : dm osgi.ds.satisfying.condition tracker reset (closed)
11:50:01.183 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : dm osgi.ds.satisfying.condition tracking 2 SingleDynamic added {org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true} (enter)
11:50:01.202 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : dm osgi.ds.satisfying.condition tracking 2 SingleDynamic added {org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true} (exit)
11:50:01.221 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : dm osgi.ds.satisfying.condition tracker opened
11:50:01.234 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : registering service listener for dependency osgi.ds.satisfying.condition
11:50:01.247 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Changed state from disabled to unsatisfiedReference
11:50:01.259 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Component enabled
11:50:01.271 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : ActivateInternal
11:50:01.282 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Querying state unsatisfiedReference
11:50:01.294 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Querying state unsatisfiedReference
11:50:01.306 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Activating component from state unsatisfiedReference
11:50:01.318 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Querying state unsatisfiedReference
11:50:01.330 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Querying state unsatisfiedReference
11:50:01.342 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Dependency not satisfied: UpnpServiceConfiguration
11:50:01.354 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Not all dependencies satisfied, cannot activate
11:50:01.428 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : dm UpnpServiceConfiguration tracking 3 SingleStatic added {org.jupnp.UpnpServiceConfiguration}={autoEnable=false, service.id=491, service.bundleid=250, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), threadPoolSize=15, component.name=org.openhab.core.config.jupnp.internal.OHUpnpServiceConfiguration, component.id=319, asyncThreadPoolSize=30, felix.fileinstall.filename=file:/home/pi/openhab/userdata/etc/org.jupnp.cfg, service.pid=org.jupnp, multicastResponsePort=0} (enter)
11:50:01.454 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : ActivateInternal
11:50:01.466 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Querying state unsatisfiedReference
11:50:01.478 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Querying state unsatisfiedReference
11:50:01.490 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Activating component from state unsatisfiedReference
11:50:01.503 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Querying state unsatisfiedReference
11:50:01.516 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Querying state unsatisfiedReference
11:50:01.529 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Changed state from unsatisfiedReference to satisfied
11:50:01.542 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : registration change queue [registered]
11:50:01.574 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Checking constructor public org.jupnp.UpnpServiceImpl()
11:50:01.588 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Found constructor with 0 arguments : public org.jupnp.UpnpServiceImpl()
11:50:01.602 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : getting bind: setHttpService
11:50:01.614 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Locating method setHttpService in class org.jupnp.UpnpServiceImpl
11:50:01.628 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : doFindMethod: Looking for method org.jupnp.UpnpServiceImpl.setHttpService
11:50:01.644 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Declared Method org.jupnp.UpnpServiceImpl.setHttpService([interface org.osgi.framework.ServiceReference]) not found
11:50:01.659 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Declared Method org.jupnp.UpnpServiceImpl.setHttpService([interface org.osgi.service.component.ComponentServiceObjects]) not found
11:50:01.675 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : getClassFromComponentClassLoader: Looking for interface class org.osgi.service.http.HttpService through loader of org.jupnp.UpnpServiceImpl
11:50:01.691 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : getClassFromComponentClassLoader: Found class org.osgi.service.http.HttpService
11:50:01.705 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : doFindMethod: No method taking ServiceReference found, checking method taking org.osgi.service.http.HttpService
11:50:01.720 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : doFindMethod: Found Method public void org.jupnp.UpnpServiceImpl.setHttpService(org.osgi.service.http.HttpService)
11:50:01.735 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Found bind method: public void org.jupnp.UpnpServiceImpl.setHttpService(org.osgi.service.http.HttpService)
11:50:01.749 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : getting bind: setUpnpServiceConfiguration
11:50:01.762 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Locating method setUpnpServiceConfiguration in class org.jupnp.UpnpServiceImpl
11:50:01.776 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : doFindMethod: Looking for method org.jupnp.UpnpServiceImpl.setUpnpServiceConfiguration
11:50:01.791 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Declared Method org.jupnp.UpnpServiceImpl.setUpnpServiceConfiguration([interface org.osgi.framework.ServiceReference]) not found
11:50:01.806 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Declared Method org.jupnp.UpnpServiceImpl.setUpnpServiceConfiguration([interface org.osgi.service.component.ComponentServiceObjects]) not found
11:50:01.823 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : getClassFromComponentClassLoader: Looking for interface class org.jupnp.UpnpServiceConfiguration through loader of org.jupnp.UpnpServiceImpl
11:50:01.838 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : getClassFromComponentClassLoader: Found class org.jupnp.UpnpServiceConfiguration
11:50:01.852 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : doFindMethod: No method taking ServiceReference found, checking method taking org.jupnp.UpnpServiceConfiguration
11:50:01.867 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : doFindMethod: Found Method public void org.jupnp.UpnpServiceImpl.setUpnpServiceConfiguration(org.jupnp.UpnpServiceConfiguration)
11:50:01.883 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Found bind method: public void org.jupnp.UpnpServiceImpl.setUpnpServiceConfiguration(org.jupnp.UpnpServiceConfiguration)
11:50:01.910 [DEBUG] [rg.jupnp.OSGiUpnpServiceConfiguration] - OSGiUpnpServiceConfiguration 0 0 true
11:50:01.939 [DEBUG] [rg.jupnp.OSGiUpnpServiceConfiguration] - OSGiUpnpServiceConfiguration activate
11:50:01.949 [INFO ] [rg.jupnp.OSGiUpnpServiceConfiguration] - OSGiUpnpServiceConfiguration createConfiguration threadPoolSize = 15 true
11:50:01.961 [INFO ] [rg.jupnp.OSGiUpnpServiceConfiguration] - OSGiUpnpServiceConfiguration createConfiguration asyncThreadPoolSize = 30 true
11:50:01.973 [INFO ] [rg.jupnp.OSGiUpnpServiceConfiguration] - OSGiUpnpServiceConfiguration retryAfterSeconds = 600
11:50:01.984 [INFO ] [rg.jupnp.OSGiUpnpServiceConfiguration] - OSGiUpnpServiceConfiguration retryIterations = 5
11:50:01.994 [INFO ] [rg.jupnp.OSGiUpnpServiceConfiguration] - OSGiUpnpServiceConfiguration timeoutSeconds = 10
11:50:02.005 [DEBUG] [rg.jupnp.OSGiUpnpServiceConfiguration] - Creating mainThreadPool
11:50:02.020 [DEBUG] [rg.jupnp.OSGiUpnpServiceConfiguration] - Creating asyncThreadPool
11:50:02.030 [DEBUG] [rg.jupnp.OSGiUpnpServiceConfiguration] - Creating remoteThreadPool
11:50:02.151 [DEBUG] [rg.jupnp.OSGiUpnpServiceConfiguration] - org.openhab.core.config.jupnp.internal.OHUpnpServiceConfiguration@ebc57b activated
11:50:02.163 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : This thread collected dependencies
11:50:02.175 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : getService (single component manager) dependencies collected.
11:50:02.189 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Querying state satisfied
11:50:02.201 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Querying state satisfied
11:50:02.214 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : For dependency HttpService, optional: false; to bind: [[RefPair: ref: [{org.osgi.service.http.HttpService, org.ops4j.pax.web.service.WebContainer}={org.ops4j.pax.web.log.ncsa.extended=true, org.ops4j.pax.web.ssl.keystore.password=********, service.scope=bundle, org.ops4j.pax.web.ssl.key.password=********, org.ops4j.pax.web.session.cookie.name=JSESSIONID, org.osgi.service.http.connector.name=default, org.ops4j.pax.web.enc.iterationcount=1000, org.ops4j.pax.web.log.ncsa.file=yyyy_mm_dd.request.log, org.ops4j.pax.web.server.eventDispatcherThreadCount=1, org.osgi.service.http.checkForwardedHeaders=false, org.ops4j.pax.web.enc.suffix=), org.ops4j.pax.web.digestAuth.maxNonceAge=60000, org.ops4j.pax.web.ssl.ciphersuites.included=, org.ops4j.pax.web.session.url=jsessionid, org.ops4j.pax.web.formAuth.errorRedirect=false, org.ops4j.pax.web.ssl.ciphersuites.excluded=^.*_(MD5|SHA|SHA1)$,^TLS_RSA_.*$,^SSL_.*$,^.*_NULL_.*$,^.*_anon_.*, org.ops4j.pax.web.enc.prefix=ENC(, org.ops4j.pax.web.server.maxThreads=50, org.ops4j.pax.web.validatePeerCerts=false, service.id=163, org.ops4j.pax.web.session.cookie.maxAge=-1, org.ops4j.pax.web.ssl.truststore.password=********, org.ops4j.pax.web.ssl.session.cacheSize=-1, org.ops4j.pax.web.ssl.truststore.type=JKS, org.ops4j.pax.web.ssl.keystore.type=JKS, org.ops4j.pax.web.ssl.session.enabled=true, org.ops4j.pax.web.ssl.protocol=TLSv1.3, org.osgi.service.http.port=8080, org.ops4j.pax.web.log.ncsa.file.date.format=yyyy-MM-dd, org.ops4j.pax.web.ssl.renegotiationLimit=-1, org.osgi.service.http.secure.enabled=true, org.osgi.service.http.enabled=true, org.ops4j.pax.web.server.idleTimeout=300000, org.ops4j.pax.web.log.ncsa.retaindays=90, org.ops4j.pax.web.log.ncsa.logtimezone=GMT, org.ops4j.pax.web.enc.algorithm=PBEWithHmacSHA256AndAES_128, org.ops4j.pax.web.validateCerts=false, org.ops4j.pax.web.config.files=/home/pi/openhab/runtime/etc/jetty.xml, org.ops4j.pax.web.ssl.renegotiationAllowed=true, org.ops4j.pax.web.digestAuth.maxNonceCount=1024, org.ops4j.pax.web.enableOCSP=false, org.ops4j.pax.web.ssl.clientauth.needed=false, org.ops4j.pax.web.enc.enabled=false, org.osgi.service.http.port.secure=8443, javax.servlet.context.tempdir=/home/pi/openhab/userdata/tmp, org.ops4j.pax.web.enableCRLDP=false, org.ops4j.pax.web.server.connector.idleTimeout=30000, org.ops4j.pax.web.session.timeout=10, org.ops4j.pax.web.ssl.clientauth.wanted=false, org.ops4j.pax.web.ssl.protocols.excluded=SSL,SSLv2,SSLv2Hello,SSLv3, service.bundleid=233, org.ops4j.pax.web.server.minThreads=2, org.ops4j.pax.web.session.cookie.secure=false, org.ops4j.pax.web.enc.masterpassword=********, org.ops4j.pax.web.log.ncsa.append=true, org.osgi.service.http.secure.connector.name=secureDefault, org.ops4j.pax.web.ssl.session.timeout=-1, org.ops4j.pax.web.listening.addresses=0.0.0.0, org.ops4j.pax.web.log.ncsa.buffered=true, org.ops4j.pax.web.session.cookie.sameSite=unset, org.ops4j.pax.web.log.ncsa.enabled=false, org.ops4j.pax.web.ssl.protocols.included=, org.ops4j.pax.web.session.cookie.httpOnly=true, org.ops4j.pax.web.server.showStacks=false}] service: [Proxy for HttpService (enabled) for bundle org.jupnp_3.0.1.202403291044 [248]]]]
11:50:02.323 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : For dependency UpnpServiceConfiguration, optional: false; to bind: [[RefPair: ref: [{org.jupnp.UpnpServiceConfiguration}={autoEnable=false, service.id=491, service.bundleid=250, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), threadPoolSize=15, component.name=org.openhab.core.config.jupnp.internal.OHUpnpServiceConfiguration, component.id=319, asyncThreadPoolSize=30, felix.fileinstall.filename=file:/home/pi/openhab/userdata/etc/org.jupnp.cfg, service.pid=org.jupnp, multicastResponsePort=0}] service: [org.openhab.core.config.jupnp.internal.OHUpnpServiceConfiguration@ebc57b]]]
11:50:02.353 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : For dependency osgi.ds.satisfying.condition, optional: false; to bind: [[RefPair: ref: [{org.osgi.service.condition.Condition}={service.id=6, service.bundleid=0, service.scope=singleton, service.pid=0.org.osgi.service.condition.ConditionImpl, osgi.condition.id=true}] service: [null]]]
11:50:02.374 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : invoking bind: setHttpService: parameters [org.ops4j.pax.web.service.internal.HttpServiceProxy]
11:50:02.388 [DEBUG] [org.jupnp.UpnpServiceImpl ] - UpnpServiceImpl setHttpService
11:50:02.398 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : invoked bind: setHttpService
11:50:02.465 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : invoking bind: setUpnpServiceConfiguration: parameters [org.openhab.core.config.jupnp.internal.OHUpnpServiceConfiguration]
11:50:02.480 [DEBUG] [org.jupnp.UpnpServiceImpl ] - UpnpServiceImpl setUpnpServiceConfiguration
11:50:02.491 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : invoked bind: setUpnpServiceConfiguration
11:50:02.504 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : getting activate: activate
11:50:02.516 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Locating method activate in class org.jupnp.UpnpServiceImpl
11:50:02.529 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Declared Method org.jupnp.UpnpServiceImpl.activate([interface org.osgi.service.component.ComponentContext]) not found
11:50:02.545 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Found activate method: public void org.jupnp.UpnpServiceImpl.activate(org.jupnp.UpnpServiceImpl$Config)
11:50:02.564 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : invoking activate: activate: parameters [jdk.proxy23.$Proxy127]
11:50:02.578 [DEBUG] [org.jupnp.UpnpServiceImpl ] - UpnpServiceImpl activate
11:50:02.589 [DEBUG] [org.jupnp.UpnpServiceImpl ] - UpnpServiceImpl startup configurationInjected true httpServiceInjected true
11:50:02.601 [INFO ] [org.jupnp.UpnpServiceImpl ] - Starting UPnP service...
11:50:02.611 [DEBUG] [org.jupnp.UpnpServiceImpl ] - Using configuration: org.openhab.core.config.jupnp.internal.OHUpnpServiceConfiguration
11:50:02.695 [DEBUG] [rg.jupnp.OSGiUpnpServiceConfiguration] - OSGiUpnpServiceConfiguration createStreamServer true false
11:50:02.710 [DEBUG] [rg.jupnp.OSGiUpnpServiceConfiguration] - call new ServletStreamServerImpl -1 -1
11:50:02.760 [DEBUG] [rg.jupnp.OSGiUpnpServiceConfiguration] - OSGiUpnpServiceConfiguration createStreamServer true true
11:50:02.771 [DEBUG] [rg.jupnp.OSGiUpnpServiceConfiguration] - call new ServletStreamServerImpl -1 -1
11:50:02.784 [DEBUG] [rg.jupnp.OSGiUpnpServiceConfiguration] - OSGiUpnpServiceConfiguration createStreamClient
11:50:02.812 [DEBUG] [org.jupnp.UpnpServiceImpl ] - UPnP service started successfully
11:50:02.854 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : invoked activate: activate
11:50:02.867 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Set implementation object for component
11:50:02.880 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : Changed state from satisfied to active
11:50:02.961 [DEBUG] [org.jupnp.UpnpServiceImpl ] - bundle org.jupnp:3.0.1.202403291044 (248)[org.jupnp.UpnpServiceImpl(316)] : dm UpnpServiceConfiguration tracking 3 SingleStatic added {org.jupnp.UpnpServiceConfiguration}={autoEnable=false, service.id=491, service.bundleid=250, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), threadPoolSize=15, component.name=org.openhab.core.config.jupnp.internal.OHUpnpServiceConfiguration, component.id=319, asyncThreadPoolSize=30, felix.fileinstall.filename=file:/home/pi/openhab/userdata/etc/org.jupnp.cfg, service.pid=org.jupnp, multicastResponsePort=0} (exit)
The sequence is as if the policy was REQUIRED ?
from openhab-core.
lolodomo
commented on June 24, 2024
Looking more attentively at the first lines, it seems to be rather optional:
[org.jupnp.UpnpServiceImpl] : Component created: DS=DS13, implementation=org.jupnp.UpnpServiceImpl, immediate=false, default-enabled=true, factory=null, configuration-policy=optional, activate=activate, deactivate=deactivate, modified=null configuration-pid=[org.jupnp.upnpservice]
That would mean the loading order could be different and my dependencies could be not yet injected when the component is activated ?
from openhab-core.
lolodomo
commented on June 24, 2024
In addition to the fact that I would expect required OSGi dependencies to avoid potential re-init of all stuff in the bundle, I also see no valid reason to release the OSGi HttpService. The idea was maybe to trigger the unset method in the main bundle and then restart all the stuff but this time without using the HttpService. In addition to the fact that it apparently does not work well, my question is what is the interest of doing that (because this is ok to use the HttpService) ?
from openhab-core.
lolodomo
commented on June 24, 2024
Issue has to be reopened until OH switchs to JUPnP 3.0.1.
from openhab-core.
wborn
commented on June 24, 2024
I already thought that might happen based on the "Fix ..." text in your PR. 😉
from openhab-core.
openhab-bot
commented on June 24, 2024
This issue has been mentioned on openHAB Community. There might be relevant details there:
https://community.openhab.org/t/openhab-4-2-milestone-discussion/154316/103
from openhab-core.
Related Issues (20)
- Allow offset for "at the time specified in an item's state" trigger HOT 7
- customTags.yaml not loading after reboot HOT 6
- Thing File based configuration not loaded correctly after changing HOT 33
- Attempting to send a state update of an item which doesn't exist: __v_isRef HOT 7
- Default statedescription pattern for NumberItem HOT 3
- Error during logger activation HOT 3
- Snapshot 4069: failed to install bundles at startup HOT 39
- Missmatch between system:start-level and openhab.event.StartlevelEvent HOT 5
- OpenHAB 4.1.2 - Karaf cannot start HOT 4
- Add SDDP service to core HOT 4
- Sitemap widget grid
- [ephemeris] Calls to `isBankHoliday` failing with exception HOT 6
- Local build failing in config.core due to violation in schema\config-description-1.0.0.xsd HOT 2
- Thing file loading issue HOT 3
- Persisted group items with base type Number:Dimension not restored correctly in persistence extensions HOT 3
- What to do with my 'fake' device code
- Possible Startup loop HOT 1
- Skipping setup causes issues due to locale not being set HOT 2
- [Feature] Add support to format channel-type description using `html` tags HOT 1
- oh-rollershutter-item with stateInCenter set doesn't respect State Description Pattern HOT 2
Recommend Projects
-
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
-
Vue.js
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
-
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
-
TensorFlow
An Open Source Machine Learning Framework for Everyone
-
Django
The Web framework for perfectionists with deadlines.
-
Laravel
A PHP framework for web artisans
-
D3
Bring data to life with SVG, Canvas and HTML. 📊📈🎉
-
Recommend Topics
-
javascript
JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
-
web
Some thing interesting about web. New door for the world.
-
server
A server is a program made to process requests and deliver data to clients.
-
Machine learning
Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
-
Visualization
Some thing interesting about visualization, use data art
-
Game
Some thing interesting about game, make everyone happy.
Recommend Org
-
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
-
Microsoft
Open source projects and samples from Microsoft.
-
Google
Google ❤️ Open Source for everyone.
-
Alibaba
Alibaba Open Source for everyone
-
D3
Data-Driven Documents codes.
-
Tencent
China tencent open source team.
from openhab-core.