Eco Plugs

bigeazy000 · January 31, 2016, 8:07pm

Here are 4 screenshots of pcaps I took. The src is my homebridge server, and the dst is the Wifi outlet. So, these are captures of it working…

cybrmage · January 31, 2016, 11:22pm

And the packets created by the implementation file are close…

The name of the switch, and one byte of the fixed data were wrong…

This should fix it…

** REMOVED NON-FUNCTIONAL VERSION **

bigeazy000 · February 1, 2016, 12:00am

Sweet, good progress now The switch now works to turn on the outlet! However, when I turn it to ‘on’, it doesn’t change the switch status to ‘on’. Also, clicking ‘off’ in the switch does not turn the switch off. I just ran a new packet capture from my homebridge server, and the attached packet capture screenshot specifically shows me turning the switch off. Also, here are what the logs show when I try to turn it off:

8 01/31/16 16:58:29.218 JobHandler_LuaUPnP::HandleActionRequest device: 116 service: urn:upnp-org:serviceId:SwitchPower1 action: SetTarget <0x2f331680>
08 01/31/16 16:58:29.219 JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=116 <0x2f331680>
08 01/31/16 16:58:29.219 JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:upnp-org:serviceId:SwitchPower1 <0x2f331680>
08 01/31/16 16:58:29.220 JobHandler_LuaUPnP::HandleActionRequest argument action=SetTarget <0x2f331680>
08 01/31/16 16:58:29.220 JobHandler_LuaUPnP::HandleActionRequest argument newTargetValue=0 <0x2f331680>
08 01/31/16 16:58:29.221 JobHandler_LuaUPnP::HandleActionRequest argument rand=0.25710172834806144 <0x2f331680>
50 01/31/16 16:58:29.223 luup_log:116: (I_ECO_Switch::ACTION::SetTarget) Setting switch state to [0] <0x2ad9f000>
06 01/31/16 16:58:29.223 Device_Variable::m_szValue_set device: 116 service: urn:upnp-org:serviceId:SwitchPower1 variable: Target was: 0 now: 0 #hooks: 0 upnp: 0 skip: 0 v:0xd2a460/NONE duplicate:1 <0x2ad9f000>
50 01/31/16 16:58:29.224 luup_log:116: (I_ECO_Switch::EcoSwitch::setStatus) Called setStatus(172.16.0.243,“ECO-7800A1A6”,true). <0x2ad9f000>
50 01/31/16 16:58:29.224 luup_log:116: (I_ECO_Switch::EcoSwitch::createMessage) Called createMessage(set,“ECO-7800A1A6”,true). <0x2ad9f000>
50 01/31/16 16:58:29.239 luup_log:116: (I_ECO_Switch::EcoSwitch::createMessage) Created command data - time [1454284709] [
00000000 16 00 05 00 00 00 17 04 02 00 00 00 00 00 00 00 …
00000010 45 43 4F 2D 37 38 30 30 41 31 41 36 00 00 00 00 ECO-7800A1A6…
00000020 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000030 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000040 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000050 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000060 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000070 00 00 00 00 56 AE 9F A5 00 00 00 00 CD B8 42 2A …V???..͸B*
00000080 01 01 …
] <0x2ad9f000>
50 01/31/16 16:58:29.239 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) Called sendMessage(172.16.0.243,“ECO-7800A1A6”, <0x2ad9f000>
50 01/31/16 16:58:29.240 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) Sending command… <0x2ad9f000>
50 01/31/16 16:58:29.251 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) received response [NIL] <0x2ad9f000>
01 01/31/16 16:58:29.252 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) Send command failed. <0x2ad9f000>
01 01/31/16 16:58:29.253 luup_log:116: (I_ECO_Switch::EcoSwitch::setStatus) ERROR setting State of switch with ID ECO-7800A1A6. <0x2ad9f000>
06 01/31/16 16:58:29.253 Device_Variable::m_szValue_set device: 116 service: urn:upnp-org:serviceId:SwitchPower1 variable: Status was: 0 now: 0 #hooks: 1 upnp: 0 skip: 0 v:0xd2a4d8/NONE duplicate:1root@MiOS_35019890:/tmp/log/cmh#

Thanks for sticking with this, I think it’s almost done!!

cybrmage · February 1, 2016, 12:34am

And here is an update…

Please post the log showing a response from the switch, so I can verify that the data is being parsed correctly…

** ATTACHMENT REMOVED **

bigeazy000 · February 1, 2016, 1:03am

BAM!!

Now the switch turns on and off, the only thing its not doing is changing the status in the switch do display whether it is on or off. Here is what I see in the log when I turn it on:
08 01/31/16 17:57:47.189 JobHandler_LuaUPnP::HandleActionRequest device: 116 service: urn:upnp-org:serviceId:SwitchPower1 action: SetTarget <0x3106c680>
08 01/31/16 17:57:47.190 JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=116 <0x3106c680>
08 01/31/16 17:57:47.190 JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:upnp-org:serviceId:SwitchPower1 <0x3106c680>
08 01/31/16 17:57:47.191 JobHandler_LuaUPnP::HandleActionRequest argument action=SetTarget <0x3106c680>
08 01/31/16 17:57:47.191 JobHandler_LuaUPnP::HandleActionRequest argument newTargetValue=1 <0x3106c680>
08 01/31/16 17:57:47.192 JobHandler_LuaUPnP::HandleActionRequest argument rand=0.9758968667592853 <0x3106c680>
50 01/31/16 17:57:47.194 luup_log:116: (I_ECO_Switch::ACTION::SetTarget) Setting switch state to [ON] <0x2b054000>
06 01/31/16 17:57:47.195 Device_Variable::m_szValue_set device: 116 service: urn:upnp-org:serviceId:SwitchPower1 variable: Target was: 0 now: 1 #hooks: 0 upnp: 0 skip: 0 v:0xf89460/NONE duplicate:0 <0x2b054000>
50 01/31/16 17:57:47.196 luup_log:116: (I_ECO_Switch::EcoSwitch::setStatus) Called setStatus(172.16.0.243,“ECO-7800A1A6”,true). <0x2b054000>
50 01/31/16 17:57:47.196 luup_log:116: (I_ECO_Switch::EcoSwitch::createMessage) Called createMessage(set,“ECO-7800A1A6”,true). <0x2b054000>
50 01/31/16 17:57:47.241 luup_log:116: (I_ECO_Switch::EcoSwitch::createMessage) Created command data - time [1454288267] [
00000000 16 00 05 00 00 00 BF 16 02 00 00 00 00 00 00 00 …?..
00000010 45 43 4F 2D 37 38 30 30 41 31 41 36 00 00 00 00 ECO-7800A1A6…
00000020 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000030 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000040 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000050 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000060 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000070 00 00 00 00 56 AE AD 8B 00 00 00 00 CD B8 42 2A …V???..͸B*
00000080 01 01 …
] <0x2b054000>
50 01/31/16 17:57:47.242 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) Called sendMessage(172.16.0.243,“ECO-7800A1A6”, <0x2b054000>
50 01/31/16 17:57:47.242 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) Sending command… <0x2b054000>
50 01/31/16 17:57:47.326 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) received response [NIL] <0x2b054000>
01 01/31/16 17:57:47.327 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) Send command failed. <0x2b054000>
01 01/31/16 17:57:47.327 luup_log:116: (I_ECO_Switch::EcoSwitch::setStatus) ERROR setting State of switch with ID ECO-7800A1A6. <0x2b054000>
50 01/31/16 17:57:47.328 luup_log:116: (I_ECO_Switch::ACTION::GetStatus) Switch state not set for switch [ECO-7800A1A6] <0x2b054000>
04 01/31/16 17:57:47.329 <0x2b054000>

Here is what I see in the log when I turn it off:

08 01/31/16 18:00:01.266 JobHandler_LuaUPnP::HandleActionRequest device: 116 service: urn:upnp-org:serviceId:SwitchPower1 action: SetTarget <0x30a30680>
08 01/31/16 18:00:01.266 JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=116 <0x30a30680>
08 01/31/16 18:00:01.267 JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:upnp-org:serviceId:SwitchPower1 <0x30a30680>
08 01/31/16 18:00:01.267 JobHandler_LuaUPnP::HandleActionRequest argument action=SetTarget <0x30a30680>
08 01/31/16 18:00:01.268 JobHandler_LuaUPnP::HandleActionRequest argument newTargetValue=0 <0x30a30680>
08 01/31/16 18:00:01.268 JobHandler_LuaUPnP::HandleActionRequest argument rand=0.3850131968501955 <0x30a30680>
50 01/31/16 18:00:01.270 luup_log:116: (I_ECO_Switch::ACTION::SetTarget) Setting switch state to [OFF] <0x2b054000>
06 01/31/16 18:00:01.271 Device_Variable::m_szValue_set device: 116 service: urn:upnp-org:serviceId:SwitchPower1 variable: Target was: 1 now: 0 #hooks: 0 upnp: 0 skip: 0 v:0xf89460/NONE duplicate:0 <0x2b054000>
50 01/31/16 18:00:01.272 luup_log:116: (I_ECO_Switch::EcoSwitch::setStatus) Called setStatus(172.16.0.243,“ECO-7800A1A6”,false). <0x2b054000>
50 01/31/16 18:00:01.273 luup_log:116: (I_ECO_Switch::EcoSwitch::createMessage) Called createMessage(set,“ECO-7800A1A6”,false). <0x2b054000>
50 01/31/16 18:00:01.328 luup_log:116: (I_ECO_Switch::EcoSwitch::createMessage) Created command data - time [1454288401] [
00000000 16 00 05 00 00 00 65 D8 02 00 00 00 00 00 00 00 …e?..
00000010 45 43 4F 2D 37 38 30 30 41 31 41 36 00 00 00 00 ECO-7800A1A6…
00000020 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000030 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000040 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000050 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000060 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000070 00 00 00 00 56 AE AE 11 00 00 00 00 CD B8 42 2A …V??..͸B*
00000080 01 00 …
] <0x2b054000>
50 01/31/16 18:00:01.328 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) Called sendMessage(172.16.0.243,“ECO-7800A1A6”, <0x2b054000>
50 01/31/16 18:00:01.329 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) Sending command… <0x2b054000>
50 01/31/16 18:00:01.396 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) received response [NIL] <0x2b054000>
01 01/31/16 18:00:01.396 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) Send command failed. <0x2b054000>
01 01/31/16 18:00:01.397 luup_log:116: (I_ECO_Switch::EcoSwitch::setStatus) ERROR setting State of switch with ID ECO-7800A1A6. <0x2b054000>
50 01/31/16 18:00:01.398 luup_log:116: (I_ECO_Switch::ACTION::GetStatus) Switch state not set for switch [ECO-7800A1A6] <0x2b054000>
04 01/31/16 18:00:01.399 <0x2b054000>
04 01/31/16 18:00:05.249 <0x2b7a4680>
06 01/31/16 18:00:05.249 Device_Variable::m_szValue_set device: 60 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: LastPollSuccess was: 1454288075 now: 1454288405 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0root@MiOS_35019890:/tmp/log/cmh#

cybrmage · February 1, 2016, 4:41am

Well… That’s half the battle…

Obviously, we don’t get a response to the on/off command…

I need to know if it is because the switch doesn’t send a response to the command and must be polled, or if it’s not waiting long enough for the response…

During startup, a getStatus command is sent to the switch, which should definitely get a response back… Can you post the log showing the device startup during a LuaUPnP reload…

cybrmage · February 1, 2016, 4:49am

Actually… I found a bug that may have been causing the problem…

Try this…

** ATTACHMENT REMOVED **

bigeazy000 · February 1, 2016, 3:31pm

With the latest file installed, the switch now shows ‘on’ and I cannot make it change to ‘off’ although it does still turn the lights off. I’ll get you the requested logs in a few, thanks!

bigeazy000 · February 1, 2016, 4:04pm

Also, FWIW, I think it may be a poll. If I ask Siri (homebridge integration) “are the Kitchen LEDs on?” I get a response from Siri that says “the Kitchen LEDs are on” it looks like the homebridge server sends a packet (pcap1) to the wifi outlet and then I have 2 response packets (pacap2 and pcap3). The sequence numbers in the captures line up with this theory too… Captures attached.

bigeazy000 · February 1, 2016, 4:20pm

Also, here is the startup logs from Vera. Kitchen-Upper-LEDs is the what I named the device in the ECO Plug app when I provisioned the outlet.

50 02/01/16 9:19:18.881 luup_log:116: (I_ECO_Switch::Init) Starting… <0x2bc46680>
50 02/01/16 9:19:18.882 luup_log:116: (I_ECO_Switch::getIP) raw ip address [172.16.0.243:80]. <0x2bc46680>
50 02/01/16 9:19:18.882 luup_log:116: (I_ECO_Switch::Init) Switch ID [ECO-7800A1A6]. <0x2bc46680>
50 02/01/16 9:19:18.883 luup_log:116: (I_ECO_Switch::EcoSwitch::getStatus) Called getStatus(172.16.0.243,“ECO-7800A1A6”). <0x2bc46680>
50 02/01/16 9:19:18.884 luup_log:116: (I_ECO_Switch::EcoSwitch::createMessage) Called createMessage(get,“ECO-7800A1A6”,false). <0x2bc46680>
50 02/01/16 9:19:18.908 luup_log:116: (I_ECO_Switch::EcoSwitch::createMessage) Created command data - time [1454343558] [
00000000 17 00 05 00 00 00 17 84 00 00 00 00 00 00 00 00 …?..
00000010 45 43 4F 2D 37 38 30 30 41 31 41 36 00 00 00 00 ECO-7800A1A6…
00000020 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000030 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000040 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000050 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000060 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000070 00 00 00 00 56 AF 85 86 00 00 00 00 CD B8 42 2A …V???..͸B*
] <0x2bc46680>
50 02/01/16 9:19:18.909 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) Called sendMessage(172.16.0.243,“ECO-7800A1A6”, <0x2bc46680>
50 02/01/16 9:19:18.930 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) Sending command… <0x2bc46680>
50 02/01/16 9:19:18.968 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) received response [
00000000 17 00 05 00 00 00 17 84 02 00 31 2E 36 2E 30 00 …?..1.6.0.
00000010 45 43 4F 2D 37 38 30 30 41 31 41 36 00 00 00 00 ECO-7800A1A6…
00000020 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000030 6B 69 74 63 68 65 6E 2D 55 70 70 65 72 2D 4C 45 kitchen-Upper-LE
00000040 44 73 00 00 00 00 00 00 00 00 00 00 00 00 00 00 Ds…
00000050 37 38 30 30 41 31 41 36 00 00 00 00 00 00 00 00 7800A1A6…
00000060 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000070 53 0A 02 7E 56 AF 85 86 00 00 00 00 CD B8 42 2A S…~V???..͸B*
00000080 01 01 …
] <0x2bc46680>
01 02/01/16 9:19:18.969 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) Sent command. <0x2bc46680>
50 02/01/16 9:19:18.969 luup_log:116: (I_ECO_Switch::EcoSwitch::getStatus) Status of switch with ID ECO-7800A1A6 is: [ON] <0x2bc46680>
06 02/01/16 9:19:18.970 Device_Variable::m_szValue_set device: 116 service: urn:upnp-org:serviceId:SwitchPower1 variable: Status was: 1 now: 1 #hooks: 1 upnp: 0 skip: 0 v:0xb983c8/NONE duplicate:1 <0x2bc46680>
50 02/01/16 9:19:18.971 luup_log:116: (I_ECO_Switch::Init) Started. <0x2bc46680>

cybrmage · February 1, 2016, 5:19pm

The first issue… not showing the correct status when turning the light off…

I need the logs showing the setTarget command for turning the light off…

The second issue… not showing correct status when the state is changed by an external source (Homekit or native APP)… That is a polling issue… The implementation does not do any polling yet… That can be added AFTER everything else works…

bigeazy000 · February 1, 2016, 5:54pm

Attached are 3 pcaps from homebridge server. First one (pcap1off) shows server sending the command to turn the lights off. The second two pcaps (pcap2off and pcap3off) show the 2 response packets sent from the wifi outlet to the server. Also, here is what I see in Vera logs when I turn the switch off from Vera:

50 02/01/16 10:45:46.642 luup_log:116: (I_ECO_Switch::ACTION::SetTarget) Setting switch state to [OFF] <0x2b4a1000>
06 02/01/16 10:45:46.642 Device_Variable::m_szValue_set device: 116 service: urn:upnp-org:serviceId:SwitchPower1 variable: Target was: 0 now: 0 #hooks: 0 upnp: 0 skip: 0 v:0x9e8350/NONE duplicate:1 <0x2b4a1000>
50 02/01/16 10:45:46.643 luup_log:116: (I_ECO_Switch::EcoSwitch::setStatus) Called setStatus(172.16.0.243,“ECO-7800A1A6”,false). <0x2b4a1000>
50 02/01/16 10:45:46.643 luup_log:116: (I_ECO_Switch::EcoSwitch::createMessage) Called createMessage(set,“ECO-7800A1A6”,false). <0x2b4a1000>
50 02/01/16 10:45:46.659 luup_log:116: (I_ECO_Switch::EcoSwitch::createMessage) Created command data - time [1454348746] [
00000000 16 00 05 00 00 00 9C B2 02 00 00 00 00 00 00 00 …??..
00000010 45 43 4F 2D 37 38 30 30 41 31 41 36 00 00 00 00 ECO-7800A1A6…
00000020 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000030 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000040 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000050 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000060 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000070 00 00 00 00 56 AF 99 CA 00 00 00 00 CD B8 42 2A …V???..͸B*
00000080 01 00 …
] <0x2b4a1000>

cybrmage · February 1, 2016, 10:07pm

There are 2 issues with these:

The pcap data window (the one at the bottom) is too small, so the entire contents of the response packet is not shown…
You did not provide enough of the LuaUPnP log to tell what the implementation file is doing… You truncated the log at the command packet was built… It does not show the packet being sent, or a response being received nor how the response is processed…

Please repost the LuaUPnP log from the ‘Setting switch state’ line through to the ‘<Job ID=“X” Name=“” Device=“116”’ line.

bigeazy000 · February 1, 2016, 10:45pm

I guess poorly cropped screenshots is the bane of my existence Sorry about that, attached are the full captures (same order) and the logs you requested:

08 02/01/16 15:40:31.658 JobHandler_LuaUPnP::HandleActionRequest device: 116 service: urn:upnp-org:serviceId:SwitchPower1 action: SetTarget <0x313ea680>
08 02/01/16 15:40:31.659 JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=116 <0x313ea680>
08 02/01/16 15:40:31.659 JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:upnp-org:serviceId:SwitchPower1 <0x313ea680>
08 02/01/16 15:40:31.660 JobHandler_LuaUPnP::HandleActionRequest argument action=SetTarget <0x313ea680>
08 02/01/16 15:40:31.660 JobHandler_LuaUPnP::HandleActionRequest argument newTargetValue=0 <0x313ea680>
08 02/01/16 15:40:31.661 JobHandler_LuaUPnP::HandleActionRequest argument rand=0.329764663008973 <0x313ea680>
50 02/01/16 15:40:31.664 luup_log:116: (I_ECO_Switch::ACTION::SetTarget) Setting switch state to [OFF] <0x2b60e000>
06 02/01/16 15:40:31.664 Device_Variable::m_szValue_set device: 116 service: urn:upnp-org:serviceId:SwitchPower1 variable: Target was: 0 now: 0 #hooks: 0 upnp: 0 skip: 0 v:0x103cad0/NONE dupli
50 02/01/16 15:40:31.666 luup_log:116: (I_ECO_Switch::EcoSwitch::setStatus) Called setStatus(172.16.0.243,“ECO-7800A1A6”,false). <0x2b60e000>
50 02/01/16 15:40:31.667 luup_log:116: (I_ECO_Switch::EcoSwitch::createMessage) Called createMessage(set,“ECO-7800A1A6”,false). <0x2b60e000>
50 02/01/16 15:40:31.679 luup_log:116: (I_ECO_Switch::EcoSwitch::createMessage) Created command data - time [1454366431] [
00000000 16 00 05 00 00 00 33 29 02 00 00 00 00 00 00 00 …3)…
00000010 45 43 4F 2D 37 38 30 30 41 31 41 36 00 00 00 00 ECO-7800A1A6…
00000020 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000030 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000040 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000050 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000060 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000070 00 00 00 00 56 AF DE DF 00 00 00 00 CD B8 42 2A …V???..͸B*
00000080 01 00 …
] <0x2b60e000>
50 02/01/16 15:40:31.680 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) Called sendMessage(172.16.0.243,“ECO-7800A1A6”, <0x2b60e000>
50 02/01/16 15:40:31.681 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) Sending command… <0x2b60e000>
50 02/01/16 15:40:31.699 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) received response [
00000000 16 00 05 00 00 00 33 29 00 00 31 2E 36 2E 30 00 …3)…1.6.0.
00000010 45 43 4F 2D 37 38 30 30 41 31 41 36 00 00 00 00 ECO-7800A1A6…
00000020 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000030 6B 69 74 63 68 65 6E 2D 55 70 70 65 72 2D 4C 45 kitchen-Upper-LE
00000040 44 73 00 00 00 00 00 00 00 00 00 00 00 00 00 00 Ds…
00000050 37 38 30 30 41 31 41 36 00 00 00 00 00 00 00 00 7800A1A6…
00000060 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000070 E8 0B 02 7E 56 AF DE DF 00 00 00 00 CD B8 42 2A ?..~V???..͸B*
] <0x2b60e000>
01 02/01/16 15:40:31.700 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) Sent command. <0x2b60e000>
50 02/01/16 15:40:31.700 luup_log:116: (I_ECO_Switch::EcoSwitch::setStatus) Setting state of switch with ID ECO-7800A1A6 to: [OFF] <0x2b60e000>
50 02/01/16 15:40:31.701 luup_log:116: (I_ECO_Switch::EcoSwitch::setStatus) State of switch with ID ECO-7800A1A6 set to: [ON] <0x2b60e000>
06 02/01/16 15:40:31.702 Device_Variable::m_szValue_set device: 116 service: urn:upnp-org:serviceId:SwitchPower1 variable: Status was: 1 now: 1 #hooks: 1 upnp: 0 skip: 0 v:0x103cb48/NONE dupli
50 02/01/16 15:40:31.702 luup_log:116: (I_ECO_Switch::ACTION::SetTarget) Switch state to ON] <0x2b60e000>
04 02/01/16 15:40:31.703 <Job ID=“9” Name=“” Device=“116” Created=“2016-02-01 15:40:31” Started=“2016-02-01 15:40:31” Completed=“2016-02-01 15:40:31” Duration=“0.41386000” Runtime=“0.39588000”

bigeazy000 · February 1, 2016, 10:46pm

And here is the final pcap…

cybrmage · February 2, 2016, 1:32am

Touch?!

Much better 8-}

Looks like the response from a command is just an acknowledgement that the command was received… it does not include status information…

Implementation file updated to account for that…

** ATTACHMENT REMOVED **

bigeazy000 · February 2, 2016, 3:30am

Thanks for the update. In the UI everything is the same, switch always displays as ‘on’ even if I turn it off. When I do turn it off, there is a lot more activity in the logs now:

08 02/01/16 20:27:30.446 JobHandler_LuaUPnP::HandleActionRequest device: 116 service: urn:upnp-org:serviceId:SwitchPower1 action: SetTarget <0x30c8b680>
08 02/01/16 20:27:30.446 JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=116 <0x30c8b680>
08 02/01/16 20:27:30.447 JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:upnp-org:serviceId:SwitchPower1 <0x30c8b680>
08 02/01/16 20:27:30.447 JobHandler_LuaUPnP::HandleActionRequest argument action=SetTarget <0x30c8b680>
08 02/01/16 20:27:30.448 JobHandler_LuaUPnP::HandleActionRequest argument newTargetValue=0 <0x30c8b680>
08 02/01/16 20:27:30.448 JobHandler_LuaUPnP::HandleActionRequest argument rand=0.7630785729270428 <0x30c8b680>
50 02/01/16 20:27:30.452 luup_log:116: (I_ECO_Switch::ACTION::SetTarget) Setting switch state to [OFF] <0x2adf1000>
06 02/01/16 20:27:30.452 Device_Variable::m_szValue_set device: 116 service: urn:upnp-org:serviceId:SwitchPower1 variable: Target was: 0 now: 0 #hooks: 0 upnp: 0 skip: 0 v:0xe75a28/NONE duplicate:1 <0x2adf1000>
50 02/01/16 20:27:30.453 luup_log:116: (I_ECO_Switch::EcoSwitch::setStatus) Called setStatus(172.16.0.243,“ECO-7800A1A6”,false). <0x2adf1000>
50 02/01/16 20:27:30.453 luup_log:116: (I_ECO_Switch::EcoSwitch::createMessage) Called createMessage(set,“ECO-7800A1A6”,false). <0x2adf1000>
50 02/01/16 20:27:30.468 luup_log:116: (I_ECO_Switch::EcoSwitch::createMessage) Created command data - time [1454383650] [
00000000 16 00 05 00 00 00 9F 23 02 00 00 00 00 00 00 00 …?#…
00000010 45 43 4F 2D 37 38 30 30 41 31 41 36 00 00 00 00 ECO-7800A1A6…
00000020 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000030 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000040 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000050 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000060 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000070 00 00 00 00 56 B0 22 22 00 00 00 00 CD B8 42 2A …V?“”…͸B*
00000080 01 00 …
] <0x2adf1000>
50 02/01/16 20:27:30.468 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) Called sendMessage(172.16.0.243,“ECO-7800A1A6”, <0x2adf1000>
50 02/01/16 20:27:30.469 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) Sending command… <0x2adf1000>
50 02/01/16 20:27:30.495 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) received response [
00000000 16 00 05 00 00 00 9F 23 00 00 31 2E 36 2E 30 00 …?#…1.6.0.
00000010 45 43 4F 2D 37 38 30 30 41 31 41 36 00 00 00 00 ECO-7800A1A6…
00000020 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000030 6B 69 74 63 68 65 6E 2D 55 70 70 65 72 2D 4C 45 kitchen-Upper-LE
00000040 44 73 00 00 00 00 00 00 00 00 00 00 00 00 00 00 Ds…
00000050 37 38 30 30 41 31 41 36 00 00 00 00 00 00 00 00 7800A1A6…
00000060 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000070 1B 0D 02 7E 56 B0 22 22 00 00 00 00 CD B8 42 2A …~V?“”…͸B*
] <0x2adf1000>
01 02/01/16 20:27:30.496 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) Sent command. <0x2adf1000>
50 02/01/16 20:27:30.496 luup_log:116: (I_ECO_Switch::EcoSwitch::getStatus) Called getStatus(172.16.0.243,“ECO-7800A1A6”). <0x2adf1000>
50 02/01/16 20:27:30.497 luup_log:116: (I_ECO_Switch::EcoSwitch::createMessage) Called createMessage(get,“ECO-7800A1A6”,false). <0x2adf1000>
50 02/01/16 20:27:30.507 luup_log:116: (I_ECO_Switch::EcoSwitch::createMessage) Created command data - time [1454383650] [
00000000 17 00 05 00 00 00 79 8E 00 00 00 00 00 00 00 00 …y?..
00000010 45 43 4F 2D 37 38 30 30 41 31 41 36 00 00 00 00 ECO-7800A1A6…
00000020 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000030 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000040 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000050 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000060 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000070 00 00 00 00 56 B0 22 22 00 00 00 00 CD B8 42 2A …V?“”…͸B*
] <0x2adf1000>
50 02/01/16 20:27:30.508 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) Called sendMessage(172.16.0.243,“ECO-7800A1A6”, <0x2adf1000>
50 02/01/16 20:27:30.508 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) Sending command… <0x2adf1000>
50 02/01/16 20:27:30.532 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) received response [
00000000 17 00 05 00 00 00 79 8E 02 00 31 2E 36 2E 30 00 …y?..1.6.0.
00000010 45 43 4F 2D 37 38 30 30 41 31 41 36 00 00 00 00 ECO-7800A1A6…
00000020 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000030 6B 69 74 63 68 65 6E 2D 55 70 70 65 72 2D 4C 45 kitchen-Upper-LE
00000040 44 73 00 00 00 00 00 00 00 00 00 00 00 00 00 00 Ds…
00000050 37 38 30 30 41 31 41 36 00 00 00 00 00 00 00 00 7800A1A6…
00000060 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 …
00000070 1B 0D 02 7E 56 B0 22 22 00 00 00 00 CD B8 42 2A …~V?“”…͸B*
00000080 01 00 …
] <0x2adf1000>
01 02/01/16 20:27:30.533 luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) Sent command. <0x2adf1000>
50 02/01/16 20:27:30.534 luup_log:116: (I_ECO_Switch::EcoSwitch::getStatus) Status of switch with ID ECO-7800A1A6 is: [ON] <0x2adf1000>
50 02/01/16 20:27:30.534 luup_log:116: (I_ECO_Switch::EcoSwitch::setStatus) State of switch with ID ECO-7800A1A6 set to: [ON] <0x2adf1000>
06 02/01/16 20:27:30.535 Device_Variable::m_szValue_set device: 116 service: urn:upnp-org:serviceId:SwitchPower1 variable: Status was: 1 now: 1 #hooks: 1 upnp: 0 skip: 0 v:0xe75aa0/NONE duplicate:1 <0x2adf1000>
50 02/01/16 20:27:30.536 luup_log:116: (I_ECO_Switch::ACTION::SetTarget) Switch state to ON] <0x2adf1000>
04 02/01/16 20:27:30.545 <0x2adf1000>

cybrmage · February 2, 2016, 5:02am

This one should do it…

** ATTACHMENT REMOVED **

bigeazy000 · February 3, 2016, 1:49am

Now it works!! The switch turns on and off, and the display is updated accordingly. The response is a little sluggish but I’m guessing that’s just the nature of how the switch works. I guess the only thing left would be polling, any ideas on how to do that?

Thanks SO much for helping me out with this! I know it was a lot of back and forth, I really appreciate your help. I’m very knowledgeable on the network side of things, but still pretty useless when it comes to writing code. After this adventure I’m going to try and spend some time trying to figure out how to do this myself next time…

bigeazy000 · February 3, 2016, 2:56am

ok, there is a new problem. It appears that for some reason the new code is opening a ton of sessions to the plug, I wonder if there is some sort of loop. Since installing the code an hour or so ago, the vera is now borderline unresponsive and I see a TON of sessions open in my data path table of my wireless controller. Literally hundreds of active sessions. Any ideas?