Author Topic: Strange behavior with altsteon/keypadlinc  (Read 1530 times)

Offline nanobots

  • Newbie
  • *
  • Posts: 10
  • Karma: +0/-0
Strange behavior with altsteon/keypadlinc
« on: January 02, 2015, 01:35:29 pm »
Hey guys,

I have an 8-button KPL setup that is exhibiting some unusual behavior. The main (load) switch is setup to control my undercabinet lighting via a scene. (The switch doesn't actually have a load attached.) This seems straight forward enough, but frequently when I use the switch, the scene triggers (the lights turn on, for example), but then a few seconds later it reverts (the lights turn back on, or vice versa). Sometimes this will occur repeatedly and indefinitely, sometimes it will just happen once or a few times.

Any thoughts on what could be causing this?

This is the luup running when the scene is triggered (On):
Code: [Select]
luup.call_action("urn:upnp-org:serviceId:Dimming1", "SetLoadLevelTarget", {newLoadlevelTarget = "100"},46)
This is the luup running when the scene is triggered (Off):
Code: [Select]
luup.call_action("urn:upnp-org:serviceId:Dimming1", "SetLoadLevelTarget", {newLoadlevelTarget = "0"},46)

Below is some log data where the issue is occurring. Here I think the button was pressed once, the light turned off and then back on:

Code: [Select]
50 01/02/15 10:33:14.234 luup_log:50: Parsing : 2C.05.10:008D,00,01,00 - LED follow mask for button/group 1 is 0. <0x2febc680>
50 01/02/15 10:33:14.235 luup_log:50: Sending to child id 51 (2C.05.10) <0x2febc680>
50 01/02/15 10:33:14.237 luup_log:50: Parsing : 2C.05.10:008E,00,01,00 - LED off mask for button/group 1 is 0. <0x2febc680>
50 01/02/15 10:33:14.237 luup_log:50: Sending to child id 51 (2C.05.10) <0x2febc680>
50 01/02/15 10:33:14.239 luup_log:50: Parsing : 2C.05.10:008F,00,01,20 - X10 house code for button/group 1 is 32. <0x2febc680>
50 01/02/15 10:33:14.251 luup_log:50: Sending to child id 51 (2C.05.10) <0x2febc680>
50 01/02/15 10:33:14.253 luup_log:50: Parsing : 2C.05.10:0090,00,01,20 - X10 unit code for button/group 1 is 32. <0x2febc680>
50 01/02/15 10:33:14.254 luup_log:50: Sending to child id 51 (2C.05.10) <0x2febc680>
50 01/02/15 10:33:14.256 luup_log:50: Parsing : 2C.05.10:0091,00,01,1C - Ramp rate for button/group 1 is 28. <0x2febc680>
50 01/02/15 10:33:14.256 luup_log:50: Sending to child id 51 (2C.05.10) <0x2febc680>
50 01/02/15 10:33:14.258 luup_log:50: Parsing : 2C.05.10:0092,00,01,FE - On level for button/group 1 is 254. <0x2febc680>
50 01/02/15 10:33:14.258 luup_log:50: Sending to child id 51 (2C.05.10) <0x2febc680>
50 01/02/15 10:33:14.307 luup_log:50: Parsing : 2C.05.10:0093,00,01,05 - Global LED brightness for button/group 1 is 5. <0x2febc680>
50 01/02/15 10:33:14.307 luup_log:50: Sending to child id 51 (2C.05.10) <0x2febc680>
50 01/02/15 10:33:14.309 luup_log:50: Parsing : 2C.05.10:0094,00,01,00 - Associated non-toggle bitmap for button/group 1 is 0. <0x2febc680>
50 01/02/15 10:33:14.353 luup_log:50: Sending to child id 51 (2C.05.10) <0x2febc680>
50 01/02/15 10:33:14.355 luup_log:50: Parsing : 2C.05.10:0095,00,01,0F - LED state for button/group 1 is 15. <0x2febc680>
50 01/02/15 10:33:14.356 luup_log:50: Sending to child id 51 (2C.05.10) <0x2febc680>
50 01/02/15 10:33:14.358 luup_log:50: Parsing : 2C.05.10:0096,00,01,00 - X-10 all bitmap for button/group 1 is 0. <0x2febc680>
50 01/02/15 10:33:14.358 luup_log:50: Sending to child id 51 (2C.05.10) <0x2febc680>
50 01/02/15 10:33:14.414 luup_log:50: Parsing : 2C.05.10:0097,00,01,00 - Non-toggle bitmap for button/group 1 is 0. <0x2febc680>
50 01/02/15 10:33:14.415 luup_log:50: Sending to child id 51 (2C.05.10) <0x2febc680>
50 01/02/15 10:33:14.417 luup_log:50: Parsing : 2C.05.10:0098,00,01,00 - Trigger all-link bitmap for button/group 1 is 0. <0x2febc680>
50 01/02/15 10:33:14.418 luup_log:50: Sending to child id 51 (2C.05.10) <0x2febc680>
50 01/02/15 10:33:17.602 luup_log:50: Parsing : 2B.A7.14:0009,00,01 - 2B.A7.14 button/group 1 is off. <0x2febc680>
50 01/02/15 10:33:17.602 luup_log:50: Sending to child id 71 (2B.A7.14) <0x2febc680>
06 01/02/15 10:33:17.603 Device_Variable::m_szValue_set device: 71 service: urn:upnp-org:serviceId:SwitchPower1 variable: Status was: 1 now: 0 #hooks: 2 upnp: 0 v:0xf7beb8/NONE duplicate:0 <0x2febc680>
07 01/02/15 10:33:17.603 Event::Evaluate 28 Kitchen 8 Button Scene Controller Main On scene Undercabinet Lights On is false repeat 0/-1 <0x2febc680>
07 01/02/15 10:33:17.604 Event::Evaluate 29 Kitchen KPL Off scene Undercabinet Lights Off is true users:(null) allow:1 <0x2febc680>
08 01/02/15 10:33:17.604 Scene::RunScene running 29 Undercabinet Lights Off <0x2febc680>
08 01/02/15 10:33:17.605 JobHandler_LuaUPnP::HandleActionRequest device: 46 service: urn:upnp-org:serviceId:Dimming1 action: SetLoadLevelTarget <0x2febc680>
08 01/02/15 10:33:17.605 JobHandler_LuaUPnP::HandleActionRequest argument newLoadlevelTarget=0 <0x2febc680>
50 01/02/15 10:33:17.606 luup_log:26: Philips Hue Controller: 46 <0x2febc680>
50 01/02/15 10:33:17.606 luup_log:26: Philips Hue Controller: *** DIM device: 46 value: 0  altid:5 <0x2febc680>
50 01/02/15 10:33:17.607 luup_log:26: Philips Hue Controller: Post: {"on":false} <0x2febc680>
06 01/02/15 10:33:17.906 Device_Variable::m_szValue_set device: 46 service: urn:upnp-org:serviceId:Dimming1 variable: LoadLevelStatus was: 100 now: 0 #hooks: 2 upnp: 0 v:0xf95e00/NONE duplicate:0 <0x2febc680>
06 01/02/15 10:33:17.907 Device_Variable::m_szValue_set device: 46 service: urn:upnp-org:serviceId:SwitchPower1 variable: Status was: 1 now: 0 #hooks: 0 upnp: 0 v:0xf7beb8/NONE duplicate:0 <0x2febc680>
50 01/02/15 10:33:18.892 luup_log:50: Parsing : 2B.A7.14:0024,00,FF - Light brightness is 255. <0x2febc680>
50 01/02/15 10:33:18.893 luup_log:50: Sending to child id 71 (2B.A7.14) <0x2febc680>
06 01/02/15 10:33:18.893 Device_Variable::m_szValue_set device: 71 service: urn:upnp-org:serviceId:Dimming1 variable: LoadLevelStatus was: 100 now: 100 #hooks: 0 upnp: 0 v:0xf95e00/NONE duplicate:1 <0x2febc680>
06 01/02/15 10:33:18.894 Device_Variable::m_szValue_set device: 71 service: urn:upnp-org:serviceId:SwitchPower1 variable: Status was: 0 now: 1 #hooks: 2 upnp: 0 v:0xf7beb8/NONE duplicate:0 <0x2febc680>
07 01/02/15 10:33:18.894 Event::Evaluate 28 Kitchen 8 Button Scene Controller Main On scene Undercabinet Lights On is true users:(null) allow:1 <0x2febc680>
08 01/02/15 10:33:18.894 Scene::RunScene running 28 Undercabinet Lights On <0x2febc680>
08 01/02/15 10:33:18.895 JobHandler_LuaUPnP::HandleActionRequest device: 71 service: urn:upnp-org:serviceId:Dimming1 action: SetLoadLevelTarget <0x2febc680>
08 01/02/15 10:33:18.895 JobHandler_LuaUPnP::HandleActionRequest argument newLoadlevelTarget=100 <0x2febc680>
50 01/02/15 10:33:18.896 luup_log:50: Setting dimmer to 100 <0x2febc680>
50 01/02/15 10:33:18.896 luup_log:50: Sending (setloadleveltarget) : "2B.A7.14" instant_dim 100
<0x2febc680>
08 01/02/15 10:33:18.898 JobHandler_LuaUPnP::HandleActionRequest device: 46 service: urn:upnp-org:serviceId:Dimming1 action: SetLoadLevelTarget <0x2febc680>
08 01/02/15 10:33:18.898 JobHandler_LuaUPnP::HandleActionRequest argument newLoadlevelTarget=100 <0x2febc680>
50 01/02/15 10:33:18.899 luup_log:26: Philips Hue Controller: 46 <0x2febc680>
50 01/02/15 10:33:18.899 luup_log:26: Philips Hue Controller: *** DIM device: 46 value: 100  altid:5 <0x2febc680>
50 01/02/15 10:33:18.981 luup_log:26: Philips Hue Controller: Post: {"on":true,"bri":254} <0x2febc680>
06 01/02/15 10:33:19.179 Device_Variable::m_szValue_set device: 46 service: urn:upnp-org:serviceId:Dimming1 variable: LoadLevelStatus was: 0 now: 100 #hooks: 2 upnp: 0 v:0xf95e00/NONE duplicate:0 <0x2febc680>
06 01/02/15 10:33:19.273 Device_Variable::m_szValue_set device: 46 service: urn:upnp-org:serviceId:SwitchPower1 variable: Status was: 0 now: 1 #hooks: 0 upnp: 0 v:0xf7beb8/NONE duplicate:0 <0x2febc680>
08 01/02/15 10:33:19.274 JobHandler_LuaUPnP::HandleActionRequest device: 47 service: urn:intvelt-com:serviceId:HueColors1 action: SetPreset <0x2febc680>
08 01/02/15 10:33:19.274 JobHandler_LuaUPnP::HandleActionRequest argument Preset=1 <0x2febc680>
50 01/02/15 10:33:19.275 luup_log:26: Philips Hue Controller: >>> Device:47  Lamp nr:5  To preset:1 <0x2febc680>
50 01/02/15 10:33:19.276 luup_log:26: Philips Hue Controller:      level:100   on:1 <0x2febc680>
50 01/02/15 10:33:19.276 luup_log:26: Philips Hue Controller: Post: {"xy":[0.4567,0.3481]} <0x2febc680>
06 01/02/15 10:33:19.376 Device_Variable::m_szValue_set device: 47 service: urn:intvelt-com:serviceId:HueColors1 variable: CurrentPreset was: 1 now: 1 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0x2febc680>
50 01/02/15 10:33:19.666 luup_log:26: Philips Hue Controller: Got JSON on get username: {"state": {"on":true,"bri":254,"hue":57359,"sat":78,"xy":[0.4567,0.3481],"alert":"none","effect":"none","colormode":"xy","reachable":true}, "type": "Color light", "name": "Undercabinet", "modelid": "LST001", "swversion": "66010400", "pointsymbol": { "1":"none", "2":"none", "3":"none", "4":"none", "5":"none", "6":"none", "7":"none", "8":"none" }} <0x2febc680>
50 01/02/15 10:33:19.666 luup_log:26: Philips Hue Controller: Response received for light state <0x2febc680>
06 01/02/15 10:33:19.667 Device_Variable::m_szValue_set device: 26 service: urn:intvelt-com:serviceId:HueController1 variable: LinkStatus was: Hue hub is up and linked now: Hue hub is up and linked #hooks: 0 upnp: 0 v:0xfcc330/NONE duplicate:1 <0x2febc680>
50 01/02/15 10:33:19.667 luup_log:26: Philips Hue Controller: Updating for light <0x2febc680>
06 01/02/15 10:33:19.668 Device_Variable::m_szValue_set device: 47 service: urn:intvelt-com:serviceId:HueColors1 variable: ColorTemperature was: 0 now: 0 #hooks: 0 upnp: 0 v:0xff9438/NONE duplicate:1 <0x2febc680>
06 01/02/15 10:33:19.668 Device_Variable::m_szValue_set device: 47 service: urn:intvelt-com:serviceId:HueColors1 variable: Hue was: 0 now: 0 #hooks: 0 upnp: 0 v:0xff9fc8/NONE duplicate:1 <0x2febc680>
06 01/02/15 10:33:19.668 Device_Variable::m_szValue_set device: 47 service: urn:intvelt-com:serviceId:HueColors1 variable: Saturation was: 0 now: 0 #hooks: 0 upnp: 0 v:0xff9fa8/NONE duplicate:1 <0x2febc680>
08 01/02/15 10:33:19.669 JobHandler_LuaUPnP::HandleActionRequest device: 46 service: urn:upnp-org:serviceId:Dimming1 action: SetLoadLevelTarget <0x2febc680>
08 01/02/15 10:33:19.720 JobHandler_LuaUPnP::HandleActionRequest argument newLoadlevelTarget=100 <0x2febc680>
50 01/02/15 10:33:19.720 luup_log:26: Philips Hue Controller: 46 <0x2febc680>
50 01/02/15 10:33:19.721 luup_log:26: Philips Hue Controller: *** DIM device: 46 value: 100  altid:5 <0x2febc680>
50 01/02/15 10:33:19.722 luup_log:26: Philips Hue Controller: Post: {"on":true,"bri":254} <0x2febc680>
06 01/02/15 10:33:19.875 Device_Variable::m_szValue_set device: 46 service: urn:upnp-org:serviceId:Dimming1 variable: LoadLevelStatus was: 100 now: 100 #hooks: 2 upnp: 0 v:0xf95e00/NONE duplicate:1 <0x2febc680>
06 01/02/15 10:33:19.876 Device_Variable::m_szValue_set device: 46 service: urn:upnp-org:serviceId:SwitchPower1 variable: Status was: 1 now: 1 #hooks: 0 upnp: 0 v:0xf7beb8/NONE duplicate:1 <0x2febc680>
08 01/02/15 10:33:19.877 JobHandler_LuaUPnP::HandleActionRequest device: 47 service: urn:intvelt-com:serviceId:HueColors1 action: SetPreset <0x2febc680>
08 01/02/15 10:33:19.877 JobHandler_LuaUPnP::HandleActionRequest argument Preset=1 <0x2febc680>
50 01/02/15 10:33:19.878 luup_log:26: Philips Hue Controller: >>> Device:47  Lamp nr:5  To preset:1 <0x2febc680>
50 01/02/15 10:33:19.878 luup_log:26: Philips Hue Controller:      level:100   on:1 <0x2febc680>
50 01/02/15 10:33:19.879 luup_log:26: Philips Hue Controller: Post: {"xy":[0.4567,0.3481]} <0x2febc680>
06 01/02/15 10:33:20.125 Device_Variable::m_szValue_set device: 47 service: urn:intvelt-com:serviceId:HueColors1 variable: CurrentPreset was: 1 now: 1 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0x2febc680>
50 01/02/15 10:33:20.452 luup_log:26: Philips Hue Controller: Got JSON on get username: {"state": {"on":true,"bri":254,"hue":57359,"sat":78,"xy":[0.4567,0.3481],"alert":"none","effect":"none","colormode":"xy","reachable":true}, "type": "Color light", "name": "Undercabinet", "modelid": "LST001", "swversion": "66010400", "pointsymbol": { "1":"none", "2":"none", "3":"none", "4":"none", "5":"none", "6":"none", "7":"none", "8":"none" }} <0x2febc680>
50 01/02/15 10:33:20.453 luup_log:26: Philips Hue Controller: Response received for light state <0x2febc680>
06 01/02/15 10:33:20.453 Device_Variable::m_szValue_set device: 26 service: urn:intvelt-com:serviceId:HueController1 variable: LinkStatus was: Hue hub is up and linked now: Hue hub is up and linked #hooks: 0 upnp: 0 v:0xfcc330/NONE duplicate:1 <0x2febc680>
50 01/02/15 10:33:20.453 luup_log:26: Philips Hue Controller: Updating for light <0x2febc680>
06 01/02/15 10:33:20.454 Device_Variable::m_szValue_set device: 47 service: urn:intvelt-com:serviceId:HueColors1 variable: ColorTemperature was: 0 now: 0 #hooks: 0 upnp: 0 v:0xff9438/NONE duplicate:1 <0x2febc680>

Offline PurdueGuy

  • Hero Member
  • *****
  • Posts: 1169
  • Karma: +21/-0
Re: Strange behavior with altsteon/keypadlinc
« Reply #1 on: January 02, 2015, 04:37:20 pm »
I am a little unclear on which device is which, and your setup.

Vera device 71 = Insteon KPL with ID 2B.A7.14
Vera device 46 = Philips Hue light that you are controlling

It looks like you have a scene #28 ("Undercabinet Lights On") which is triggered by turning "2B.A7.14 button 1" on.
This scene then turns device #46 (Philips Hue) on.

It looks like you have a scene #29 ("Undercabinet Lights Off") which is triggered by turning "2B.A7.14 button 1" off.
This scene then turns device #46 (Philips Hue) off.

The issue only happens when you run from the switch, correct?  Evert time you do it from the Vera dashboard, it works exactly as intended?
Vera3, Leviton, Intermatic, SQ Blaster, HomeWave, DSC 1832, Insteon/Altsteon

Offline nanobots

  • Newbie
  • *
  • Posts: 10
  • Karma: +0/-0
Re: Strange behavior with altsteon/keypadlinc
« Reply #2 on: January 02, 2015, 08:39:17 pm »
Yep, I believe that is all exactly correct. It does not seem that triggering the scenes (Undercabinet light on or off) from the dashboard causes the same behavior.