Wemo subscription failed in OH 2.2.0

Add-ons Bindings
,
1

Hello,

I previously had a Wemo insight switch running in OH 2.1 with wemo binding 0.9.0 successfully.
After doing a yum package update to OH 2.2 the whole system wouldn’t start anymore…I eventually gave up troubleshooting that and just yum removed the packages and re-installed from scratch.

Now I cannot seem to get the insight switch to work again.
Initially after installing new wemo binding it did show up in inbox and could be added as a thing but all I ever got in the logs were these messages:

2017-12-21 16:49:34.712 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - WeMo UPnP device Insight-1_0-221608K12007D6 not yet registered
2017-12-21 16:49:34.716 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Setting up WeMo GENA subscription for ‘org.eclipse.smarthome.binding.wemo.handler.WemoHandler@2126f49f’ FAILED - service.isRegistered(this) is FALSE

At some point I deleted the thing and tried to re-discover; it no longer shows up in inbox or manual search. Doing a manual add with the same UDN leads to those same gena subscription errors and nothing more.

Not sure how to troubleshoot this further; can anyone help?
Here are the wemo related logs of installing the binding and adding the thing manually:

2017-12-21 16:44:47.167 [DEBUG] [org.eclipse.smarthome.binding.wemo ] - BundleEvent INSTALLED - org.eclipse.smarthome.binding.wemo
2017-12-21 16:44:47.223 [DEBUG] [org.eclipse.smarthome.binding.wemo ] - BundleEvent RESOLVED - org.eclipse.smarthome.binding.wemo
2017-12-21 16:44:47.245 [DEBUG] [org.eclipse.smarthome.binding.wemo ] - BundleEvent STARTING - org.eclipse.smarthome.binding.wemo
2017-12-21 16:44:47.250 [DEBUG] [org.eclipse.smarthome.binding.wemo ] - BundleEvent STARTED - org.eclipse.smarthome.binding.wemo
2017-12-21 16:44:47.281 [DEBUG] [org.eclipse.smarthome.binding.wemo ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.upnp.UpnpDiscoveryParticipant}={component.name=org.eclipse.smarthome.binding.wemo.discovery.WemoDiscoveryParticipant, component.id=214, service.id=344, service.bundleid=226, service.scope=bundle} - org.eclipse.smarthome.binding.wemo
2017-12-21 16:44:47.289 [DEBUG] [ernal.discovery.WemoDiscoveryService] - Starting WeMo UPnP discovery…
2017-12-21 16:44:47.292 [DEBUG] [ernal.discovery.WemoDiscoveryService] - Starting UPnP RootDevice search…
2017-12-21 16:44:47.297 [DEBUG] [org.eclipse.smarthome.binding.wemo ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={component.name=org.eclipse.smarthome.binding.wemo.discovery.WemoDiscoveryService, component.id=215, service.id=345, service.bundleid=226, service.scope=bundle} - org.eclipse.smarthome.binding.wemo
2017-12-21 16:44:47.310 [DEBUG] [org.eclipse.smarthome.binding.wemo ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={component.name=org.eclipse.smarthome.binding.wemo.internal.WemoHandlerFactory, component.id=216, service.id=346, service.bundleid=226, service.scope=bundle} - org.eclipse.smarthome.binding.wemo
2017-12-21 16:45:34.644 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - Trying to create a handler for ThingType 'wemo:insight
2017-12-21 16:45:34.662 [DEBUG] [ing.wemo.internal.WemoHandlerFactory] - Creating a WemoHandler for thing ‘wemo:insight:257efe0d’ with UDN 'Insight-1_0-221608K12007D6’
2017-12-21 16:45:34.671 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Creating a WemoHandler for thing 'wemo:insight:257efe0d’
2017-12-21 16:45:34.685 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Initializing WemoHandler for UDN 'Insight-1_0-221608K12007D6’
2017-12-21 16:45:34.687 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Setting up WeMo GENA subscription for ‘org.eclipse.smarthome.binding.wemo.handler.WemoHandler@2126f49f’ FAILED - service.isRegistered(this) is FALSE
2017-12-21 16:45:34.691 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - WeMo UPnP device Insight-1_0-221608K12007D6 not yet registered
2017-12-21 16:45:34.694 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Setting up WeMo GENA subscription for ‘org.eclipse.smarthome.binding.wemo.handler.WemoHandler@2126f49f’ FAILED - service.isRegistered(this) is FALSE

OH server can reach the wemo switch:
nmap 10.0.2.93
Starting Nmap 6.40 ( http://nmap.org ) at 2017-12-21 16:52 AEDT
Nmap scan report for 10.0.2.93
Host is up (0.0044s latency).
Not shown: 998 closed ports
PORT STATE SERVICE
53/tcp open domain
49153/tcp open unknown
MAC Address: 94:10:3E:43:1C:FD (Unknown)

It works ok in the wemo android app.
Server is a Centos 7.4 VM. Java is openjdk 1.8.0_151.

Thank you,
-Martin.

2

Could you please check your Java version. It seems you are running openJDK, which is not recommended.
Please change to Oracle JAVA.

3

I am interested in this thread as I am forever having wemo issues.
I was surprised that openhabian uses openjdk and you advise that it is not recommended?

here is my output:

java -version
openjdk version "1.8.0_152"
OpenJDK Runtime Environment (Zulu Embedded 8.25.0.76-linux-aarch32hf) (build 1.8.0_152-b76)
OpenJDK Client VM (Zulu Embedded 8.25.0.76-linux-aarch32hf) (build 25.152-b76, mixed mode, Evaluation)

Thanks

Paul

4

No, that’s not what I meant.
If it’s Zulu embedded openJDK, than it is fine.
Out of Martins post, I could not see if it is Zulu or not.

5

Mine is not the zulu version. I’ll try the Oracle version when I get a chance and see if it behaves differently thanks.

6

Thanks for the clarification, I find myself totally lost when it comes to
jave and its many versions and even products; way to confusing for those
passing by and not heavily involved.

Regards

Paul

7

I have no idea what changed but randomly yesterday morning it started working from one minute to the next:

2017-12-22 07:43:39.914 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - WeMo UPnP device Insight-1_0-221608K12007D6 not yet registered
2017-12-22 07:43:39.916 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Setting up WeMo GENA subscription for ‘org.eclipse.smarthome.binding.wemo.handler.WemoHandler@67ea20d6’ FAILED - service.isRegistered(this) is FALSE
2017-12-22 07:45:39.918 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - WeMo UPnP device Insight-1_0-221608K12007D6 not yet registered
2017-12-22 07:45:39.920 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Setting up WeMo GENA subscription for ‘org.eclipse.smarthome.binding.wemo.handler.WemoHandler@67ea20d6’ FAILED - service.isRegistered(this) is FALSE
2017-12-22 07:46:01.621 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - Discovered a WeMo Insight thing with UDN 'Insight-1_0-221608K12007D6’
2017-12-22 07:46:01.624 [DEBUG] [l.discovery.WemoDiscoveryParticipant] - Created a DiscoveryResult for device ‘WeMo 1’ with UDN 'Insight-1_0-221608K12007D6’
2017-12-22 07:47:39.953 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Setting up GENA subscription Insight-1_0-221608K12007D6: Subscribing to service basicevent1…
2017-12-22 07:47:39.958 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Setting up GENA subscription Insight-1_0-221608K12007D6: Subscribing to service insight1…
2017-12-22 07:47:39.987 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - WeMo Insight-1_0-221608K12007D6: Subscription to service insight1 succeeded
2017-12-22 07:47:39.998 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - WeMo Insight-1_0-221608K12007D6: Subscription to service basicevent1 succeeded

And now regularly:
12:06:20.864 [DEBUG] [home.binding.wemo.handler.WemoHandler] - Received pair ‘InsightParams’:‘8|1513989582|273|8188|8036|1209600|631|1200|81364790|81364790|8000’ (service ‘insight1’) for thing ‘wemo:insight:257efe0d’

Changing to Oracle java seemed to break charting for some reason so I reverted that for now until I have more time to investigate.