Wemo Binding FAILED - service.isRegistered

Hi, I’ve been experiencing some issue in OH2 with the Wemo binding stability. When booting the Raspberry the Binding does work correctly for some hours and all connection are working, then suddenly the Wemo light switches stop responding in all my rules and sitemap. If I do try the Wemo ios app, the switch are still responding…

i did try to capture that with the log and got that:

When booting the Raspberry, all status are updated:

2017-09-26 08:32:32.227 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New state ‘0’ for device ‘wemo:lightswitch:Lightswitch-1_0-221413K130090B’ received
2017-09-26 08:32:32.228 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Received pair ‘BinaryState’:‘0’ (service ‘basicevent1’) for thing 'wemo:lightswitch:Lightswitch-1_0-221413K130090B’
2017-09-26 08:32:32.234 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - State ‘OFF’ for device ‘wemo:lightswitch:Lightswitch-1_0-221413K130090B’ received
2017-09-26 08:32:32.240 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Checking WeMo GENA subscription for 'org.eclipse.smarthome.binding.wemo.handler.WemoHandler@11cc897’
2017-09-26 08:32:46.958 [TRACE] [ome.binding.wemo.handler.WemoHandler] - State response

Then after a period of time The log gives me:

[DEBUG] [o.discovery.WemoDiscoveryParticipant] - Discovered a WeMo Lightswitch thing with UDN 'Lightswitch-1_0-221410K1300935’
2017-09-26 20:48:27.419 [DEBUG] [o.discovery.WemoDiscoveryParticipant] - Discovered a WeMo Lightswitch thing with UDN 'Lightswitch-1_0-221413K130090B’
2017-09-26 20:48:32.193 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - WeMo UPnP device Lightswitch-1_0-221413K130090B not yet registered
2017-09-26 20:48:32.194 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Setting up WeMo GENA subscription for ‘org.eclipse.smarthome.binding.wemo.handler.WemoHandler@11cc897’ FAILED - service.isRegistered(this) is FALSE
2017-09-26 20:48:46.929 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - WeMo UPnP device Lightswitch-1_0-221410K1300935 not yet registered
2017-09-26 20:48:46.931 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Setting up WeMo GENA subscription for ‘org.eclipse.smarthome.binding.wemo.handler.WemoHandler@69adcd’ FAILED - service.isRegistered(this) is FALSE
2017-09-26 20:50:22.975 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Setting up WeMo GENA subscription for ‘org.eclipse.smarthome.binding.wemo.handler.WemoHandler@17848a7’ FAILED - service.isRegistered(this) is FALSE
2017-09-26 20:50:32.192 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - WeMo UPnP device Lightswitch-1_0-221413K130090B not yet registered

i did try two different method of declaring the items:

  1. Using Paper UI Things, creating dummy switch in a .items so that I refer to them in a .sitemap and also use the Homekit integration
//Type	SW_Name		VisualisationName	Logo	HomekitType
Switch 	lt_bedroom 	"Lumiere Chambre"	<light>	["Lighting"]
Switch 	lt_outside 	"Lumiere Exterieur"	<light>	["Lighting"]

2)Simply using the .items file to declare them and have the Thing discovered in Paper UI but not linked to any .item

//Type	SW_Name		VisualisationName	Logo	HomekitType		UUID
Switch 	lt_bedroom 	"Lumiere Chambre"	<light>	["Lighting"]	{channel="wemo:lightswitch:Lightswitch-1_0-221413K130090B:state"}
Switch 	lt_outside 	"Lumiere Exterieur"	<light>	["Lighting"]	{channel="wemo:lightswitch:Lightswitch-1_0-221410K1300935:state"}

in both situation the GENA subscription always end up failing after a certain period of time. Is there something I’ve missed? I did try a quick search on the forum but no luck.

Note: All my OH2 updated we done last week but nothing fixed the issue

I will check this. Do you have other WeMo devices in your environment? If yes, are those failing ?
Asking, because I can’t see this behavior at my installation. Do not have a WeMo lightswitch cause it’s not available in Germany.

Thk for your quick reply. I,ve connected a Wemo socket that I have around and i,ll monitor if the same issue happen. currently in my Wemo item file there are 2 Wemo lightswitch and a Wemo socket. Is there anything special I should trace to help the debugging process ?

I’ve just got a fail of one of the two light switch some minutes ago. Here is the log showing all 3 devices working (both lightSwitch and 1 socket) then 1 light switch stopping.

one strange thing is the Paper UI is still reporting the status as “Online” but the channel is clearly not responding anymore

</s:Body> </s:Envelope>’ for device ‘wemo:lightswitch:Lightswitch-1_0-221410K1300935’ received
2017-09-28 20:01:34.783 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New state ‘1’ for device ‘wemo:lightswitch:Lightswitch-1_0-221410K1300935’ received
2017-09-28 20:01:34.785 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Received pair ‘BinaryState’:‘1’ (service ‘basicevent1’) for thing 'wemo:lightswitch:Lightswitch-1_0-221410K1300935’
2017-09-28 20:01:34.789 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - State ‘ON’ for device ‘wemo:lightswitch:Lightswitch-1_0-221410K1300935’ received
2017-09-28 20:01:34.795 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Checking WeMo GENA subscription for 'org.eclipse.smarthome.binding.wemo.handler.WemoHandler@107b351’
2017-09-28 20:01:34.826 [TRACE] [ome.binding.wemo.handler.WemoHandler] - State response ‘<s:Envelope xmlns:s=“http://schemas.xmlsoap.org/soap/envelope/” s:encodingStyle=“http://schemas.xmlsoap.org/soap/encoding/”><s:Body>
<u:GetBinaryStateResponse xmlns:u=“urn:Belkin:service:basicevent:1”>
0
</u:GetBinaryStateResponse>
</s:Body> </s:Envelope>’ for device ‘wemo:lightswitch:Lightswitch-1_0-221413K130090B’ received
2017-09-28 20:01:34.829 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New state ‘0’ for device ‘wemo:lightswitch:Lightswitch-1_0-221413K130090B’ received
2017-09-28 20:01:34.831 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Received pair ‘BinaryState’:‘0’ (service ‘basicevent1’) for thing 'wemo:lightswitch:Lightswitch-1_0-221413K130090B’
2017-09-28 20:01:34.834 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - State ‘OFF’ for device ‘wemo:lightswitch:Lightswitch-1_0-221413K130090B’ received
2017-09-28 20:01:34.838 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Checking WeMo GENA subscription for 'org.eclipse.smarthome.binding.wemo.handler.WemoHandler@c96331’
2017-09-28 20:01:38.007 [DEBUG] [o.discovery.WemoDiscoveryParticipant] - Discovered a WeMo Lightswitch thing with UDN 'Lightswitch-1_0-221413K130090B’
2017-09-28 20:02:17.068 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - WeMo Socket-1_0-221422K0100AEF: Subscription to service basicevent1 succeeded
2017-09-28 20:02:17.100 [ERROR] [g.jupnp.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /upnpcallback/dev/Socket-1_0-221422K0100AEF/svc/Belkin/basicevent1/event/cb SEQUENCE: 2
2017-09-28 20:03:34.741 [TRACE] [ome.binding.wemo.handler.WemoHandler] - State response ‘<s:Envelope xmlns:s=“http://schemas.xmlsoap.org/soap/envelope/” s:encodingStyle=“http://schemas.xmlsoap.org/soap/encoding/”><s:Body>
<u:GetBinaryStateResponse xmlns:u=“urn:Belkin:service:basicevent:1”>
0
</u:GetBinaryStateResponse>
</s:Body> </s:Envelope>’ for device ‘wemo:socket:Socket-1_0-221422K0100AEF’ received
2017-09-28 20:03:34.744 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New state ‘0’ for device ‘wemo:socket:Socket-1_0-221422K0100AEF’ received
2017-09-28 20:03:34.747 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Received pair ‘BinaryState’:‘0’ (service ‘basicevent1’) for thing 'wemo:socket:Socket-1_0-221422K0100AEF’
2017-09-28 20:03:34.752 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - State ‘OFF’ for device ‘wemo:socket:Socket-1_0-221422K0100AEF’ received
2017-09-28 20:03:34.756 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Checking WeMo GENA subscription for 'org.eclipse.smarthome.binding.wemo.handler.WemoHandler@1948c8b’
2017-09-28 20:03:34.796 [TRACE] [ome.binding.wemo.handler.WemoHandler] - State response ‘<s:Envelope xmlns:s=“http://schemas.xmlsoap.org/soap/envelope/” s:encodingStyle=“http://schemas.xmlsoap.org/soap/encoding/”><s:Body>
<u:GetBinaryStateResponse xmlns:u=“urn:Belkin:service:basicevent:1”>
1
</u:GetBinaryStateResponse>
</s:Body> </s:Envelope>’ for device ‘wemo:lightswitch:Lightswitch-1_0-221410K1300935’ received
2017-09-28 20:03:34.800 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New state ‘1’ for device ‘wemo:lightswitch:Lightswitch-1_0-221410K1300935’ received
2017-09-28 20:03:34.803 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Received pair ‘BinaryState’:‘1’ (service ‘basicevent1’) for thing 'wemo:lightswitch:Lightswitch-1_0-221410K1300935’
2017-09-28 20:03:34.807 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - WeMo UPnP device Lightswitch-1_0-221413K130090B not yet registered
2017-09-28 20:03:34.809 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Setting up WeMo GENA subscription for ‘org.eclipse.smarthome.binding.wemo.handler.WemoHandler@c96331’ FAILED - service.isRegistered(this) is FALSE
2017-09-28 20:03:34.809 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - State ‘ON’ for device ‘wemo:lightswitch:Lightswitch-1_0-221410K1300935’ received
2017-09-28 20:03:34.815 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Checking WeMo GENA subscription for 'org.eclipse.smarthome.binding.wemo.handler.WemoHandler@107b351’
2017-09-28 20:03:39.170 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - WeMo Lightswitch-1_0-221410K1300935: Subscription to service basicevent1 succeeded
2017-09-28 20:03:39.195 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Received pair ‘BinaryState’:‘1’ (service ‘basicevent1’) for thing 'wemo:lightswitch:Lightswitch-1_0-221410K1300935’
2017-09-28 20:03:39.198 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - State ‘ON’ for device ‘wemo:lightswitch:Lightswitch-1_0-221410K1300935’ received
2017-09-28 20:05:34.726 [TRACE] [ome.binding.wemo.handler.WemoHandler] - State response ‘<s:Envelope xmlns:s=“http://schemas.xmlsoap.org/soap/envelope/” s:encodingStyle=“http://schemas.xmlsoap.org/soap/encoding/”><s:Body>
<u:GetBinaryStateResponse xmlns:u=“urn:Belkin:service:basicevent:1”>
0
</u:GetBinaryStateResponse>
</s:Body> </s:Envelope>’ for device ‘wemo:socket:Socket-1_0-221422K0100AEF’ received
2017-09-28 20:05:34.728 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New state ‘0’ for device ‘wemo:socket:Socket-1_0-221422K0100AEF’ received
2017-09-28 20:05:34.730 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Received pair ‘BinaryState’:‘0’ (service ‘basicevent1’) for thing 'wemo:socket:Socket-1_0-221422K0100AEF’
2017-09-28 20:05:34.733 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - State ‘OFF’ for device ‘wemo:socket:Socket-1_0-221422K0100AEF’ received
2017-09-28 20:05:34.737 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Checking WeMo GENA subscription for 'org.eclipse.smarthome.binding.wemo.handler.WemoHandler@1948c8b’
2017-09-28 20:05:34.789 [TRACE] [ome.binding.wemo.handler.WemoHandler] - State response ‘<s:Envelope xmlns:s=“http://schemas.xmlsoap.org/soap/envelope/” s:encodingStyle=“http://schemas.xmlsoap.org/soap/encoding/”><s:Body>
<u:GetBinaryStateResponse xmlns:u=“urn:Belkin:service:basicevent:1”>
1
</u:GetBinaryStateResponse>
</s:Body> </s:Envelope>’ for device ‘wemo:lightswitch:Lightswitch-1_0-221410K1300935’ received
2017-09-28 20:05:34.791 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New state ‘1’ for device ‘wemo:lightswitch:Lightswitch-1_0-221410K1300935’ received
2017-09-28 20:05:34.793 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Received pair ‘BinaryState’:‘1’ (service ‘basicevent1’) for thing 'wemo:lightswitch:Lightswitch-1_0-221410K1300935’
2017-09-28 20:05:34.796 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - State ‘ON’ for device ‘wemo:lightswitch:Lightswitch-1_0-221410K1300935’ received
2017-09-28 20:05:34.801 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Checking WeMo GENA subscription for 'org.eclipse.smarthome.binding.wemo.handler.WemoHandler@107b351’
2017-09-28 20:05:34.807 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - WeMo UPnP device Lightswitch-1_0-221413K130090B not yet registered
2017-09-28 20:05:34.809 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Setting up WeMo GENA subscription for ‘org.eclipse.smarthome.binding.wemo.handler.WemoHandler@c96331’ FAILED - service.isRegistered(this) is FALSE
2017-09-28 20:07:18.179 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - WeMo Socket-1_0-221422K0100AEF: Subscription to service basicevent1 succeeded
2017-09-28 20:07:18.211 [ERROR] [g.jupnp.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /upnpcallback/dev/Socket-1_0-221422K0100AEF/svc/Belkin/basicevent1/event/cb SEQUENCE: 2
2017-09-28 20:07:34.726 [TRACE] [ome.binding.wemo.handler.WemoHandler] - State response '<s:Envelope xmlns:s=“http://schemas.xmlsoap.org/soap/envelope/” s:encodingStyle=“http://schemas.xmlsoap.org/soap/encoding/”><s:Body>
<u:GetBinaryStateResponse xmlns:u=“urn:Belkin:service:basicevent:1”>
0
</u:GetBinaryStateResponse>

Thanks for your log posting. Seems Belkin again changed things in the firmware wich break the binding.
I will have to check …

Hi there, is there any word on this issue, I am trying to add an ESP8266 WEMO emulator and am receiving the same error as described in this post. it will also not auto discover so I had to make manual entries in .items and .things but still no joy.

the arduino can be made to respond to discoveries but OH2 will not register them.

Can you post what the discovery process of OH2 is looking for ? as well as a status of this issue. I notice that the discover messages do not include the “Belkin:device…” in the search parameter so I would assume it is looking for everything, not just belkin ?

Many thanks, I look forward to getting this resolved and up and running

We are using „global“ UPnP discover and extended it with a RootDevice search

            upnpService.getControlPoint().search(new RootDeviceHeader());

as WeMo devices respond to that search only.
The binding then looks for Belkin specific entries in the discovery results

  if (device.getDetails().getManufacturerDetails().getManufacturer() != null) {
                if (device.getDetails().getManufacturerDetails().getManufacturer().toUpperCase().contains("BELKIN")) {
                    if (device.getDetails().getModelDetails().getModelName() != null) {
                        if (device.getDetails().getModelDetails().getModelName().toLowerCase().startsWith("socket")) {
                            logger.debug("Discovered a WeMo Socket thing with UDN '{}'",
                                    device.getIdentity().getUdn().getIdentifierString());
                            return new ThingUID(THING_TYPE_SOCKET, device.getIdentity().getUdn().getIdentifierString());
                        }

Upon the service.isRegistered failure, I did not see such an error in my logs, so I have to investigate a bit more. This might take some time as I am quite busy on other projekts.

I think I may have found the problem.
Based on the statement elsewhere that Belkin has changed their interfaces again etc, I looked at the source code for the ESP8266/Arduino and a whole bunch of other locations including many base documents for global UPnP protocols and came up with a new implementation of the Arduino side of the puzzle, it now correctly responds to the discovery requests (Sends back a compatable working response) and therefor is now further interrogated for setup and actions etc.

It was also lacking a getBinaryState method so I added that too and this removed pretty much all the errors I was seeing. I will record a howto on all that real soon including my code.

Can you please tell me what keys are you using for the database for the detected wemo device. I changed the name and UUID and re ran discover but it continued with the old entries so I am thinking it may be keyed on IP Address or something?, can you please verify what your using for me.

Thanks for the help
Peter

Key is the device udn (Socket-1234…)

Thanks for the info, I had changed the wemo’s udn from “Socket-1_0-38323636-4558-4dda-9188-cda0e…” to “Socket-1_0-48323636-4558-4dda-9188-cda0e…” but it would not detect till I removed the existing and re started OH.
I can’t see in your code why it would not pick it up but it is a minor thing I guess. I do however still get GENA errors, this is a snip from the log

02:27:58.294 [TRACE] [ome.binding.wemo.handler.WemoHandler] - State response '<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetBinaryStateResponse xmlns:u="urn:Belkin:service:basicevent:1"><BinaryState>0</BinaryState></u:GetBinaryStateResponse></s:Body></s:Envelope>' for device 'wemo:socket:Socket-1_0-48323636-4558-4dda-9188-cda0e623c81b' received
02:27:58.296 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New state '0' for device 'wemo:socket:Socket-1_0-48323636-4558-4dda-9188-cda0e623c81b' received
02:27:58.298 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Received pair 'BinaryState':'0' (service 'basicevent1') for thing 'wemo:socket:Socket-1_0-48323636-4558-4dda-9188-cda0e623c81b'
02:27:58.301 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - State 'OFF' for device 'wemo:socket:Socket-1_0-48323636-4558-4dda-9188-cda0e623c81b' received
02:27:58.312 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Checking WeMo GENA subscription for 'org.eclipse.smarthome.binding.wemo.handler.WemoHandler@11890cb'
02:27:58.314 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Setting up GENA subscription Socket-1_0-48323636-4558-4dda-9188-cda0e623c81b: Subscribing to service basicevent1...
02:27:58.363 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - WeMo Socket-1_0-48323636-4558-4dda-9188-cda0e623c81b: Subscription to service basicevent1 failed

I can not find a reference to the wemo actually having to support this and the code seems to indicate it is a local feature of the wemo binding module, if you can clarify anything here or provide a link for further reading it would be appreciated.
Thanks
Peter

Please have a look here

Wow, that was quick, thanks

So there is a “Subscription” handler the wemo is supposed to implement… ok
From reading that article, it seems I need to use unorthodox methods on the HTTP protocol, in addition to the normal post, get, delete, etc. the wemo protocol is adding SUBSCRIBE, NOTIFY and UNSUBSCRIBE… am I reading this correctly ?, and is the current OH2 binding already calling out on this, I was only trapping POST and GET methods up to now.

If this is the case then updating the Arduino / ESP code just got much more complicated lol.

Those are no unorthodox methods, it is UPnP standard.
If you might have a look at my code at


You will see that the binding uses UPnP calls implemented in

based on

Will do, but perhaps later, its 4:30am :sleeping: and I need sleep lol. I will pick up on this later, thanks.

very useful links

Peter

OK, I have the Client end “Almost” complete, you may be able to help out with a quick answer
I have my ESP responding to the SUBSCRIBE method and the OH2 is seeing it but throwing an error
this is what I am returning

String subResponse_txt =
        "HTTP/1.1 200 OK\r\n"
        "CONTENT-LENGTH: 0\r\n"
        "SID: uuid:7206f5ac-1dd2-11b2-80f3-e76de858414e\r\n"
        "TIMEOUT: Second-3600\r\n"
        "SERVER: ArdESP8266, 1.0 , UPnP/1.0, ESP8266 ,1.1\r\n"
        "Connection: close\r\n\r\n";
        SendResponse("text/html", subResponse_txt);

I have been wading through the code for the WEMO and UPnP but so far have not figured out what is wrong, I am pretty sure it is something very simple

Do you see anything wrong there, this is the error I get in the console

01:39:58.326 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Setting up GENA subscription Socket-1_0-48323636-4558-4dda-9188-cda0e623c81b: Subscribing to service basicevent1...
01:39:58.372 [ERROR] [jupnp.protocol.sync.SendingSubscribe] - Subscription failed, invalid or missing (SID, Timeout) response headers
01:39:58.375 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - WeMo Socket-1_0-48323636-4558-4dda-9188-cda0e623c81b: Subscription to service basicevent1 failed

but they are clearly there so perhaps something else ??

Thanks in advance for the help again
Peter

My wemos started acting weird as well, I uninstalled and now can’t detect them anymore. So this post and if I understood this right wemo has changed their firmware?

The first poster and the response seem to indicate that. I also just bought a WEMO Insight and after installing it, the first thing it prompted me with was to perform an upgrade to its firmware. I have a switch too but I will take notes before saying yes to upgrade it, just incase I need to quote versions.

What I am trying to do is develop a sketch for Arduino / ESP8266 to behave based on the UPnP protocols and WEMO like features but this would allow folks to take a SONOFF Switch for instance and easily integrate it directly if desired (I currently run mine using a local MQTT server), its nice to have options

Oh, on one occasion I tried to re-discover a device and it did not work until I re-started OH2, not sure if that was related but worth a shot if you can

I figured it out, I recently installed ufw on the device as I have home assistant on a seperate server, seems like the firewall was causing it as soon, as I shut it off. Bam found all of them again, for now I need to create firewall rule, but not sure what ports got to figure that out.