search

openhab / openhab-addons

Add-ons for openHAB
https://www.openhab.org/
Eclipse Public License 2.0
1.86k stars 3.57k forks source link

Bindings not suggested while expected #16023

Closed lolodomo closed 8 months ago

lolodomo commented 8 months ago

I just tested using snapshot 3760 the new binding suggestion feature. Edit: 1 binding should have been suggested in my network but is not: freeboxos. Others are suggested as expected. Tested on my PC windows 10.

@andrewfg for information

mherwege commented 8 months ago

Hi @lolodomo, was this when running the setup wizard, or afterwards when looking at the add-on store?

I have noticed there is sometimes some delay in devices becoming visible, both with mDNS and UPnP. You could switch on debug logging for org.openhab.core.config.discovery.addon to see a log of all found devices, and when they are found. If it is in the setup wizard, an option could be to wait a little longer and show some searching suggestions screen.

andrewfg commented 8 months ago

Also, perhaps a stupid point, but some of my devices are discoverable when in sleep mode (e.g. Oppo bluray player) but others have to be fully on (e.g. Sony Tv)..

lolodomo commented 8 months ago

Hi @lolodomo, was this when running the setup wizard, or afterwards when looking at the add-on store?

Both

lolodomo commented 8 months ago

Also, perhaps a stupid point, but some of my devices are discoverable when in sleep mode (e.g. Oppo bluray player) but others have to be fully on (e.g. Sony Tv)..

To be checked later for my TV and washing machine. My Freebox is always on, it is a ADSL router.

If the Android app discovering mDNS devices find them, OH should also. I have to check.

lolodomo commented 8 months ago

After turning on my TV and washing machine, the home connect and LG webOS bindings finally appeared. Even the Freebox OS binding appeared but after a certain time.

I will reinstall to see if they appear in the first setup step.

andrewfg commented 8 months ago

home connect and LG webOS bindings finally appeared. Freebox OS binding appeared but after a certain time.

On clean startup, if you imagine being a new user, and go through the process of creating a new user account, and then choosing your exact home location, it takes perhaps 1..2 minutes (??), and I have found that this is sufficient to discover all devices on my LAN. But if you 'crash' through those steps like an experienced user, it would take less time, and therefore risk not to discover everything.

This is why the Add-on Store now has the extra 'Recommended Addons' tab; so you can check at that tab even later, at any time.

andrewfg commented 8 months ago

^ As a side note: It probably depends on your OS and what state it is in. Some OS (certainly Windows) maintain a cache of mDNS discovery results at OS level. So if you do a clean OH install on a Windows PC which has been running for some time, then you might benefit from discovery results being served from OS cache rather than from actual scan of the LAN. By contrast if both OS and OH are fully clean installed (e.g. say from an openhabian image) then there cannot be any OS cache, so it can only rely on real LAN scan results..

lolodomo commented 8 months ago

Ok, I can confirm there is no problem at all with home connect and LG webOS bindings.

The problem with freeboxos is confirmed. Even if I wait many minutes, it does not appear. Same for Android debug bridge and Android TV bindings. So it is mDNS discovery that does not work as expected. Waiting seems to not help. I have now started the server 30 minutes ago.

If I restart OH, I can even get less suggested bindings. It's quite random.

Is there a kind of time frame setup somewhere for mDNS ?

Note that the freebox is detected very fast by the mDNS discovery app on my Android phone.

PS: I also played with the advanced settings and enabling/disabling UPnP/mDNS seems to work even if there is a certain delay, this is not immediate. I can see jupnp bundle being uninstalled when I disable UPnP.

lolodomo commented 8 months ago

After a second server restart, this time, I got no mDNS suggestions, only UPnP suggestions.

I will wait 30 minutes...

Edit: still no mDNS discovery at all.

PS: what is funny is that UPnP discovery seems to work very well while mDNS discovery does not.

andrewfg commented 8 months ago

@lolodomo did you read this? => what OS and hardware etc. do you have?

lolodomo commented 8 months ago

PC on Windows 10. That is very strange, it looks like mDNS suggestion is working at the first start of the server and then returns nothing at the next starts. Maybe it would work again if I restart the PC. I can try. UPnP suggestions does not suffer from that, it is stable even after several OH server restarts.

lolodomo commented 8 months ago

@andrewfg : did yo implement a kind of cache ?

lolodomo commented 8 months ago

I have the feeling it is a startup problem. Maybe the order of bundles startup ? At startup, you get a random result regarding mDNS suggestions. If you disable mDNS suggestion finder, wait a certain moment, then enable it again and wait again a certain moment, then you get all mDNS suggestions. Maybe there is a problem between jmdns and the mDNS suggestion finder ?

lolodomo commented 8 months ago

If I got more results at the very first startup, it could be simply because the order of bundles is very different.

Maybe a race condition somewhere.

andrewfg commented 8 months ago

did yo implement a kind of cache ?

The finder subscribes to the Jmdns service. The Jmdns service probably does have some kind of cache (but I don't know the details). When the finder subscribes to the Jmdns service, the service responds immediately with a bunch of already found mDNS service types, and then over time it adds further mDNS service types as they are discovered in real time.

If you think there is a bug, then it would help to see your trace logs. (@mherwege mentioned above which logger settings to make).

lolodomo commented 8 months ago

I am certain there is a problem at server startup.

Here are partial logs when starting the server. This case leads to 0 mDNS suggestions:

2023-12-09 00:42:29.415 [INFO ] [org.openhab.core.Activator          ] - Starting openHAB 4.1.0 (build Build #3760)
2023-12-09 00:42:29.736 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Time zone set to 'Europe/Paris'.
2023-12-09 00:42:29.737 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Locale set to 'fr_FR'.
2023-12-09 00:42:30.525 [DEBUG] [scovery.addon.AddonSuggestionService] - bundle org.openhab.core.config.discovery.addon:4.1.0.202312080306 (167)[org.openhab.core.config.discovery.addon.AddonSuggestionService] : BundleComponentActivator : ComponentHolder created.
...
2023-12-09 00:42:30.635 [DEBUG] [scovery.addon.AddonSuggestionService] - bundle org.openhab.core.config.discovery.addon:4.1.0.202312080306 (167)[org.openhab.core.config.discovery.addon.AddonSuggestionService(121)] : Changed state from satisfied to active
2023-12-09 00:42:31.414 [DEBUG] [ransport.mdns.internal.MDNSActivator] - mDNS service has been started.
2023-12-09 00:42:31.418 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - bundle org.openhab.core.io.transport.mdns:4.1.0.202312080310 (190)[org.openhab.core.io.transport.mdns.internal.MDNSClientImpl] : BundleComponentActivator : ComponentHolder created.
2023-12-09 00:42:31.421 [DEBUG] [nsport.mdns.internal.MDNSServiceImpl] - bundle org.openhab.core.io.transport.mdns:4.1.0.202312080310 (190)[org.openhab.core.io.transport.mdns.internal.MDNSServiceImpl] : BundleComponentActivator : ComponentHolder created.
...
2023-12-09 00:42:31.826 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - mDNS service has been started (xxx for IP <IPv6_1>)
2023-12-09 00:42:31.835 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - mDNS service has been started (xxx for IP <IPv6_2>)
2023-12-09 00:42:31.845 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - mDNS service has been started (xxx for IP <IPv4>)
...
2023-12-09 00:42:31.963 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - Registering new service _openhab-server._tcp.local. at xxx
2023-12-09 00:42:31.968 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - Registering new service _openhab-server-ssl._tcp.local. at xxx
2023-12-09 00:42:31.975 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - Registering new service _openhab-server._tcp.local. at xxx
2023-12-09 00:42:31.977 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - Registering new service _openhab-server-ssl._tcp.local. at xxx
2023-12-09 00:42:31.980 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - Registering new service _openhab-server._tcp.local. at xxx
2023-12-09 00:42:31.982 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - Registering new service _openhab-server-ssl._tcp.local. at xxx
...
2023-12-09 00:42:32.911 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - ip address change: added [xxx, xxx, xxx, xxx], removed []
2023-12-09 00:42:34.945 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - mDNS service has been stopped (xxx)
2023-12-09 00:42:36.506 [INFO ] [.core.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2023-12-09 00:42:36.959 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - mDNS service has been stopped (xxx)
...
2023-12-09 00:42:38.201 [TRACE] [discovery.addon.mdns.MDNSAddonFinder] - Added service: openhab-ssl._openhab-server-ssl._tcp.local.
2023-12-09 00:42:38.204 [TRACE] [discovery.addon.mdns.MDNSAddonFinder] - Added service: openhab._openhab-server._tcp.local.
2023-12-09 00:42:38.207 [DEBUG] [scovery.addon.AddonSuggestionService] - bundle org.openhab.core.config.discovery.addon:4.1.0.202312080306 (167)[org.openhab.core.config.discovery.addon.AddonSuggestionService(121)] : invoked bind: addAddonFinder
2023-12-09 00:42:38.212 [DEBUG] [scovery.addon.AddonSuggestionService] - bundle org.openhab.core.config.discovery.addon:4.1.0.202312080306 (167)[org.openhab.core.config.discovery.addon.AddonSuggestionService(121)] : dm AddonFinder tracking 8 MultipleDynamic added {org.openhab.core.config.discovery.addon.AddonFinder}={service.id=510, service.bundleid=248, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=mdns-addon-suggestion-finder, component.id=328} (exit)
2023-12-09 00:42:38.242 [TRACE] [discovery.addon.upnp.UpnpAddonFinder] - Added device: Sonos, Inc. Sonos xxx
2023-12-09 00:42:38.266 [TRACE] [discovery.addon.upnp.UpnpAddonFinder] - Added device: Freebox SAS Freebox Media Server 1
2023-12-09 00:42:38.455 [TRACE] [discovery.addon.upnp.UpnpAddonFinder] - Added device: Sonos, Inc. Sonos xxx
2023-12-09 00:42:38.515 [TRACE] [discovery.addon.upnp.UpnpAddonFinder] - Added device: Sonos, Inc. Sonos xxx
2023-12-09 00:42:38.972 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - mDNS service has been stopped (xxx)
2023-12-09 00:42:39.073 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - mDNS service has been started (xxx for IP xxx)
2023-12-09 00:42:39.081 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - mDNS service has been started (xxx for IP xxx)
2023-12-09 00:42:39.090 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - mDNS service has been started (xxx for IP xxx)
2023-12-09 00:42:39.090 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - Registering new service _openhab-server._tcp.local. at xxx
2023-12-09 00:42:39.090 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - Registering new service _openhab-server._tcp.local. at xxx
2023-12-09 00:42:39.092 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - Registering new service _openhab-server._tcp.local. at xxx
2023-12-09 00:42:39.092 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - Registering new service _openhab-server-ssl._tcp.local. at xxx
2023-12-09 00:42:39.093 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - Registering new service _openhab-server-ssl._tcp.local. at xxx
2023-12-09 00:42:39.094 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - Registering new service _openhab-server-ssl._tcp.local. at xxx
2023-12-09 00:42:44.975 [INFO ] [e.automation.internal.RuleEngineImpl] - Rule engine started.
2023-12-09 00:48:49.785 [TRACE] [discovery.addon.upnp.UpnpAddonFinder] - Checking candidate: binding-kaleidescape
...
2023-12-09 00:48:50.217 [TRACE] [discovery.addon.mdns.MDNSAddonFinder] - Checking candidate: binding-freeboxos
2023-12-09 00:48:50.218 [TRACE] [discovery.addon.mdns.MDNSAddonFinder] - Checking service: openhab-ssl._openhab-server-ssl._tcp.local./\00
2023-12-09 00:48:50.219 [TRACE] [discovery.addon.mdns.MDNSAddonFinder] - Checking service: openhab._openhab-server._tcp.local./\00

The mDNS client seems to be started and stopped several times.

lolodomo commented 8 months ago

Here are logs partial logs for another example where only 2 mDNS suggestions are found:

2023-12-09 01:19:36.099 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - mDNS service has been stopped (xxx)
2023-12-09 01:19:36.919 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder] : BundleComponentActivator : ComponentHolder created.
2023-12-09 01:19:36.924 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder] : Dependency Manager created $000interface=org.jupnp.UpnpService, filter=null, policy=static, cardinality=1..1, bind=null, unbind=null, updated=null, field=null, field-option=null, collection-type=service, parameter=0
2023-12-09 01:19:36.926 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder] : 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
2023-12-09 01:19:36.928 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder] : Component created: DS=DS14, implementation=org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder, immediate=false, default-enabled=true, factory=null, configuration-policy=optional, activate=activate, deactivate=deactivate, modified=null configuration-pid=[upnp-addon-suggestion-finder]
2023-12-09 01:19:36.931 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder] : Component Services: scope=singleton, services=[org.openhab.core.config.discovery.addon.AddonFinder]
2023-12-09 01:19:36.932 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder] : Component Properties: {osgi.ds.satisfying.condition.target=(osgi.condition.id=true)}
2023-12-09 01:19:36.934 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder] : Querying state disabled
2023-12-09 01:19:36.935 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder] : Querying state disabled
2023-12-09 01:19:36.936 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder] : Component can not be activated since it is in state disabled
2023-12-09 01:19:36.937 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder] : Querying state disabled
2023-12-09 01:19:36.938 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : Updating target filters
2023-12-09 01:19:36.940 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : No change in target property for dependency $000: currently registered: false
2023-12-09 01:19:36.945 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] :  No existing service listener to unregister for dependency $000
2023-12-09 01:19:36.946 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : Setting target property for dependency $000 to null
2023-12-09 01:19:36.949 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : New service tracker for $000, initial active: false, previous references: {}, classFilter: (objectClass=org.jupnp.UpnpService), initialReferenceFilter (objectClass=org.jupnp.UpnpService)
2023-12-09 01:19:36.959 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : dm $000 tracker reset (closed)
2023-12-09 01:19:36.970 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : dm $000 tracking 1 SingleStatic added {org.jupnp.UpnpService}={service.id=470, service.bundleid=242, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.jupnp.upnpservice, component.id=303} (enter)
2023-12-09 01:19:36.975 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : dm $000 tracking 1 SingleStatic active: false trackerOpened: false optional: false
2023-12-09 01:19:36.979 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : dm $000 tracking 1 SingleStatic added {org.jupnp.UpnpService}={service.id=470, service.bundleid=242, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.jupnp.upnpservice, component.id=303} (exit)
2023-12-09 01:19:36.981 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : dm $000 tracker opened
2023-12-09 01:19:36.981 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : registering service listener for dependency $000
2023-12-09 01:19:36.982 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] :  No existing service listener to unregister for dependency osgi.ds.satisfying.condition
2023-12-09 01:19:36.985 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : Setting target property for dependency osgi.ds.satisfying.condition to (osgi.condition.id=true)
2023-12-09 01:19:36.987 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : 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))
2023-12-09 01:19:36.993 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : dm osgi.ds.satisfying.condition tracker reset (closed)
2023-12-09 01:19:36.997 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : 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)
2023-12-09 01:19:37.056 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : 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)
2023-12-09 01:19:37.082 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : dm osgi.ds.satisfying.condition tracker opened
2023-12-09 01:19:37.103 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : registering service listener for dependency osgi.ds.satisfying.condition
2023-12-09 01:19:37.109 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : Changed state from disabled to unsatisfiedReference
2023-12-09 01:19:37.110 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : Component enabled
2023-12-09 01:19:37.112 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : ActivateInternal
2023-12-09 01:19:37.113 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : Querying state unsatisfiedReference
2023-12-09 01:19:37.115 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : Querying state unsatisfiedReference
2023-12-09 01:19:37.116 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : Activating component from state unsatisfiedReference
2023-12-09 01:19:37.117 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : Querying state unsatisfiedReference
2023-12-09 01:19:37.118 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : Querying state unsatisfiedReference
2023-12-09 01:19:37.120 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : Changed state from unsatisfiedReference to satisfied
2023-12-09 01:19:37.121 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : registration change queue [registered]
2023-12-09 01:19:37.124 [DEBUG] [scovery.addon.AddonSuggestionService] - bundle org.openhab.core.config.discovery.addon:4.1.0.202312080306 (167)[org.openhab.core.config.discovery.addon.AddonSuggestionService(121)] : dm AddonFinder tracking 7 MultipleDynamic added {org.openhab.core.config.discovery.addon.AddonFinder}={service.id=471, service.bundleid=243, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=upnp-addon-suggestion-finder, component.id=305} (enter)
2023-12-09 01:19:37.127 [DEBUG] [scovery.addon.AddonSuggestionService] - bundle org.openhab.core.config.discovery.addon:4.1.0.202312080306 (167)[org.openhab.core.config.discovery.addon.AddonSuggestionService(121)] : dm AddonFinder tracking 7 MultipleDynamic already active, binding {org.openhab.core.config.discovery.addon.AddonFinder}={service.id=471, service.bundleid=243, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=upnp-addon-suggestion-finder, component.id=305}
2023-12-09 01:19:37.132 [DEBUG] [scovery.addon.AddonSuggestionService] - bundle org.openhab.core.config.discovery.addon:4.1.0.202312080306 (167)[org.openhab.core.config.discovery.addon.AddonSuggestionService(121)] : getting bind: addAddonFinder
2023-12-09 01:19:37.133 [DEBUG] [scovery.addon.AddonSuggestionService] - bundle org.openhab.core.config.discovery.addon:4.1.0.202312080306 (167)[org.openhab.core.config.discovery.addon.AddonSuggestionService(121)] : Locating method addAddonFinder in class org.openhab.core.config.discovery.addon.AddonSuggestionService
2023-12-09 01:19:37.135 [DEBUG] [scovery.addon.AddonSuggestionService] - bundle org.openhab.core.config.discovery.addon:4.1.0.202312080306 (167)[org.openhab.core.config.discovery.addon.AddonSuggestionService(121)] : doFindMethod: Looking for method org.openhab.core.config.discovery.addon.AddonSuggestionService.addAddonFinder
2023-12-09 01:19:37.138 [DEBUG] [scovery.addon.AddonSuggestionService] - bundle org.openhab.core.config.discovery.addon:4.1.0.202312080306 (167)[org.openhab.core.config.discovery.addon.AddonSuggestionService(121)] : Declared Method org.openhab.core.config.discovery.addon.AddonSuggestionService.addAddonFinder([interface org.osgi.framework.ServiceReference]) not found
2023-12-09 01:19:37.141 [DEBUG] [scovery.addon.AddonSuggestionService] - bundle org.openhab.core.config.discovery.addon:4.1.0.202312080306 (167)[org.openhab.core.config.discovery.addon.AddonSuggestionService(121)] : Declared Method org.openhab.core.config.discovery.addon.AddonSuggestionService.addAddonFinder([interface org.osgi.service.component.ComponentServiceObjects]) not found
2023-12-09 01:19:37.146 [DEBUG] [scovery.addon.AddonSuggestionService] - bundle org.openhab.core.config.discovery.addon:4.1.0.202312080306 (167)[org.openhab.core.config.discovery.addon.AddonSuggestionService(121)] : getClassFromComponentClassLoader: Looking for interface class org.openhab.core.config.discovery.addon.AddonFinder through loader of org.openhab.core.config.discovery.addon.AddonSuggestionService
2023-12-09 01:19:37.155 [DEBUG] [scovery.addon.AddonSuggestionService] - bundle org.openhab.core.config.discovery.addon:4.1.0.202312080306 (167)[org.openhab.core.config.discovery.addon.AddonSuggestionService(121)] : getClassFromComponentClassLoader: Found class org.openhab.core.config.discovery.addon.AddonFinder
2023-12-09 01:19:37.157 [DEBUG] [scovery.addon.AddonSuggestionService] - bundle org.openhab.core.config.discovery.addon:4.1.0.202312080306 (167)[org.openhab.core.config.discovery.addon.AddonSuggestionService(121)] : doFindMethod: No method taking ServiceReference found, checking method taking org.openhab.core.config.discovery.addon.AddonFinder
2023-12-09 01:19:37.164 [DEBUG] [scovery.addon.AddonSuggestionService] - bundle org.openhab.core.config.discovery.addon:4.1.0.202312080306 (167)[org.openhab.core.config.discovery.addon.AddonSuggestionService(121)] : doFindMethod: Found Method public void org.openhab.core.config.discovery.addon.AddonSuggestionService.addAddonFinder(org.openhab.core.config.discovery.addon.AddonFinder)
2023-12-09 01:19:37.166 [DEBUG] [scovery.addon.AddonSuggestionService] - bundle org.openhab.core.config.discovery.addon:4.1.0.202312080306 (167)[org.openhab.core.config.discovery.addon.AddonSuggestionService(121)] : Found bind method: public void org.openhab.core.config.discovery.addon.AddonSuggestionService.addAddonFinder(org.openhab.core.config.discovery.addon.AddonFinder)
2023-12-09 01:19:37.169 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : Checking constructor public org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(org.jupnp.UpnpService)
2023-12-09 01:19:37.170 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : getClassFromComponentClassLoader: Looking for interface class org.jupnp.UpnpService through loader of org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder
2023-12-09 01:19:37.171 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : getClassFromComponentClassLoader: Found class org.jupnp.UpnpService
2023-12-09 01:19:37.175 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : Found constructor with 1 arguments : public org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(org.jupnp.UpnpService)
2023-12-09 01:19:37.177 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : This thread collected dependencies
2023-12-09 01:19:37.178 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : getService (single component manager) dependencies collected.
2023-12-09 01:19:37.180 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : Querying state satisfied
2023-12-09 01:19:37.181 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : Querying state satisfied
2023-12-09 01:19:37.183 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : For dependency $000, optional: false; to bind: [[RefPair: ref: [{org.jupnp.UpnpService}={service.id=470, service.bundleid=242, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.jupnp.upnpservice, component.id=303}] service: [null]]]
2023-12-09 01:19:37.185 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : 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]]]
2023-12-09 01:19:37.187 [TRACE] [discovery.addon.upnp.UpnpAddonFinder] - Added device: Royal Philips Electronics Philips hue bridge xxx
2023-12-09 01:19:37.190 [TRACE] [discovery.addon.upnp.UpnpAddonFinder] - Added device: Freebox Player Mini
2023-12-09 01:19:37.191 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : getting activate: activate
2023-12-09 01:19:37.193 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : Locating method activate in class org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder
2023-12-09 01:19:37.194 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : Declared Method org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder.activate([interface org.osgi.service.component.ComponentContext]) not found
2023-12-09 01:19:37.196 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : Locating method activate in class org.openhab.core.config.discovery.addon.BaseAddonFinder
2023-12-09 01:19:37.197 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : Declared Method org.openhab.core.config.discovery.addon.BaseAddonFinder.activate([interface org.osgi.service.component.ComponentContext]) not found
2023-12-09 01:19:37.199 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : Locating method activate in class java.lang.Object
2023-12-09 01:19:37.201 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : Declared Method java.lang.Object.activate([interface org.osgi.service.component.ComponentContext]) not found
2023-12-09 01:19:37.212 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : activate method [activate] not found, ignoring
2023-12-09 01:19:37.214 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : Set implementation object for component
2023-12-09 01:19:37.216 [DEBUG] [discovery.addon.upnp.UpnpAddonFinder] - bundle org.openhab.core.config.discovery.addon.upnp:4.1.0.202312080308 (243)[org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder(305)] : Changed state from satisfied to active
2023-12-09 01:19:37.218 [DEBUG] [scovery.addon.AddonSuggestionService] - bundle org.openhab.core.config.discovery.addon:4.1.0.202312080306 (167)[org.openhab.core.config.discovery.addon.AddonSuggestionService(121)] : invoking bind: addAddonFinder: parameters [org.openhab.core.config.discovery.addon.upnp.UpnpAddonFinder]
2023-12-09 01:19:37.221 [DEBUG] [scovery.addon.AddonSuggestionService] - bundle org.openhab.core.config.discovery.addon:4.1.0.202312080306 (167)[org.openhab.core.config.discovery.addon.AddonSuggestionService(121)] : invoked bind: addAddonFinder
2023-12-09 01:19:37.223 [DEBUG] [scovery.addon.AddonSuggestionService] - bundle org.openhab.core.config.discovery.addon:4.1.0.202312080306 (167)[org.openhab.core.config.discovery.addon.AddonSuggestionService(121)] : dm AddonFinder tracking 7 MultipleDynamic added {org.openhab.core.config.discovery.addon.AddonFinder}={service.id=471, service.bundleid=243, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=upnp-addon-suggestion-finder, component.id=305} (exit)
2023-12-09 01:19:37.338 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder] : BundleComponentActivator : ComponentHolder created.
2023-12-09 01:19:37.340 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder] : Dependency Manager created $000interface=org.openhab.core.io.transport.mdns.MDNSClient, filter=null, policy=static, cardinality=1..1, bind=null, unbind=null, updated=null, field=null, field-option=null, collection-type=service, parameter=0
2023-12-09 01:19:37.342 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder] : 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
2023-12-09 01:19:37.346 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder] : Component created: DS=DS14, implementation=org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder, immediate=false, default-enabled=true, factory=null, configuration-policy=optional, activate=activate, deactivate=deactivate, modified=null configuration-pid=[mdns-addon-suggestion-finder]
2023-12-09 01:19:37.348 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder] : Component Services: scope=singleton, services=[org.openhab.core.config.discovery.addon.AddonFinder]
2023-12-09 01:19:37.350 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder] : Component Properties: {osgi.ds.satisfying.condition.target=(osgi.condition.id=true)}
2023-12-09 01:19:37.351 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder] : Querying state disabled
2023-12-09 01:19:37.352 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder] : Querying state disabled
2023-12-09 01:19:37.353 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder] : Component can not be activated since it is in state disabled
2023-12-09 01:19:37.355 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder] : Querying state disabled
2023-12-09 01:19:37.359 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : Updating target filters
2023-12-09 01:19:37.362 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : No change in target property for dependency $000: currently registered: false
2023-12-09 01:19:37.364 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] :  No existing service listener to unregister for dependency $000
2023-12-09 01:19:37.366 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : Setting target property for dependency $000 to null
2023-12-09 01:19:37.367 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : New service tracker for $000, initial active: false, previous references: {}, classFilter: (objectClass=org.openhab.core.io.transport.mdns.MDNSClient), initialReferenceFilter (objectClass=org.openhab.core.io.transport.mdns.MDNSClient)
2023-12-09 01:19:37.369 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : dm $000 tracker reset (closed)
2023-12-09 01:19:37.370 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : dm $000 tracking 1 SingleStatic added {org.openhab.core.io.transport.mdns.MDNSClient}={service.id=309, service.bundleid=190, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.core.io.transport.mdns.internal.MDNSClientImpl, component.id=184} (enter)
2023-12-09 01:19:37.375 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : dm $000 tracking 1 SingleStatic active: false trackerOpened: false optional: false
2023-12-09 01:19:37.380 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : dm $000 tracking 1 SingleStatic added {org.openhab.core.io.transport.mdns.MDNSClient}={service.id=309, service.bundleid=190, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.core.io.transport.mdns.internal.MDNSClientImpl, component.id=184} (exit)
2023-12-09 01:19:37.382 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : dm $000 tracker opened
2023-12-09 01:19:37.384 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : registering service listener for dependency $000
2023-12-09 01:19:37.385 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] :  No existing service listener to unregister for dependency osgi.ds.satisfying.condition
2023-12-09 01:19:37.388 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : Setting target property for dependency osgi.ds.satisfying.condition to (osgi.condition.id=true)
2023-12-09 01:19:37.390 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : 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))
2023-12-09 01:19:37.394 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : dm osgi.ds.satisfying.condition tracker reset (closed)
2023-12-09 01:19:37.396 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : 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)
2023-12-09 01:19:37.399 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : 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)
2023-12-09 01:19:37.404 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : dm osgi.ds.satisfying.condition tracker opened
2023-12-09 01:19:37.407 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : registering service listener for dependency osgi.ds.satisfying.condition
2023-12-09 01:19:37.408 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : Changed state from disabled to unsatisfiedReference
2023-12-09 01:19:37.410 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : Component enabled
2023-12-09 01:19:37.411 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : ActivateInternal
2023-12-09 01:19:37.412 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : Querying state unsatisfiedReference
2023-12-09 01:19:37.413 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : Querying state unsatisfiedReference
2023-12-09 01:19:37.421 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : Activating component from state unsatisfiedReference
2023-12-09 01:19:37.424 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : Querying state unsatisfiedReference
2023-12-09 01:19:37.431 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : Querying state unsatisfiedReference
2023-12-09 01:19:37.434 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : Changed state from unsatisfiedReference to satisfied
2023-12-09 01:19:37.460 [TRACE] [discovery.addon.upnp.UpnpAddonFinder] - Added device: Sonos, Inc. Sonos xxx
2023-12-09 01:19:37.481 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : registration change queue [registered]
2023-12-09 01:19:37.484 [DEBUG] [scovery.addon.AddonSuggestionService] - bundle org.openhab.core.config.discovery.addon:4.1.0.202312080306 (167)[org.openhab.core.config.discovery.addon.AddonSuggestionService(121)] : dm AddonFinder tracking 8 MultipleDynamic added {org.openhab.core.config.discovery.addon.AddonFinder}={service.id=494, service.bundleid=248, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=mdns-addon-suggestion-finder, component.id=328} (enter)
2023-12-09 01:19:37.488 [DEBUG] [scovery.addon.AddonSuggestionService] - bundle org.openhab.core.config.discovery.addon:4.1.0.202312080306 (167)[org.openhab.core.config.discovery.addon.AddonSuggestionService(121)] : dm AddonFinder tracking 8 MultipleDynamic already active, binding {org.openhab.core.config.discovery.addon.AddonFinder}={service.id=494, service.bundleid=248, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=mdns-addon-suggestion-finder, component.id=328}
2023-12-09 01:19:37.494 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : Checking constructor public org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(org.openhab.core.io.transport.mdns.MDNSClient)
2023-12-09 01:19:37.495 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : getClassFromComponentClassLoader: Looking for interface class org.openhab.core.io.transport.mdns.MDNSClient through loader of org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder
2023-12-09 01:19:37.498 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : getClassFromComponentClassLoader: Found class org.openhab.core.io.transport.mdns.MDNSClient
2023-12-09 01:19:37.500 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : Found constructor with 1 arguments : public org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(org.openhab.core.io.transport.mdns.MDNSClient)
2023-12-09 01:19:37.501 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : This thread collected dependencies
2023-12-09 01:19:37.503 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : getService (single component manager) dependencies collected.
2023-12-09 01:19:37.504 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : Querying state satisfied
2023-12-09 01:19:37.509 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : Querying state satisfied
2023-12-09 01:19:37.510 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : For dependency $000, optional: false; to bind: [[RefPair: ref: [{org.openhab.core.io.transport.mdns.MDNSClient}={service.id=309, service.bundleid=190, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=org.openhab.core.io.transport.mdns.internal.MDNSClientImpl, component.id=184}] service: [null]]]
2023-12-09 01:19:37.512 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : 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]]]
2023-12-09 01:19:37.515 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : getting activate: activate
2023-12-09 01:19:37.517 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : Locating method activate in class org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder
2023-12-09 01:19:37.519 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : Declared Method org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder.activate([interface org.osgi.service.component.ComponentContext]) not found
2023-12-09 01:19:37.521 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : Locating method activate in class org.openhab.core.config.discovery.addon.BaseAddonFinder
2023-12-09 01:19:37.525 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : Declared Method org.openhab.core.config.discovery.addon.BaseAddonFinder.activate([interface org.osgi.service.component.ComponentContext]) not found
2023-12-09 01:19:37.527 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : Locating method activate in class java.lang.Object
2023-12-09 01:19:37.528 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : Declared Method java.lang.Object.activate([interface org.osgi.service.component.ComponentContext]) not found
2023-12-09 01:19:37.530 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : activate method [activate] not found, ignoring
2023-12-09 01:19:37.532 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : Set implementation object for component
2023-12-09 01:19:37.534 [DEBUG] [discovery.addon.mdns.MDNSAddonFinder] - bundle org.openhab.core.config.discovery.addon.mdns:4.1.0.202312080312 (248)[org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder(328)] : Changed state from satisfied to active
2023-12-09 01:19:37.535 [DEBUG] [scovery.addon.AddonSuggestionService] - bundle org.openhab.core.config.discovery.addon:4.1.0.202312080306 (167)[org.openhab.core.config.discovery.addon.AddonSuggestionService(121)] : invoking bind: addAddonFinder: parameters [org.openhab.core.config.discovery.addon.mdns.MDNSAddonFinder]
2023-12-09 01:19:37.548 [TRACE] [discovery.addon.mdns.MDNSAddonFinder] - Added service: openhab-ssl._openhab-server-ssl._tcp.local.
2023-12-09 01:19:37.549 [TRACE] [discovery.addon.mdns.MDNSAddonFinder] - Added service: openhab._openhab-server._tcp.local.
2023-12-09 01:19:37.551 [DEBUG] [scovery.addon.AddonSuggestionService] - bundle org.openhab.core.config.discovery.addon:4.1.0.202312080306 (167)[org.openhab.core.config.discovery.addon.AddonSuggestionService(121)] : invoked bind: addAddonFinder
2023-12-09 01:19:37.555 [DEBUG] [scovery.addon.AddonSuggestionService] - bundle org.openhab.core.config.discovery.addon:4.1.0.202312080306 (167)[org.openhab.core.config.discovery.addon.AddonSuggestionService(121)] : dm AddonFinder tracking 8 MultipleDynamic added {org.openhab.core.config.discovery.addon.AddonFinder}={service.id=494, service.bundleid=248, service.scope=bundle, osgi.ds.satisfying.condition.target=(osgi.condition.id=true), component.name=mdns-addon-suggestion-finder, component.id=328} (exit)
2023-12-09 01:19:37.716 [TRACE] [discovery.addon.upnp.UpnpAddonFinder] - Added device: Sonos, Inc. Sonos xxx
2023-12-09 01:19:37.840 [TRACE] [discovery.addon.mdns.MDNSAddonFinder] - Added service: Freebox Server._http._tcp.local.
2023-12-09 01:19:37.841 [TRACE] [discovery.addon.mdns.MDNSAddonFinder] - Added service: Freebox Server._fbx-api._tcp.local.
2023-12-09 01:19:37.920 [TRACE] [discovery.addon.mdns.MDNSAddonFinder] - Added service: openhab3._nut._tcp.local.
2023-12-09 01:19:38.021 [TRACE] [discovery.addon.upnp.UpnpAddonFinder] - Added device: Sonos, Inc. Sonos xxx
2023-12-09 01:19:38.085 [TRACE] [discovery.addon.upnp.UpnpAddonFinder] - Added device: Freebox SAS Freebox Media Server 1
2023-12-09 01:19:38.114 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - mDNS service has been stopped (xxx)
2023-12-09 01:19:40.151 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - mDNS service has been stopped (xxx)
2023-12-09 01:19:40.267 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - mDNS service has been started (xxx for IP xxx)
2023-12-09 01:19:40.275 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - mDNS service has been started (xxx for IP xxx)
2023-12-09 01:19:40.284 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - mDNS service has been started (xxx for IP xxx)
2023-12-09 01:19:40.285 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - Registering new service _openhab-server._tcp.local. at xxx
2023-12-09 01:19:40.285 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - Registering new service _openhab-server._tcp.local. at xxx
2023-12-09 01:19:40.286 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - Registering new service _openhab-server._tcp.local. at xxx
2023-12-09 01:19:40.287 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - Registering new service _openhab-server-ssl._tcp.local. at xxx
2023-12-09 01:19:40.288 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - Registering new service _openhab-server-ssl._tcp.local. at xxx
2023-12-09 01:19:40.289 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - Registering new service _openhab-server-ssl._tcp.local. at xxx
2023-12-09 01:19:41.323 [INFO ] [e.automation.internal.RuleEngineImpl] - Rule engine started.
2023-12-09 01:19:55.893 [TRACE] [discovery.addon.upnp.UpnpAddonFinder] - Checking candidate: binding-avmfritz
lolodomo commented 8 months ago

It looks like the mDNS services are stopped before the device discovery can happen (not enough time). With chance, few devices can be discovered. And the service is finally restarted a last time immediately after.

2023-12-09 01:19:36.099 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - mDNS service has been stopped (xxx)
...
2023-12-09 01:19:32.638 [DEBUG] [ransport.mdns.internal.MDNSActivator] - mDNS service has been started.
...
2023-12-09 01:19:34.084 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - ip address change: added [xxx, xxx, xxx, xxx], removed []
2023-12-09 01:19:35.884 [INFO ] [.core.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2023-12-09 01:19:36.099 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - mDNS service has been stopped (xxx)
...
2023-12-09 01:19:37.840 [TRACE] [discovery.addon.mdns.MDNSAddonFinder] - Added service: Freebox Server._http._tcp.local.
2023-12-09 01:19:37.841 [TRACE] [discovery.addon.mdns.MDNSAddonFinder] - Added service: Freebox Server._fbx-api._tcp.local.
2023-12-09 01:19:37.920 [TRACE] [discovery.addon.mdns.MDNSAddonFinder] - Added service: openhab3._nut._tcp.local.
...
2023-12-09 01:19:38.114 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - mDNS service has been stopped (xxx)
2023-12-09 01:19:40.151 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - mDNS service has been stopped (xxx)
...
2023-12-09 01:19:40.267 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - mDNS service has been started (xxx for IP xxx)
2023-12-09 01:19:40.275 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - mDNS service has been started (xxx for IP xxx)
2023-12-09 01:19:40.284 [DEBUG] [ansport.mdns.internal.MDNSClientImpl] - mDNS service has been started (xxx for IP xxx)

It looks like it is the detection of network interfaces that triggers the restart of the mDNS services (one per interface) and the lost of device discovery.

I guess the problem is rather in o.o.core.io.transport.mdns.

lolodomo commented 8 months ago

The problem is probably here: https://github.com/openhab/openhab-core/blob/main/bundles/org.openhab.core.io.transport.mdns/src/main/java/org/openhab/core/io/transport/mdns/internal/MDNSClientImpl.java#L280

When IP interfaces are detected, there is a call to close() and then start() leading to a removal of all JmDNS instances. They are recreated by the call to start() but apparently without detecting anything again.

We have to implement a more clever onChange() method that will close only JmDNS instances that are really removed, and keep unchanged the instances already started for an interface still present.

I will try during the weekend with a modified version of io.transport.mdns bundle.

lolodomo commented 8 months ago

With the proposed fix, it is now reliable.

lolodomo commented 8 months ago

Tested again with snapshot 3763 and for me everything is working very well now with this new feature. I played again with the enabling/disabling of finders and I can confirm that bundles are installed/uninstalled as expected. It takes few seconds to happen but this is normal I guess. Great.

mherwege commented 8 months ago

It takes few seconds to happen but this is normal I guess.

It happens on a schedule, every minute. So there is a delay of up to a minute.

lolodomo commented 8 months ago

It takes few seconds to happen but this is normal I guess.

It happens on a schedule, every minute. So there is a delay of up to a minute.

I wrongly thought it was the time to install the bundle but I was asking myself why it was so long to uninstall it. Maybe we could reduce a little this timing ?

mherwege commented 8 months ago

Maybe we could reduce a little this timing ?

I would be happy to. But I just did exactly the same thing as in the feature installer/uninstaller for add-ons (code is essentially copied from there). It also refreshes the configuration every minute, so has the same delay for installing/uninstalling an add-on. Is 1 minute really a big deal for this?

lolodomo commented 8 months ago

Is 1 minute really a big deal for this?

Probably not. Most of users will probably not update these settings and as they are ON by default, that is ok. But maybe the description of the setting should mention that the change can take until one minute ?