search

eclipse-archived / smarthome

Eclipse SmartHome™ project
https://www.eclipse.org/smarthome/
Eclipse Public License 2.0
866 stars 782 forks source link

Wemo handlers depend on UPnP discovery #4662

Open sjsf opened 6 years ago

sjsf commented 6 years ago

The Wemo binding uses the UPnP discovery (by implementing the DiscoveryListener interface in its handlers) in order to set things to ONLINE/OFFLINE. If I'm not mistaken then the real communication for updates and commands is done via HTTP and not via UPnP broadcast.

Therefore its a pity that the devices have to be found by UPnP, because that needlessly limits the use-cases to being within the same network segment. That e.g. prevents any docker based installations like openhab/openhab and others from being able to use this binding.

Discovery should be an optional thing. Normal operations should be completely independent of it. Or did I miss anything?

hmerk commented 6 years ago

@sjka This is not completely correct. The binding uses UPnP GENA events to receive updates from the devices, state polling is implemented only as a backup. Therefore I would not consider it as a bug

hmerk commented 6 years ago

Any further comments @sjka ?

derckie commented 6 years ago

@hmerk I have a strange behaviour that after switching of an insight device from the paper UI I receive back a status update which is than not refelcting the actual status of the device. I suppose this is coming from a GENA event. Than after a maximum of 2 minutes (the polling cycle) the device is again reflected correctly in paper UI. Is this a problem linked to how WEMO is handling events ?

hmerk commented 6 years ago

@derckie I have never seen this issue. Please set log level to debug for WeMo binding and post the GENA event informatio, the polling result and your expected values

johnjason888 commented 6 years ago

Cab u help me how to spam all email no information how to recovery account no information

derckie commented 6 years ago

@hmerk I have put on some debug logging. As you can see in the logging I am switching ON the switch from paper UI. The switch goes physically ON. Than afterwards I receive an event from WEMO and the status of the item goes back to OFF although the switch is physically ON. Then afterwards I receive a new event which put the item to ON. In this case it went fast but in reality it can take up to 2 minutes before the correct is reflected in the paper UI. As I am reacting on this item changes in rules this is a bit difficult to handle.

2017-12-15 09:32:27.924 [ItemCommandEvent ] - Item 'Mobiel_Switch' received command ON

2017-12-15 09:32:27.943 [ItemStateChangedEvent ] - Mobiel_Switch changed from OFF to ON

2017-12-15 09:32:28.028 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Received pair 'InsightParams':'8|1513325961|72|338|17103|1209600|384|3615|5479724|108646519|8000' (service 'insight1') for thing 'wemo:insight:Insight-1_0-22155xxxxxxxx'

2017-12-15 09:32:30.266 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Received pair 'EnergyPerUnitCost':'3|72|4' (service 'basicevent1') for thing 'wemo:insight:Insight-1_0-22155xxxxxxxx

2017-12-15 09:32:30.279 [ItemStateChangedEvent ] - Mobiel_Switch changed from ON to OFF

2017-12-15 09:32:30.317 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Received pair 'BinaryState':'8|1513326749|6|6480|565873|1209600|15|8700|1627017|127591295' (service 'basicevent1') for thing 'wemo:insight:Insight-1_0-22155xxxxxxx'

2017-12-15 09:32:30.541 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Received pair 'InsightParams':'8|1513325961|72|338|17103|1209600|384|3665|5479724|108646519|8000' (service 'insight1') for thing 'wemo:insight:Insight-1_0-22155xxxxxxx'

2017-12-15 09:32:30.784 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Received pair 'InsightParams':'8|1513326749|6|6480|565873|1209600|15|8700|1627017|127591295|8000' (service 'insight1') for thing 'wemo:insight:Insight-1_0-22155xxxxxxx'

2017-12-15 09:32:30.793 [ItemStateChangedEvent ] - Mobiel_Switch changed from OFF to ON

hmerk commented 6 years ago

Nothing suspicious in your logs. Please change loglevel to TRACE and test again.

derckie commented 6 years ago

There was a big amount of logging here. I filtered it to make it easier. First the command and state changes from the openhab items. Than the logging from the WEMO device in trace level. As you can see the command OFF was send to WEMO but afterwards telegrams are coming in with the ON state. It is only after one minute that the OFF status is reflected in the status telegrams.

Openhab items log 09:56:48.374 [INFO ] [smarthome.event.ItemCommandEvent ] - Item 'Mobiel_Switch' received command OFF 09:56:48.405 [INFO ] [marthome.event.ItemStateChangedEvent] - Mobiel_Switch changed from ON to OFF 09:56:49.563 [INFO ] [marthome.event.ItemStateChangedEvent] - Mobiel_Switch changed from OFF to ON 09:57:41.193 [INFO ] [marthome.event.ItemStateChangedEvent] - Mobiel_Switch changed from ON to OFF

WEMO binding trace log

09:56:48.384 [TRACE] [ome.binding.wemo.handler.WemoHandler] - Command 'OFF' received for channel 'wemo:insight:Insight-1_0-22155xxxxxxx:state' 09:56:49.541 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Received pair 'EnergyPerUnitCost':'3|72|4' (service 'basicevent1') for thing 'wemo:insight:Insight-1_0-22155xxxxxxx' 09:56:49.544 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New InsightParam binaryState 'ON' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received 09:56:49.552 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New InsightParam lastChangedAt '2017-12-15T09:47:32.000+0100' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received 09:56:49.559 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New InsightParam lastOnFor '554' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received 09:56:49.563 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New InsightParam onToday '7034' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received 09:56:49.568 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New InsightParam onTotal '566416' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received 09:56:49.572 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New InsightParam timespan '1209600' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received 09:56:49.577 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New InsightParam averagePower '15' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received 09:56:49.584 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New InsightParam currentPower '14' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received 09:56:49.590 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New InsightParam energyToday '29' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received 09:56:49.596 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New InsightParam energyTotal '2129' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received 09:56:49.602 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New InsightParam standByLimit '8' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received 09:56:49.607 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Received pair 'BinaryState':'0|1513328208|555|7035|566417|1209600|15|0|1760365|127724643' (service 'basicevent1') for thing 'wemo:insight:Insight-1_0-22155xxxxxxx' 09:56:49.610 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New InsightParam binaryState 'ON' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received 09:56:49.617 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New InsightParam lastChangedAt '2017-12-15T09:47:32.000+0100' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received 09:56:49.622 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New InsightParam lastOnFor '554' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received 09:56:49.627 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New InsightParam onToday '7034' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received 09:56:49.632 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New InsightParam onTotal '566416' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received 09:56:49.637 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New InsightParam timespan '1209600' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received 09:56:49.642 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New InsightParam averagePower '15' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received 09:56:49.648 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New InsightParam currentPower '14' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received 09:56:49.653 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New InsightParam energyToday '29' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received 09:56:49.656 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New InsightParam energyTotal '2129' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received 09:56:49.661 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New InsightParam standByLimit '8' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received </s:Body> </s:Envelope>' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received 09:57:41.175 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New state '0|1513328208|555|7035|566417|1209600|15|0|1760365|127724643.000000|8000' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received 09:57:41.176 [DEBUG] [ome.binding.wemo.handler.WemoHandler] - Received pair 'InsightParams':'0|1513328208|555|7035|566417|1209600|15|0|1760365|127724643.000000|8000' (service 'insight1') for thing 'wemo:insight:Insight-1_0-22155xxxxxxx' 09:57:41.179 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New InsightParam binaryState 'OFF' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received 09:57:41.188 [TRACE] [ome.binding.wemo.handler.WemoHandler] - New InsightParam lastChangedAt '2017-12-15T09:56:48.000+0100' for device 'wemo:insight:Insight-1_0-22155xxxxxxx' received

derckie commented 6 years ago

@hmerk I did some further investigating and I was wondering if it could be linked to interference between Sonos and Wemo binding. I restarted everything and the problems with Wemo seemed solved. Although I got some problems with sonos at that time. Restarted everything with Sonos binding inactive and Wemo binding worked fine. After activating Sonos binding again I got new delays on the Wemo binding.

hmerk commented 6 years ago

@sjka I think this issue can be closed.

sjsf commented 6 years ago

Maybe I should have been more precise - what I consider a bug is that WemoHandler implements the DiscoveryListener interface. Using UPnP in general (i.e. being a UpnpIOParticipant) is perfectly fine of course, no issues with that.

hmerk commented 6 years ago

Ok, now I understood. I am doing a major rework of the binding atm and will take this into count.

sjsf commented 6 years ago

Cool, thanks.

kaikreuzer commented 6 years ago

@hmerk Any news on that "major rework"?

hmerk commented 6 years ago

@kaikreuzer unfortunately no. As you know, my priorities are changing. Had some issues renovating the house and even some issues at day work. Don‘t really know when to have the PR ready, since the little one was born last Wednesday. So no more late coding sessions during night time for the moment. Hope to find some time during my fist paternity leave in June.