OH3.2M4, Wemo Binding

lukics · December 1, 2021, 1:56pm

I am using my Wemo switches only for X-Mas light decoration. The last time I used them was when the OH was still 2.5.2 on my production system. Meanwhile, I was running 3.2M3 and the switches were not found anymore. I removed and reinstalled the Wemo binding, with no success. I thought it is a problem with my current OH3.2M3 so I installed the Wemo binding on my test system under OH3.2M4. This time switches were found eminently.
Next, I upgraded the production system to 3.2M4. Still the same issue. Initiating a manual scan does not deliver any results either. I tried to create the switches manually and use the unique ids from the test system. No luck either. The switches are shown online but not working at all. (you can put whatever id, its always online).

Does anybody have an idea what can be wrong here?

hmerk · December 1, 2021, 2:58pm

Please provide more information of your system.
OS / Java version

The binding is running fine, even with larger amount of Wemo devices.
A trace log would be helpfull.

lukics · December 2, 2021, 6:45pm

I have set on both system (pro & test) the log set to:


log:set DEBUG org/openhab/binding/wemo

On the test system, I removed all already installed wemo things an uninstalled the wemo binding. The uninstall on the GUI stalls with running cicle

the debug shows (strange) a restart of BasicUi and HabPanel

2021-12-02 19:25:11.748 [INFO ] [ab.ui.habpanel.internal.HABPanelTile] - Stopped HABPanel
2021-12-02 19:25:11.869 [INFO ] [basic.internal.servlet.WebAppServlet] - Stopped Basic UI
2021-12-02 19:25:17.305 [INFO ] [ab.ui.habpanel.internal.HABPanelTile] - Started HABPanel at /habpanel

After refresh, I see that the binding has gone, no trace in the debug.

I installed the binding, install UI stalles as before, the debug output is as follows:

2021-12-02 19:26:44.137 [INFO ] [ab.ui.habpanel.internal.HABPanelTile] - Stopped HABPanel
2021-12-02 19:26:44.235 [INFO ] [basic.internal.servlet.WebAppServlet] - Stopped Basic UI
2021-12-02 19:26:49.858 [INFO ] [ab.ui.habpanel.internal.HABPanelTile] - Started HABPanel at /habpanel
==> /openhab/userdata/logs/events.log <==
2021-12-02 19:26:51.470 [INFO ] [openhab.event.InboxAddedEvent       ] - Discovery Result with UID 'wemo:insight:Insight-1_0-221501K12005EF' has been added.
2021-12-02 19:26:51.524 [INFO ] [openhab.event.InboxAddedEvent       ] - Discovery Result with UID 'wemo:insight:Insight-1_0-221449K1200DCF' has been added.
==> /openhab/userdata/logs/openhab.log <==
2021-12-02 19:26:51.468 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'wemo:insight:Insight-1_0-221501K12005EF' to inbox.
2021-12-02 19:26:51.523 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'wemo:insight:Insight-1_0-221449K1200DCF' to inbox.

This is the functioning test system

The steps I do on the prod system
wemo binding is not installed so I start the binding installation. As on the test system the binding installation stalles with following debug output:

2021-12-02 19:36:53.031 [INFO ] [ab.ui.habpanel.internal.HABPanelTile] - Stopped HABPanel
2021-12-02 19:36:53.212 [INFO ] [basic.internal.servlet.WebAppServlet] - Stopped Basic UI
2021-12-02 19:36:53.243 [INFO ] [io.openhabcloud.internal.CloudClient] - Shutting down openHAB Cloud service connection
2021-12-02 19:36:53.247 [INFO ] [io.openhabcloud.internal.CloudClient] - Disconnected from the openHAB Cloud service (UUID = xxx, base URL = http://localhost:8080)
2021-12-02 19:37:00.240 [INFO ] [io.openhabcloud.internal.CloudClient] - Connected to the openHAB Cloud service (UUID = xxx, base URL = http://localhost:8080)
2021-12-02 19:37:01.103 [INFO ] [ab.ui.habpanel.internal.HABPanelTile] - Started HABPanel at /habpanel

Not any trace about discovery

both systems are docker instances started with the following compose file:

  openhab:
    image: openhab/openhab:${OH_VERSION:-3.2.0.M3}
    depends_on:
      - "deconz"
      - "raspberrymatic"
    container_name: openhab
    network_mode: host
    restart: unless-stopped
    volumes:
      - /etc/localtime:/etc/localtime:ro
      - /etc/timezone:/etc/timezone:ro
      - /datavol/openhab-${OH_VERSION:-3.2.0.M3}/openhab_addons:/openhab/addons 
      - /datavol/openhab-${OH_VERSION:-3.2.0.M3}/openhab_conf:/openhab/conf 
      - /datavol/openhab-${OH_VERSION:-3.2.0.M3}/openhab_userdata:/openhab/userdata 
      - /datavol/openhab-${OH_VERSION:-3.2.0.M3}/cont-init.d:/etc/cont-init.d
    environment:
      - USER_ID=9001
      - GROUP_ID=9001
      - OPENHAB_HTTP_PORT=8080
      - OPENHAB_HTTPS_PORT=8443
      - EXTRA_JAVA_OPTS=-Duser.timezone=Europe/Berlin -Xms400m -Xmx650m 
      - CRYPTO_POLICY=unlimited

hmerk · December 2, 2021, 9:13pm

I asked for a trace log so please set loglevel to TRACE.
What is the output of
bundle:list |grep Wemo
on both systems?

lukics · December 3, 2021, 2:12pm

TEST-SYSTEM - the functioning one

openhab> bundle:list |grep Wemo
251 │ Active │  80 │ 3.2.0.M4              │ openHAB Add-ons :: Bundles :: Wemo Binding
openhab>  bundle:classes | grep wemo                                                                                                                                                                                                                                          
251 | org/openhab/binding/wemo/internal/WemoHandlerFactory.class | exported: false
251 | org/openhab/binding/wemo/internal/discovery/WemoLinkDiscoveryService.class | exported: false
251 | org/openhab/binding/wemo/internal/handler/WemoMakerHandler.class | exported: false
251 | org/openhab/binding/wemo/internal/handler/WemoDimmerHandler.class | exported: false
251 | org/openhab/binding/wemo/internal/handler/AbstractWemoHandler.class | exported: false
251 | org/openhab/binding/wemo/internal/handler/WemoHandler$1.class | exported: false
251 | org/openhab/binding/wemo/internal/handler/WemoCoffeeHandler$1.class | exported: false
251 | org/openhab/binding/wemo/internal/handler/WemoCoffeeHandler.class | exported: false
251 | org/openhab/binding/wemo/internal/handler/WemoMakerHandler$1.class | exported: false
251 | org/openhab/binding/wemo/internal/handler/WemoLightHandler.class | exported: false
251 | org/openhab/binding/wemo/internal/handler/WemoBridgeHandler.class | exported: false
251 | org/openhab/binding/wemo/internal/handler/WemoDimmerHandler$1.class | exported: false
251 | org/openhab/binding/wemo/internal/handler/WemoLightHandler$1.class | exported: false
251 | org/openhab/binding/wemo/internal/handler/WemoHandler.class | exported: false
251 | org/openhab/binding/wemo/internal/http/WemoHttpCall.class | exported: false
251 | org/openhab/binding/wemo/internal/WemoHttpCallFactory.class | exported: false
251 | org/openhab/binding/wemo/internal/discovery/WemoDiscoveryParticipant.class | exported: false
251 | org/openhab/binding/wemo/internal/discovery/WemoDiscoveryService.class | exported: false
251 | org/openhab/binding/wemo/internal/discovery/WemoLinkDiscoveryService$WemoLinkScan.class | exported: false
251 | org/openhab/binding/wemo/internal/WemoUtil.class | exported: false
251 | org/openhab/binding/wemo/internal/WemoBindingConstants.class | exported: false
251 | org/openhab/binding/wemo/internal/handler/WemoHolmesHandler.class | exported: false
251 | org/openhab/binding/wemo/internal/handler/WemoCrockpotHandler.class | exported: false

PRODUCTION

openhab> bundle:list |grep Wemo                                                                                                                                                                                                                                               
302 │ Active │  80 │ 3.2.0.M4              │ openHAB Add-ons :: Bundles :: Wemo Binding
openhab> bundle:classes | grep wemo                                                                                                                                                                                                                                           
302 | org/openhab/binding/wemo/internal/WemoHandlerFactory.class | exported: false
302 | org/openhab/binding/wemo/internal/discovery/WemoLinkDiscoveryService.class | exported: false
302 | org/openhab/binding/wemo/internal/handler/WemoMakerHandler.class | exported: false
302 | org/openhab/binding/wemo/internal/handler/WemoDimmerHandler.class | exported: false
302 | org/openhab/binding/wemo/internal/handler/AbstractWemoHandler.class | exported: false
302 | org/openhab/binding/wemo/internal/handler/WemoHandler$1.class | exported: false
302 | org/openhab/binding/wemo/internal/handler/WemoCoffeeHandler$1.class | exported: false
302 | org/openhab/binding/wemo/internal/handler/WemoCoffeeHandler.class | exported: false
302 | org/openhab/binding/wemo/internal/handler/WemoMakerHandler$1.class | exported: false
302 | org/openhab/binding/wemo/internal/handler/WemoLightHandler.class | exported: false
302 | org/openhab/binding/wemo/internal/handler/WemoBridgeHandler.class | exported: false
302 | org/openhab/binding/wemo/internal/handler/WemoDimmerHandler$1.class | exported: false
302 | org/openhab/binding/wemo/internal/handler/WemoLightHandler$1.class | exported: false
302 | org/openhab/binding/wemo/internal/handler/WemoHandler.class | exported: false
302 | org/openhab/binding/wemo/internal/http/WemoHttpCall.class | exported: false
302 | org/openhab/binding/wemo/internal/WemoHttpCallFactory.class | exported: false
302 | org/openhab/binding/wemo/internal/discovery/WemoDiscoveryParticipant.class | exported: false
302 | org/openhab/binding/wemo/internal/discovery/WemoDiscoveryService.class | exported: false
302 | org/openhab/binding/wemo/internal/discovery/WemoLinkDiscoveryService$WemoLinkScan.class | exported: false
302 | org/openhab/binding/wemo/internal/WemoUtil.class | exported: false
302 | org/openhab/binding/wemo/internal/WemoBindingConstants.class | exported: false
302 | org/openhab/binding/wemo/internal/handler/WemoHolmesHandler.class | exported: false
302 | org/openhab/binding/wemo/internal/handler/WemoCrockpotHandler.class | exported: false

on both system loglevel to trace

openhab> log:set TRACE org/openhab/binding/wemo

TEST-SYSTEM

all existing wemo things delete and initiated a manual scan

2021-12-03 15:07:30.211 [INFO ] [openhab.event.InboxAddedEvent       ] - Discovery Result with UID 'wemo:insight:Insight-1_0-221501K12005EF' has been added.
2021-12-03 15:07:30.213 [INFO ] [openhab.event.InboxAddedEvent       ] - Discovery Result with UID 'wemo:insight:Insight-1_0-221449K1200DCF' has been added.
==> /openhab/userdata/logs/openhab.log <==
2021-12-03 15:07:30.211 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'wemo:insight:Insight-1_0-221501K12005EF' to inbox.
2021-12-03 15:07:30.213 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'wemo:insight:Insight-1_0-221449K1200DCF' to inbox.

2 new things in the inbox

PRODUCTION

initiated a manual scan

no identifiable log out at all

hmerk · December 3, 2021, 2:31pm

Oh, just saw it now, the command is not correct, needs to be

log:set TRACE org.openhab.binding.wemo

It is dots, not slashes…
Please answer the question regarding the Java version (full string)…

lukics · December 3, 2021, 2:49pm

s…t

I have uninstalled wemo binding.

This is the log during the installation of the wemo binding, manual scan does not produce any log trace.

2021-12-03 15:40:04.265 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory] : BundleComponentActivator : ComponentHolder created.
2021-12-03 15:40:04.267 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant] : BundleComponentActivator : ComponentHolder created.
2021-12-03 15:40:04.270 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService] : BundleComponentActivator : ComponentHolder created.
2021-12-03 15:40:04.276 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory] : Dependency Manager created $000interface=org.openhab.core.io.transport.upnp.UpnpIOService, filter=null, policy=static, cardinality=1..1, bind=null, unbind=null, updated=null, field=null, field-option=null, collection-type=null, parameter=0
2021-12-03 15:40:04.277 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory] : Dependency Manager created WemoHttpCallFactoryinterface=org.openhab.binding.wemo.internal.WemoHttpCallFactory, filter=null, policy=dynamic, cardinality=0..1, bind=setWemoHttpCallFactory, unbind=unsetWemoHttpCallFactory, updated=null, field=null, field-option=null, collection-type=null, parameter=null
2021-12-03 15:40:04.277 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory] : Component created: DS=DS14, implementation=org.openhab.binding.wemo.internal.WemoHandlerFactory, immediate=false, default-enabled=true, factory=null, configuration-policy=optional, activate=activate, deactivate=deactivate, modified=null configuration-pid=[binding.wemo]
2021-12-03 15:40:04.278 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory] : Component Services: scope=singleton, services=[org.openhab.core.thing.binding.ThingHandlerFactory]
2021-12-03 15:40:04.279 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory] : Component Properties: {}
2021-12-03 15:40:04.280 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory] : Querying state disabled
2021-12-03 15:40:04.280 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory] : Querying state disabled
2021-12-03 15:40:04.281 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory] : Component can not be activated since it is in state disabled
2021-12-03 15:40:04.282 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory] : Querying state disabled
2021-12-03 15:40:04.283 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : Updating target filters
2021-12-03 15:40:04.284 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : No change in target property for dependency $000: currently registered: false
2021-12-03 15:40:04.285 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] :  No existing service listener to unregister for dependency $000
2021-12-03 15:40:04.285 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : Setting target property for dependency $000 to null
2021-12-03 15:40:04.286 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : New service tracker for $000, initial active: false, previous references: {}, classFilter: (objectClass=org.openhab.core.io.transport.upnp.UpnpIOService), initialReferenceFilter (objectClass=org.openhab.core.io.transport.upnp.UpnpIOService)
2021-12-03 15:40:04.287 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : dm $000 tracker reset (closed)
2021-12-03 15:40:04.290 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : dm $000 tracking 1 SingleStatic added {org.openhab.core.io.transport.upnp.UpnpIOService, org.jupnp.registry.RegistryListener}={service.id=495, service.bundleid=289, service.scope=bundle, component.name=org.openhab.core.io.transport.upnp.internal.UpnpIOServiceImpl, component.id=318} (enter)
2021-12-03 15:40:04.291 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : dm $000 tracking 1 SingleStatic active: false trackerOpened: false optional: false
2021-12-03 15:40:04.291 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : dm $000 tracking 1 SingleStatic added {org.openhab.core.io.transport.upnp.UpnpIOService, org.jupnp.registry.RegistryListener}={service.id=495, service.bundleid=289, service.scope=bundle, component.name=org.openhab.core.io.transport.upnp.internal.UpnpIOServiceImpl, component.id=318} (exit)
2021-12-03 15:40:04.292 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : dm $000 tracker opened
2021-12-03 15:40:04.293 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : registering service listener for dependency $000
2021-12-03 15:40:04.294 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : No change in target property for dependency WemoHttpCallFactory: currently registered: false
2021-12-03 15:40:04.295 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] :  No existing service listener to unregister for dependency WemoHttpCallFactory
2021-12-03 15:40:04.295 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : Setting target property for dependency WemoHttpCallFactory to null
2021-12-03 15:40:04.296 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : New service tracker for WemoHttpCallFactory, initial active: false, previous references: {}, classFilter: (objectClass=org.openhab.binding.wemo.internal.WemoHttpCallFactory), initialReferenceFilter (objectClass=org.openhab.binding.wemo.internal.WemoHttpCallFactory)
2021-12-03 15:40:04.297 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : dm WemoHttpCallFactory tracker reset (closed)
2021-12-03 15:40:04.303 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : dm WemoHttpCallFactory tracker opened
2021-12-03 15:40:04.304 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : registering service listener for dependency WemoHttpCallFactory
2021-12-03 15:40:04.305 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : Changed state from disabled to unsatisfiedReference
2021-12-03 15:40:04.306 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : Component enabled
2021-12-03 15:40:04.306 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : ActivateInternal
2021-12-03 15:40:04.307 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : Querying state unsatisfiedReference
2021-12-03 15:40:04.308 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : Querying state unsatisfiedReference
2021-12-03 15:40:04.309 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : Activating component from state unsatisfiedReference
2021-12-03 15:40:04.310 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : Querying state unsatisfiedReference
2021-12-03 15:40:04.310 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : Querying state unsatisfiedReference
2021-12-03 15:40:04.311 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : Changed state from unsatisfiedReference to satisfied
2021-12-03 15:40:04.312 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : registration change queue [registered]
2021-12-03 15:40:04.316 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : Checking constructor public org.openhab.binding.wemo.internal.WemoHandlerFactory(org.openhab.core.io.transport.upnp.UpnpIOService)
2021-12-03 15:40:04.317 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : getReferenceClass: Looking for interface class org.openhab.core.io.transport.upnp.UpnpIOService through loader of org.openhab.binding.wemo.internal.WemoHandlerFactory
2021-12-03 15:40:04.318 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : getParameterClass: Found class org.openhab.core.io.transport.upnp.UpnpIOService
2021-12-03 15:40:04.319 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : Found constructor with 1 arguments : public org.openhab.binding.wemo.internal.WemoHandlerFactory(org.openhab.core.io.transport.upnp.UpnpIOService)
2021-12-03 15:40:04.320 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : This thread collected dependencies
2021-12-03 15:40:04.320 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : getService (single component manager) dependencies collected.
2021-12-03 15:40:04.321 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : Querying state satisfied
2021-12-03 15:40:04.322 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : Querying state satisfied
2021-12-03 15:40:04.323 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : For dependency $000, optional: false; to bind: [[RefPair: ref: [{org.openhab.core.io.transport.upnp.UpnpIOService, org.jupnp.registry.RegistryListener}={service.id=495, service.bundleid=289, service.scope=bundle, component.name=org.openhab.core.io.transport.upnp.internal.UpnpIOServiceImpl, component.id=318}] service: [null]]]
2021-12-03 15:40:04.323 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : For dependency WemoHttpCallFactory, optional: true; to bind: []
2021-12-03 15:40:04.327 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : getting activate: activate
2021-12-03 15:40:04.328 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : Locating method activate in class org.openhab.binding.wemo.internal.WemoHandlerFactory
2021-12-03 15:40:04.330 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : Declared Method org.openhab.binding.wemo.internal.WemoHandlerFactory.activate([interface org.osgi.service.component.ComponentContext]) not found
2021-12-03 15:40:04.331 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : Locating method activate in class org.openhab.core.thing.binding.BaseThingHandlerFactory
2021-12-03 15:40:04.332 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : Found activate method: protected void org.openhab.core.thing.binding.BaseThingHandlerFactory.activate(org.osgi.service.component.ComponentContext)
2021-12-03 15:40:04.333 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : invoking activate: activate: parameters [org.apache.felix.scr.impl.manager.ComponentContextImpl]
2021-12-03 15:40:04.334 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : invoked activate: activate
2021-12-03 15:40:04.335 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : Set implementation object for component
2021-12-03 15:40:04.336 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.WemoHandlerFactory(973)] : Changed state from satisfied to active
2021-12-03 15:40:04.338 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant] : Component created: DS=DS13, implementation=org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant, immediate=false, default-enabled=true, factory=null, configuration-policy=optional, activate=activate, deactivate=deactivate, modified=null configuration-pid=[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant]
2021-12-03 15:40:04.339 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant] : Component Services: scope=singleton, services=[org.openhab.core.config.discovery.upnp.UpnpDiscoveryParticipant]
2021-12-03 15:40:04.340 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant] : Component Properties: {}
2021-12-03 15:40:04.341 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant] : Querying state disabled
2021-12-03 15:40:04.341 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant] : Querying state disabled
2021-12-03 15:40:04.342 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant] : Component can not be activated since it is in state disabled
2021-12-03 15:40:04.343 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant] : Querying state disabled
2021-12-03 15:40:04.344 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : Updating target filters
2021-12-03 15:40:04.345 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : Changed state from disabled to unsatisfiedReference
2021-12-03 15:40:04.346 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : Component enabled
2021-12-03 15:40:04.347 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : ActivateInternal
2021-12-03 15:40:04.347 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : Querying state unsatisfiedReference
2021-12-03 15:40:04.348 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : Querying state unsatisfiedReference
2021-12-03 15:40:04.349 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : Activating component from state unsatisfiedReference
2021-12-03 15:40:04.350 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : Querying state unsatisfiedReference
2021-12-03 15:40:04.350 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : Querying state unsatisfiedReference
2021-12-03 15:40:04.351 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : Changed state from unsatisfiedReference to satisfied
2021-12-03 15:40:04.352 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : registration change queue [registered]
2021-12-03 15:40:04.355 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : Checking constructor public org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant()
2021-12-03 15:40:04.356 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : Found constructor with 0 arguments : public org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant()
2021-12-03 15:40:04.357 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : This thread collected dependencies
2021-12-03 15:40:04.358 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : getService (single component manager) dependencies collected.
2021-12-03 15:40:04.358 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : Querying state satisfied
2021-12-03 15:40:04.359 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : Querying state satisfied
2021-12-03 15:40:04.360 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : getting activate: activate
2021-12-03 15:40:04.360 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : Locating method activate in class org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant
2021-12-03 15:40:04.361 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : Declared Method org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant.activate([interface org.osgi.service.component.ComponentContext]) not found
2021-12-03 15:40:04.362 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : Locating method activate in class java.lang.Object
2021-12-03 15:40:04.363 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : Declared Method java.lang.Object.activate([interface org.osgi.service.component.ComponentContext]) not found
2021-12-03 15:40:04.364 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : activate method [activate] not found, ignoring
2021-12-03 15:40:04.364 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : Set implementation object for component
2021-12-03 15:40:04.365 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryParticipant(974)] : Changed state from satisfied to active
2021-12-03 15:40:04.367 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService] : Dependency Manager created UpnpServiceinterface=org.jupnp.UpnpService, filter=null, policy=static, cardinality=1..1, bind=setUpnpService, unbind=unsetUpnpService, updated=null, field=null, field-option=null, collection-type=null, parameter=null
2021-12-03 15:40:04.368 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService] : Component created: DS=DS13, implementation=org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService, immediate=false, default-enabled=true, factory=null, configuration-policy=optional, activate=activate, deactivate=deactivate, modified=null configuration-pid=[discovery.wemo]
2021-12-03 15:40:04.368 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService] : Component Services: scope=singleton, services=[org.openhab.core.config.discovery.DiscoveryService]
2021-12-03 15:40:04.369 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService] : Component Properties: {}
2021-12-03 15:40:04.370 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService] : Querying state disabled
2021-12-03 15:40:04.370 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService] : Querying state disabled
2021-12-03 15:40:04.371 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService] : Component can not be activated since it is in state disabled
2021-12-03 15:40:04.372 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService] : Querying state disabled
2021-12-03 15:40:04.373 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : Updating target filters
2021-12-03 15:40:04.374 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : No change in target property for dependency UpnpService: currently registered: false
2021-12-03 15:40:04.374 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] :  No existing service listener to unregister for dependency UpnpService
2021-12-03 15:40:04.375 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : Setting target property for dependency UpnpService to null
2021-12-03 15:40:04.376 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : New service tracker for UpnpService, initial active: false, previous references: {}, classFilter: (objectClass=org.jupnp.UpnpService), initialReferenceFilter (objectClass=org.jupnp.UpnpService)
2021-12-03 15:40:04.377 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : dm UpnpService tracker reset (closed)
2021-12-03 15:40:04.380 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : dm UpnpService tracking 1 SingleStatic added {org.jupnp.UpnpService}={service.id=493, service.bundleid=260, service.scope=bundle, component.name=org.jupnp.upnpservice, component.id=315} (enter)
2021-12-03 15:40:04.381 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : dm UpnpService tracking 1 SingleStatic active: false trackerOpened: false optional: false
2021-12-03 15:40:04.381 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : dm UpnpService tracking 1 SingleStatic added {org.jupnp.UpnpService}={service.id=493, service.bundleid=260, service.scope=bundle, component.name=org.jupnp.upnpservice, component.id=315} (exit)
2021-12-03 15:40:04.383 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : dm UpnpService tracker opened
2021-12-03 15:40:04.384 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : registering service listener for dependency UpnpService
2021-12-03 15:40:04.385 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : Changed state from disabled to unsatisfiedReference
2021-12-03 15:40:04.386 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : Component enabled
2021-12-03 15:40:04.386 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : ActivateInternal
2021-12-03 15:40:04.387 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : Querying state unsatisfiedReference
2021-12-03 15:40:04.388 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : Querying state unsatisfiedReference
2021-12-03 15:40:04.388 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : Activating component from state unsatisfiedReference
2021-12-03 15:40:04.389 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : Querying state unsatisfiedReference
2021-12-03 15:40:04.390 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : Querying state unsatisfiedReference
2021-12-03 15:40:04.390 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : Changed state from unsatisfiedReference to satisfied
2021-12-03 15:40:04.391 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : registration change queue [registered]
2021-12-03 15:40:04.395 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : Checking constructor public org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService()
2021-12-03 15:40:04.396 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : Found constructor with 0 arguments : public org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService()
2021-12-03 15:40:04.397 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : getting bind: setUpnpService
2021-12-03 15:40:04.398 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : Locating method setUpnpService in class org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService
2021-12-03 15:40:04.398 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : doFindMethod: Looking for method org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService.setUpnpService
2021-12-03 15:40:04.399 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : Declared Method org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService.setUpnpService([interface org.osgi.framework.ServiceReference]) not found
2021-12-03 15:40:04.400 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : Declared Method org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService.setUpnpService([interface org.osgi.service.component.ComponentServiceObjects]) not found
2021-12-03 15:40:04.401 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : getReferenceClass: Looking for interface class org.jupnp.UpnpService through loader of org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService
2021-12-03 15:40:04.402 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : getParameterClass: Found class org.jupnp.UpnpService
2021-12-03 15:40:04.403 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : doFindMethod: No method taking ServiceReference found, checking method taking org.jupnp.UpnpService
2021-12-03 15:40:04.404 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : doFindMethod: Found Method protected void org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService.setUpnpService(org.jupnp.UpnpService)
2021-12-03 15:40:04.404 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : Found bind method: protected void org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService.setUpnpService(org.jupnp.UpnpService)
2021-12-03 15:40:04.405 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : This thread collected dependencies
2021-12-03 15:40:04.406 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : getService (single component manager) dependencies collected.
2021-12-03 15:40:04.406 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : Querying state satisfied
2021-12-03 15:40:04.407 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : Querying state satisfied
2021-12-03 15:40:04.408 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : For dependency UpnpService, optional: false; to bind: [[RefPair: ref: [{org.jupnp.UpnpService}={service.id=493, service.bundleid=260, service.scope=bundle, component.name=org.jupnp.upnpservice, component.id=315}] service: [org.jupnp.UpnpServiceImpl@190d510]]]
2021-12-03 15:40:04.409 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : invoking bind: setUpnpService: parameters [org.jupnp.UpnpServiceImpl]
2021-12-03 15:40:04.410 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : invoked bind: setUpnpService
2021-12-03 15:40:04.410 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : getting activate: activate
2021-12-03 15:40:04.411 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : Locating method activate in class org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService
2021-12-03 15:40:04.412 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : Declared Method org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService.activate([interface org.osgi.service.component.ComponentContext]) not found
2021-12-03 15:40:04.413 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : Found activate method: public void org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService.activate()
2021-12-03 15:40:04.415 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : invoking activate: activate: parameters []
2021-12-03 15:40:04.416 [DEBUG] [ernal.discovery.WemoDiscoveryService] - Starting WeMo UPnP discovery...
2021-12-03 15:40:04.417 [DEBUG] [ernal.discovery.WemoDiscoveryService] - Starting UPnP RootDevice search...
2021-12-03 15:40:04.419 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : invoked activate: activate
2021-12-03 15:40:04.420 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : Set implementation object for component
2021-12-03 15:40:04.421 [DEBUG] [ernal.discovery.WemoDiscoveryService] - bundle org.openhab.binding.wemo:3.2.0.M4 (303)[org.openhab.binding.wemo.internal.discovery.WemoDiscoveryService(975)] : Changed state from satisfied to active

wemo-log-trace.txt (38.8 KB)

lukics · December 3, 2021, 3:30pm

I have run the installation of the wemo binding both systems (test&prod) and recorded the log trace once again.
I then compared the text in both logs, they are identical, same text and line count (except to time and some repeating internal IDs)

hmerk · December 3, 2021, 3:38pm

Why aren‘t you answering my question for the Java version of both machines ?

As both machines run openHAB 3.2.M4, there is unlikely an issue with the binding or openHAB. The binding has been proved solid with larger installations.

The issue could be Java version or different UPnP settings in your router for both machines.

lukics · December 3, 2021, 3:56pm

I thought that the info that is the official docker image answers the question
here the info:

lukics@vevedock-tst-01:~ $ docker exec -it openhab bash
root@vevedock-tst-01:/openhab# java -version
openjdk version "11.0.13" 2021-10-19 LTS
OpenJDK Runtime Environment Zulu11.52+13-CA (build 11.0.13+8-LTS)
OpenJDK Client VM Zulu11.52+13-CA (build 11.0.13+8-LTS, mixed mode)
root@vevedock-tst-01:/openhab# 


lukics@vevedock-pro:~/git.com/docker-swarm-and-compose/HA-Cluster $ docker exec -it openhab bash
root@vevedock-pro:/openhab# java -version
openjdk version "11.0.13" 2021-10-19 LTS
OpenJDK Runtime Environment Zulu11.52+13-CA (build 11.0.13+8-LTS)
OpenJDK Client VM Zulu11.52+13-CA (build 11.0.13+8-LTS, mixed mode)
root@vevedock-pro:/openhab#

sorry

hmerk · December 3, 2021, 4:02pm

Sorry, did not see that.
Then you should check your routers UPnP settings.

lukics · December 3, 2021, 5:30pm

No clue what I could do!
I checked my router, and the differences between the two nodes (pro&test) and do not see any difference.
On the pro there is a much bigger stack of applications running

the next thing I will do is do an apt update/upgrade and reboot the pro server.

lukics · December 3, 2021, 5:50pm

no luck, upgraded, rebooted!
How could I make some test that UPNP is wkn/nwkn on particular server

I use a lot of binding, cannot imagine that wemo is that special. All the other discoveries are ok

lukics · December 3, 2021, 7:58pm

from both test&pro I ussed a upnp scan

gssdp-discover -i eth0 --timeout=3

nothing found referring to wemo

I am lost

A lot of sonos and other references

hmerk · December 3, 2021, 8:56pm

Wemo devices do not respond on „normal“ discovery, that‘s why the binding does a custom discovery.

I am sorry, but I have no clue why the same version is running on one machine but not on the other.

hmerk · December 3, 2021, 9:00pm

Just saw only one openhab entry in your picture, is it the working one ?
Wondering that it shows no ports….

lukics · December 4, 2021, 7:43am

I found some resources on the web and tried following:

logedin into the production openhab container

docker exec -i openhab bash

updated the packed and installed npm, nano and the " node wemo-client"

apt update
....
apt install npm nano
....
npm install wemo-client
....

I copied the wemo test node script into local wemo.js:

var Wemo = require('wemo-client');
var wemo = new Wemo();

wemo.discover(function(err, deviceInfo) {
  console.log('Wemo Device Found: %j', deviceInfo);

  // Get the client for the found device
  var client = wemo.client(deviceInfo);

  // You definitely want to listen to error events (e.g. device went offline),
  // Node will throw them as an exception if they are left unhandled  
  client.on('error', function(err) {
    console.log('Error: %s', err.code);
  });

  // Handle BinaryState events
  client.on('binaryState', function(value) {
    console.log('Binary State changed to: %s', value);
  });

  // Turn the switch on
  client.setBinaryState(1);
});

ran the wemo.js

root@vevedock-pro:/openhab# node wemo.js 
Wemo Device Found: {"deviceType":"urn:Belkin:device:insight:1","friendlyName":"weihnachtsbaum","manufacturer":"Belkin International Inc.","manufacturerURL":"http://www.belkin.com","modelDescription":"Belkin Insight 1.0","modelName":"Insight","modelNumber":"1.0","modelURL":"http://www.belkin.com/plugin/","serialNumber":"221449K1200DCF","UDN":"uuid:Insight-1_0-221449K1200DCF","UPC":"123456789","macAddress":"94103E3E26EC","firmwareVersion":"WeMo_WW_2.00.11532.PVT-OWRT-Insight","iconVersion":"1|49153","binaryState":"0","binaryOption":"1","new_algo":"1","iconList":{"icon":{"mimetype":"jpg","width":"100","height":"100","depth":"100","url":"icon.jpg"}},"serviceList":{"service":[{"serviceType":"urn:Belkin:service:WiFiSetup:1","serviceId":"urn:Belkin:serviceId:WiFiSetup1","controlURL":"/upnp/control/WiFiSetup1","eventSubURL":"/upnp/event/WiFiSetup1","SCPDURL":"/setupservice.xml"},{"serviceType":"urn:Belkin:service:timesync:1","serviceId":"urn:Belkin:serviceId:timesync1","controlURL":"/upnp/control/timesync1","eventSubURL":"/upnp/event/timesync1","SCPDURL":"/timesyncservice.xml"},{"serviceType":"urn:Belkin:service:basicevent:1","serviceId":"urn:Belkin:serviceId:basicevent1","controlURL":"/upnp/control/basicevent1","eventSubURL":"/upnp/event/basicevent1","SCPDURL":"/eventservice.xml"},{"serviceType":"urn:Belkin:service:firmwareupdate:1","serviceId":"urn:Belkin:serviceId:firmwareupdate1","controlURL":"/upnp/control/firmwareupdate1","eventSubURL":"/upnp/event/firmwareupdate1","SCPDURL":"/firmwareupdate.xml"},{"serviceType":"urn:Belkin:service:rules:1","serviceId":"urn:Belkin:serviceId:rules1","controlURL":"/upnp/control/rules1","eventSubURL":"/upnp/event/rules1","SCPDURL":"/rulesservice.xml"},{"serviceType":"urn:Belkin:service:metainfo:1","serviceId":"urn:Belkin:serviceId:metainfo1","controlURL":"/upnp/control/metainfo1","eventSubURL":"/upnp/event/metainfo1","SCPDURL":"/metainfoservice.xml"},{"serviceType":"urn:Belkin:service:remoteaccess:1","serviceId":"urn:Belkin:serviceId:remoteaccess1","controlURL":"/upnp/control/remoteaccess1","eventSubURL":"/upnp/event/remoteaccess1","SCPDURL":"/remoteaccess.xml"},{"serviceType":"urn:Belkin:service:deviceinfo:1","serviceId":"urn:Belkin:serviceId:deviceinfo1","controlURL":"/upnp/control/deviceinfo1","eventSubURL":"/upnp/event/deviceinfo1","SCPDURL":"/deviceinfoservice.xml"},{"serviceType":"urn:Belkin:service:insight:1","serviceId":"urn:Belkin:serviceId:insight1","controlURL":"/upnp/control/insight1","eventSubURL":"/upnp/event/insight1","SCPDURL":"/insightservice.xml"},{"serviceType":"urn:Belkin:service:smartsetup:1","serviceId":"urn:Belkin:serviceId:smartsetup1","controlURL":"/upnp/control/smartsetup1","eventSubURL":"/upnp/event/smartsetup1","SCPDURL":"/smartsetup.xml"},{"serviceType":"urn:Belkin:service:manufacture:1","serviceId":"urn:Belkin:serviceId:manufacture1","controlURL":"/upnp/control/manufacture1","eventSubURL":"/upnp/event/manufacture1","SCPDURL":"/manufacture.xml"}]},"presentationURL":"/pluginpres.html","host":"192.168.3.83","port":"49153","callbackURL":"http://192.168.3.140:32869"}
Wemo Device Found: {"deviceType":"urn:Belkin:device:insight:1","friendlyName":"Weihnachtsstrauch Terasse","manufacturer":"Belkin International Inc.","manufacturerURL":"http://www.belkin.com","modelDescription":"Belkin Insight 1.0","modelName":"Insight","modelNumber":"1.0","modelURL":"http://www.belkin.com/plugin/","serialNumber":"221501K12005EF","UDN":"uuid:Insight-1_0-221501K12005EF","UPC":"123456789","macAddress":"94103E3EA21C","firmwareVersion":"WeMo_WW_2.00.11532.PVT-OWRT-Insight","iconVersion":"1|49153","binaryState":"0","binaryOption":"1","new_algo":"1","iconList":{"icon":{"mimetype":"jpg","width":"100","height":"100","depth":"100","url":"icon.jpg"}},"serviceList":{"service":[{"serviceType":"urn:Belkin:service:WiFiSetup:1","serviceId":"urn:Belkin:serviceId:WiFiSetup1","controlURL":"/upnp/control/WiFiSetup1","eventSubURL":"/upnp/event/WiFiSetup1","SCPDURL":"/setupservice.xml"},{"serviceType":"urn:Belkin:service:timesync:1","serviceId":"urn:Belkin:serviceId:timesync1","controlURL":"/upnp/control/timesync1","eventSubURL":"/upnp/event/timesync1","SCPDURL":"/timesyncservice.xml"},{"serviceType":"urn:Belkin:service:basicevent:1","serviceId":"urn:Belkin:serviceId:basicevent1","controlURL":"/upnp/control/basicevent1","eventSubURL":"/upnp/event/basicevent1","SCPDURL":"/eventservice.xml"},{"serviceType":"urn:Belkin:service:firmwareupdate:1","serviceId":"urn:Belkin:serviceId:firmwareupdate1","controlURL":"/upnp/control/firmwareupdate1","eventSubURL":"/upnp/event/firmwareupdate1","SCPDURL":"/firmwareupdate.xml"},{"serviceType":"urn:Belkin:service:rules:1","serviceId":"urn:Belkin:serviceId:rules1","controlURL":"/upnp/control/rules1","eventSubURL":"/upnp/event/rules1","SCPDURL":"/rulesservice.xml"},{"serviceType":"urn:Belkin:service:metainfo:1","serviceId":"urn:Belkin:serviceId:metainfo1","controlURL":"/upnp/control/metainfo1","eventSubURL":"/upnp/event/metainfo1","SCPDURL":"/metainfoservice.xml"},{"serviceType":"urn:Belkin:service:remoteaccess:1","serviceId":"urn:Belkin:serviceId:remoteaccess1","controlURL":"/upnp/control/remoteaccess1","eventSubURL":"/upnp/event/remoteaccess1","SCPDURL":"/remoteaccess.xml"},{"serviceType":"urn:Belkin:service:deviceinfo:1","serviceId":"urn:Belkin:serviceId:deviceinfo1","controlURL":"/upnp/control/deviceinfo1","eventSubURL":"/upnp/event/deviceinfo1","SCPDURL":"/deviceinfoservice.xml"},{"serviceType":"urn:Belkin:service:insight:1","serviceId":"urn:Belkin:serviceId:insight1","controlURL":"/upnp/control/insight1","eventSubURL":"/upnp/event/insight1","SCPDURL":"/insightservice.xml"},{"serviceType":"urn:Belkin:service:smartsetup:1","serviceId":"urn:Belkin:serviceId:smartsetup1","controlURL":"/upnp/control/smartsetup1","eventSubURL":"/upnp/event/smartsetup1","SCPDURL":"/smartsetup.xml"},{"serviceType":"urn:Belkin:service:manufacture:1","serviceId":"urn:Belkin:serviceId:manufacture1","controlURL":"/upnp/control/manufacture1","eventSubURL":"/upnp/event/manufacture1","SCPDURL":"/manufacture.xml"}]},"presentationURL":"/pluginpres.html","host":"192.168.3.79","port":"49153","callbackURL":"http://192.168.3.140:32869"}
Binary State changed to: 1
Binary State changed to: 8
Binary State changed to: 8

I can see that out of the openhab container the UPnP is working.
I do not have any idea, what to do next.

hmerk · December 4, 2021, 8:40am

So there is an issue with the container settings, blocking UPnP traffic….

As I don‘t use docker, I cannot further assist.

lukics · December 4, 2021, 9:03am

No that is not the case. I am running the node.js script out of the same container by attaching to the running openhab container.

docker exec -i openhab bash

runs a bash shell on the same instance

hmerk · December 4, 2021, 9:15am

Oh, sorry, missunderstood you, thought you are running node on the machine but outside the container.

Please check your network settings in MainUI.
Did you set the primary address ???
Compare with the working setup…