Author Topic: Eco Plugs  (Read 10445 times)

Offline bigeazy000

  • Jr. Member
  • **
  • Posts: 53
  • Karma: +1/-0
Re: Eco Plugs
« Reply #15 on: January 30, 2016, 05:39:45 pm »
Still Broken  :(

Latest Logs:

untitled text 6:22144: 50   01/30/16 15:37:07.358   luup_log:116: SengLED: Port not specified, 80 assumed. <0x2c314680>
untitled text 6:22148: 01   01/30/16 15:37:07.369   LuaInterface::CallFunction_Startup-1 device 116 function init failed [string "..."]:94: bad argument #1 to 'sendto' (string expected, got nil) <0x2c314680>
untitled text 6:22149: 01   01/30/16 15:37:07.369   LuImplementation::StartLua running startup code for 116 I_ECO_Switch.xml failed <0x2c314680>

Offline cybrmage

  • Hero Member
  • *****
  • Posts: 1057
  • Karma: +105/-5
Re: Eco Plugs
« Reply #16 on: January 30, 2016, 09:06:27 pm »
Here is another try...

I've added some extra debug logging so we can get this resolved.



** REMOVED NON-FUNCTIONAL VERSION **
« Last Edit: January 31, 2016, 07:36:08 pm by cybrmage »
EVL3Vista - Wink Connect - Caseta Connect - Venstar Colortouch - WiFi UDP Switch Controller - Broadlink RM - MyQGateway

Offline bigeazy000

  • Jr. Member
  • **
  • Posts: 53
  • Karma: +1/-0
Re: Eco Plugs
« Reply #17 on: January 30, 2016, 10:03:40 pm »
Ok some progress. Looks like the code is compiling correctly now (no errors) but the switch still doesn't work. Looking at the log, it looks like it is sending the commands, here is what I am looking at:

08   01/30/16 20:00:47.533   JobHandler_LuaUPnP::HandleActionRequest device: 116 service: urn:upnp-org:serviceId:SwitchPower1 action: SetTarget <0x2f42b680>
08   01/30/16 20:00:47.533   JobHandler_LuaUPnP::HandleActionRequest argument newTargetValue=1 <0x2f42b680>
50   01/30/16 20:00:47.557   luup_log:116: (I_ECO_Switch::ACTION::SetTarget) Setting switch state to [1] <0x2ae9a000>
06   01/30/16 20:00:47.557   Device_Variable::m_szValue_set device: 116 service: urn:upnp-org:serviceId:SwitchPower1 variable: Target was: 1 now: 1 #hooks: 0 upnp: 0 skip: 0 v:0x10659f0/NONE duplicate:1 <0x2ae9a000>
50   01/30/16 20:00:47.559   luup_log:116: (I_ECO_Switch::Ecoswitch::sendMessage) Sending command to ip [172.16.0.243:80] <0x2ae9a000>
01   01/30/16 20:00:50.564   luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) Sent command. <0x2ae9a000>
01   01/30/16 20:00:50.565   luup_log:116: (I_ECO_Switch::EcoSwitch::setStatus) ERROR setting State of switch with ID 116. <0x2ae9a000>
06   01/30/16 20:00:50.565   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:0x1065a68/NONE duplicate:1 <0x2ae9a000>
50   01/30/16 20:00:50.566   luup_log:116: (I_ECO_Switch::ACTION::SetTarget) Switch state to 0] <0x2ae9a000>
04   01/30/16 20:00:50.567   <Job ID="8" Name="" Device="116" Created="2016-01-30 20:00:47" Started="2016-01-30 20:00:47" Completed="2016-01-30 20:00:50" Duration="3.32472000" Runtime="3.9763000" Status="Successful" LastNote=""/> <0x2ae9a000>
08   01/30/16 20:00:52.865   JobHandler_LuaUPnP::HandleActionRequest device: 116 service: urn:upnp-org:serviceId:SwitchPower1 action: SetTarget <0x3002b680>
08   01/30/16 20:00:52.866   JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=116 <0x3002b680>
08   01/30/16 20:00:52.866   JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:upnp-org:serviceId:SwitchPower1 <0x3002b680>
08   01/30/16 20:00:52.867   JobHandler_LuaUPnP::HandleActionRequest argument action=SetTarget <0x3002b680>
08   01/30/16 20:00:52.867   JobHandler_LuaUPnP::HandleActionRequest argument newTargetValue=1 <0x3002b680>
08   01/30/16 20:00:52.868   JobHandler_LuaUPnP::HandleActionRequest argument rand=0.9898078248370439 <0x3002b680>
50   01/30/16 20:00:52.871   luup_log:116: (I_ECO_Switch::ACTION::SetTarget) Setting switch state to [1] <0x2ae9a000>
06   01/30/16 20:00:52.871   Device_Variable::m_szValue_set device: 116 service: urn:upnp-org:serviceId:SwitchPower1 variable: Target was: 1 now: 1 #hooks: 0 upnp: 0 skip: 0 v:0x10659f0/NONE duplicate:1 <0x2ae9a000>
50   01/30/16 20:00:52.872   luup_log:116: (I_ECO_Switch::Ecoswitch::sendMessage) Sending command to ip [172.16.0.243:80] <0x2ae9a000>

Offline cybrmage

  • Hero Member
  • *****
  • Posts: 1057
  • Karma: +105/-5
Re: Eco Plugs
« Reply #18 on: January 31, 2016, 12:42:39 pm »
Here is another version... with even more debugging (so we can see what data is being sent and any response data received)...

Also, please verify that you have the correct IP address for your device...



** REMOVED NON-FUNCTIONAL VERSION **
« Last Edit: January 31, 2016, 07:35:23 pm by cybrmage »
EVL3Vista - Wink Connect - Caseta Connect - Venstar Colortouch - WiFi UDP Switch Controller - Broadlink RM - MyQGateway

Offline bigeazy000

  • Jr. Member
  • **
  • Posts: 53
  • Karma: +1/-0
Re: Eco Plugs
« Reply #19 on: January 31, 2016, 02:36:14 pm »
Very cool, thanks for adding the debug info. I triple checked the IP address. I confirmed in my arp table and the homebridge app is still working, with 172.16.0.243 as the IP hard coded in that homebridge config file. Here are the latest logs, and you're right, there is a lot more there, including packet capture. I think I still have the packet capture I took before, If I can find it, I will post it too. Logs:

08   01/31/16 12:31:48.885   JobHandler_LuaUPnP::HandleActionRequest device: 116 service: urn:upnp-org:serviceId:SwitchPower1 action: SetTarget <0x31387680>
08   01/31/16 12:31:48.886   JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=116 <0x31387680>
08   01/31/16 12:31:48.886   JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:upnp-org:serviceId:SwitchPower1 <0x31387680>
08   01/31/16 12:31:48.887   JobHandler_LuaUPnP::HandleActionRequest argument action=SetTarget <0x31387680>
08   01/31/16 12:31:48.887   JobHandler_LuaUPnP::HandleActionRequest argument newTargetValue=1 <0x31387680>
08   01/31/16 12:31:48.888   JobHandler_LuaUPnP::HandleActionRequest argument rand=0.8577514525968581 <0x31387680>
50   01/31/16 12:31:48.890   luup_log:116: (I_ECO_Switch::ACTION::SetTarget) Setting switch state to [1] <0x2b6ee000>
06   01/31/16 12:31:48.890   Device_Variable::m_szValue_set device: 116 service: urn:upnp-org:serviceId:SwitchPower1 variable: Target was: 1 now: 1 #hooks: 0 upnp: 0 skip: 0 v:0xc26ad0/NONE duplicate:1 <0x2b6ee000>
50   01/31/16 12:31:48.891   luup_log:116: (I_ECO_Switch::EcoSwitch::setStatus) Called setStatus(172.16.0.243,116,true). <0x2b6ee000>
50   01/31/16 12:31:48.891   luup_log:116: (I_ECO_Switch::EcoSwitch::createMessage) Called createMessage(set,116,true). <0x2b6ee000>
50   01/31/16 12:31:48.909   luup_log:116: (I_ECO_Switch::EcoSwitch::createMessage) Created command data - time [1454268708] [
00000000  16 00 05 00 00 00 DF 6F  02 00 00 00 00 00 00 00  ......?o........
00000010  31 31 36 20 20 20 20 20  20 20 20 20 20 20 20 20  116             
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 61 24  00 00 00 00 CB B8 42 2A  ....V?a$....˸B*
00000080  01 01                                             ..
] <0x2b6ee000>
50   01/31/16 12:31:48.910   luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage) Called sendMessage(172.16.0.243,116, <0x2b6ee000>
50   01/31/16 12:31:48.911   luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage)    Sending command... <0x2b6ee000>
01   01/31/16 12:31:49.027   IOPort::Connect connect -1 172.16.0.12:60128 <0x3027f680>
50   01/31/16 12:31:49.913   luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage)    Sending command... <0x2b6ee000>
50   01/31/16 12:31:50.915   luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage)    Sending command... <0x2b6ee000>
50   01/31/16 12:31:51.917   luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage)   received response [NIL] <0x2b6ee000>
01   01/31/16 12:31:51.918   luup_log:116: (I_ECO_Switch::EcoSwitch::sendMessage)   Send command failed. <0x2b6ee000>
01   01/31/16 12:31:51.918   luup_log:116: (I_ECO_Switch::EcoSwitch::setStatus) ERROR setting State of switch with ID 116. <0x2b6ee000>
06   01/31/16 12:31:51.919   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:0xc26b48/NONE duplicate:1 <0x2b6ee000>
50   01/31/16 12:31:51.919   luup_log:116: (I_ECO_Switch::ACTION::SetTarget) Switch state to 0] <0x2b6ee000>
04   01/31/16 12:31:51.921   <Job ID="9" Name="" Device="116" Created="2016-01-31 12:31:48" Started="2016-01-31 12:31:48" Completed="2016-01-31 12:31:51" Duration="3.31405000" Runtime="3.30900000" Status="Successful" LastNote=""/> <0x2b6ee000>

Thanks again!

Offline bigeazy000

  • Jr. Member
  • **
  • Posts: 53
  • Karma: +1/-0
Re: Eco Plugs
« Reply #20 on: January 31, 2016, 03:07:25 pm »
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...

Offline cybrmage

  • Hero Member
  • *****
  • Posts: 1057
  • Karma: +105/-5
Re: Eco Plugs
« Reply #21 on: January 31, 2016, 06:22:54 pm »
So, these are captures of it working...

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 **
« Last Edit: January 31, 2016, 07:35:46 pm by cybrmage »
EVL3Vista - Wink Connect - Caseta Connect - Venstar Colortouch - WiFi UDP Switch Controller - Broadlink RM - MyQGateway

Offline bigeazy000

  • Jr. Member
  • **
  • Posts: 53
  • Karma: +1/-0
Re: Eco Plugs
« Reply #22 on: January 31, 2016, 07:00:11 pm »
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
  • <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!!


Offline cybrmage

  • Hero Member
  • *****
  • Posts: 1057
  • Karma: +105/-5
Re: Eco Plugs
« Reply #23 on: January 31, 2016, 07:34:21 pm »
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 **
« Last Edit: February 03, 2016, 12:05:10 am by cybrmage »
EVL3Vista - Wink Connect - Caseta Connect - Venstar Colortouch - WiFi UDP Switch Controller - Broadlink RM - MyQGateway

Offline bigeazy000

  • Jr. Member
  • **
  • Posts: 53
  • Karma: +1/-0
Re: Eco Plugs
« Reply #24 on: January 31, 2016, 08:03:08 pm »
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   <Job ID="18" Name="" Device="116" Created="2016-01-31 17:57:47" Started="2016-01-31 17:57:47" Completed="2016-01-31 17:57:47" Duration="0.135586000" Runtime="0.134658000" Status="Successful" LastNote=""/> <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   <Job ID="25" Name="" Device="116" Created="2016-01-31 18:00:01" Started="2016-01-31 18:00:01" Completed="2016-01-31 18:00:01" Duration="0.129389000" Runtime="0.128225000" Status="Successful" LastNote=""/> <0x2b054000>
04   01/31/16 18:00:05.249   <Job ID="26" Name="pollnode #22 1 cmds" Device="60" Created="2016-01-31 18:00:05" Started="2016-01-31 18:00:05" Completed="2016-01-31 18:00:05" Duration="0.147523000" Runtime="0.146775000" Status="Successful" LastNote="" Node="22" NodeType="ZWaveNonDimmableLight" NodeDescription="Outdoor Outlet/Repea"/> <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#

Offline cybrmage

  • Hero Member
  • *****
  • Posts: 1057
  • Karma: +105/-5
Re: Eco Plugs
« Reply #25 on: January 31, 2016, 11:41:56 pm »
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...


EVL3Vista - Wink Connect - Caseta Connect - Venstar Colortouch - WiFi UDP Switch Controller - Broadlink RM - MyQGateway

Offline cybrmage

  • Hero Member
  • *****
  • Posts: 1057
  • Karma: +105/-5
Re: Eco Plugs
« Reply #26 on: January 31, 2016, 11:49:49 pm »
Actually... I found a bug that may have been causing the problem...

Try this....



** ATTACHMENT REMOVED **
« Last Edit: February 03, 2016, 12:05:59 am by cybrmage »
EVL3Vista - Wink Connect - Caseta Connect - Venstar Colortouch - WiFi UDP Switch Controller - Broadlink RM - MyQGateway

Offline bigeazy000

  • Jr. Member
  • **
  • Posts: 53
  • Karma: +1/-0
Re: Eco Plugs
« Reply #27 on: February 01, 2016, 10:31:25 am »
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!

Offline bigeazy000

  • Jr. Member
  • **
  • Posts: 53
  • Karma: +1/-0
Re: Eco Plugs
« Reply #28 on: February 01, 2016, 11:04:12 am »
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.
« Last Edit: February 01, 2016, 11:06:06 am by bigeazy000 »

Offline bigeazy000

  • Jr. Member
  • **
  • Posts: 53
  • Karma: +1/-0
Re: Eco Plugs
« Reply #29 on: February 01, 2016, 11:20:49 am »
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>