tinman
January 7, 2019, 7:09pm
#1
I’m working on upgrading code that operates light switches and dimmers. I’m seeing something unexpected in the log. Vera is doing something that causes my code to fail:
08 01/07/19 13:45:07.894 JobHandler_LuaUPnP::HandleActionRequest device: 1797 service: urn:upnp-org:serviceId:SwitchPower1 action: SetTarget <0x73ea8520>
08 01/07/19 13:45:07.895 JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=1797 <0x73ea8520>
08 01/07/19 13:45:07.895 JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:upnp-org:serviceId:SwitchPower1 <0x73ea8520>
08 01/07/19 13:45:07.895 JobHandler_LuaUPnP::HandleActionRequest argument action=SetTarget <0x73ea8520>
08 01/07/19 13:45:07.895 JobHandler_LuaUPnP::HandleActionRequest argument newTargetValue=1 <0x73ea8520>
08 01/07/19 13:45:07.895 JobHandler_LuaUPnP::HandleActionRequest argument rand=0.5999288576793546 <0x73ea8520>
02 01/07/19 13:45:07.896 JobHandler_LuaUPnP::ConfirmGlobalActionRules replaced binary on with dim 45 <0x73ea8520>
epkulse
February 3, 2019, 8:15pm
#2
I see the same using AltHUE plugin, which always make it impossible to switch on the lamp bulb. The steps below is 1) Switch Off - works OK 2) Switch On - Fail 3) Change dim level - switches lamp on and changes dim level
08 02/03/19 21:00:11.809 JobHandler_LuaUPnP::HandleActionRequest device: 736 service: urn:upnp-org:serviceId:SwitchPower1 action: SetTarget <0x732f6520>02 02/03/19 21:00:13.884 JobHandler_LuaUPnP::ConfirmGlobalActionRules replaced binary on with dim 72 <0x732f6520> 50 02/03/19 21:00:13.885 luup_log:732: ALTHUE: debug: UserSetLoadLevelTarget(736,72) <0x732f6520>#hooks: 0 upnp: 0 skip: 0 v:0xf18920/NONE duplicate:0 <0x7412f520>#hooks: 0 upnp: 0 skip: 0 v:0xd5e898/NONE duplicate:0 <0x7412f520>#hooks: 0 upnp: 0 skip: 0 v:0xd74e88/NONE duplicate:1 <0x7412f520>#hooks: 0 upnp: 0 skip: 0 v:0xd74ef0/NONE duplicate:1 <0x7412f520>
tinman
February 3, 2019, 8:46pm
#3
What I’ve been told by those at Vera is that this is the way it works. It seems that any device that uses both the urn:upnp-org:serviceId:SwitchPower1 (usually for On/Off) and urn:upnp-org:serviceId:Dimming1 services to set a dim level also uses the LoadLevelLast variable. So whenever an attempt to just turn a device on it will instead set the dim level to the value in LoadLevelLast. I suppose this is how a regular dimmer switch works - when you turn it on it will just be illuminated to the last dimmer setting. If you really want to override this behavior you’ll need to set LoadLevelLast to 100 whenever you’re setting the device to anything but Off.
epkulse
February 4, 2019, 5:44pm
#4
OK, I will try to see if that works…
epkulse
February 4, 2019, 8:36pm
#5
Found another way to solve my issue - I trigger a Hue scene which switches on my lamps… Works!
Hi,
An other way to do this is to not use the SetTarget action, but SetLoadLevelTarget and set that to 100. That will turn on any dimming device fully on and not use the LastLoadLevel setting.
Personally I like the behavior of using the LastLoadLevel, so does the misses.
Cheers Rene
epkulse
February 5, 2019, 7:10pm
#7
Well, I have tested that approach - but it has not been working for managing Philips Hue lights…
Odd, I tried on a VeraEdge and I am not seeing the calls to ConfirmGlobalActionRules when doing a SetTarget or SetLoadleveltarget. I have an other plugin to control Hue lights (via the Harmony Hub Plugin V3.3) and it works as expected. Its logic is similar to ALTHUE’s one (not so many ways to do the same thing right).
08 02/06/19 11:24:38.271 JobHandler_LuaUPnP::HandleActionRequest device: 13539 service: urn:upnp-org:serviceId:SwitchPower1 action: SetTarget <0x72040520>
08 02/06/19 11:24:38.272 JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=13539 <0x72040520>
08 02/06/19 11:24:38.272 JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:upnp-org:serviceId:SwitchPower1 <0x72040520>
08 02/06/19 11:24:38.273 JobHandler_LuaUPnP::HandleActionRequest argument action=SetTarget <0x72040520>
08 02/06/19 11:24:38.273 JobHandler_LuaUPnP::HandleActionRequest argument newTargetValue=0 <0x72040520>
08 02/06/19 11:24:38.273 JobHandler_LuaUPnP::HandleActionRequest argument rand=0.47065987756310135 <0x72040520>
04 02/06/19 11:24:38.501 <Job ID="18" Name="" Device="13539" Created="2019-02-06 11:24:38" Started="2019-02-06 11:24:38" Completed="2019-02-06 11:24:38" Duration="0.227118000" Runtime="0.226258000" Status="Successful" LastNote=""/> <0x7725c000>
06 02/06/19 11:24:39.106 Device_Variable::m_szValue_set device: 13539 service: urn:upnp-org:serviceId:SwitchPower1 variable: Target was: 1 now: 0 #hooks: 0 upnp: 0 skip: 0 v:0xa1f878/NONE duplicate:0 <0x75841520>
06 02/06/19 11:24:39.107 Device_Variable::m_szValue_set device: 13539 service: urn:upnp-org:serviceId:SwitchPower1 variable: Status was: 1 now: 0 #hooks: 0 upnp: 0 skip: 0 v:0xa1e620/NONE duplicate:0 <0x75841520>
06 02/06/19 11:24:39.108 Device_Variable::m_szValue_set device: 13539 service: urn:upnp-org:serviceId:Dimming1 variable: LoadLevelTarget was: 50 now: 0 #hooks: 0 upnp: 0 skip: 0 v:0xb46758/NONE duplicate:0 <0x75841520>
06 02/06/19 11:24:39.109 Device_Variable::m_szValue_set device: 13539 service: urn:upnp-org:serviceId:Dimming1 variable: LoadLevelStatus was: 50 now: 0 #hooks: 0 upnp: 0 skip: 0 v:0xb467c0/NONE duplicate:0 <0x75841520>
06 02/06/19 11:24:39.110 Device_Variable::m_szValue_set device: 13539 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: Watts was: 4 now: 0 #hooks: 0 upnp: 0 skip: 0 v:0xa1fe68/NONE duplicate:0 <0x75841520>
06 02/06/19 11:24:39.111 Device_Variable::m_szValue_set device: 13539 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: Log was: 4,0,4,1549448501,261 now: 0,1,4,1549448679,439 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x75841520>luup.call_action('urn:upnp-org:serviceId:Dimming1','SetLoadLevelTarget',{ ["newLoadlevelTarget"] = "100" } ,13539)
08 02/06/19 11:33:37.221 JobHandler_LuaUPnP::HandleActionRequest device: 13539 service: urn:upnp-org:serviceId:Dimming1 action: SetLoadLevelTarget <0x729e6520>
08 02/06/19 11:33:37.222 JobHandler_LuaUPnP::HandleActionRequest argument newLoadlevelTarget=100 <0x729e6520>
06 02/06/19 11:33:37.267 Device_Variable::m_szValue_set device: 13539 service: urn:upnp-org:serviceId:Dimming1 variable: LoadLevelLast was: 50 now: 100 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x7725c000>
06 02/06/19 11:33:37.267 Device_Variable::m_szValue_set device: 13539 service: urn:upnp-org:serviceId:Dimming1 variable: LoadLevelTarget was: 0 now: 100 #hooks: 0 upnp: 0 skip: 0 v:0xb46758/NONE duplicate:0 <0x7725c000>
06 02/06/19 11:33:37.268 Device_Variable::m_szValue_set device: 13539 service: urn:upnp-org:serviceId:Dimming1 variable: LoadLevelStatus was: 0 now: 100 #hooks: 0 upnp: 0 skip: 0 v:0xb467c0/NONE duplicate:0 <0x7725c000>
06 02/06/19 11:33:37.269 Device_Variable::m_szValue_set device: 13539 service: urn:upnp-org:serviceId:SwitchPower1 variable: Target was: 0 now: 1 #hooks: 0 upnp: 0 skip: 0 v:0xa1f878/NONE duplicate:0 <0x7725c000>
06 02/06/19 11:33:37.270 Device_Variable::m_szValue_set device: 13539 service: urn:upnp-org:serviceId:SwitchPower1 variable: Status was: 0 now: 1 #hooks: 0 upnp: 0 skip: 0 v:0xa1e620/NONE duplicate:0 <0x7725c000>
04 02/06/19 11:33:37.497 <Job ID="35" Name="���" Device="13539" Created="2019-02-06 11:33:37" Started="2019-02-06 11:33:37" Completed="2019-02-06 11:33:37" Duration="0.274379000" Runtime="0.271942000" Status="Successful" LastNote=""/> <0x7725c000>
06 02/06/19 11:33:38.109 Device_Variable::m_szValue_set device: 13539 service: urn:upnp-org:serviceId:Dimming1 variable: LoadLevelLast was: 100 now: 99 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x75841520>
06 02/06/19 11:33:38.110 Device_Variable::m_szValue_set device: 13539 service: urn:upnp-org:serviceId:Dimming1 variable: LoadLevelTarget was: 100 now: 99 #hooks: 0 upnp: 0 skip: 0 v:0xb46758/NONE duplicate:0 <0x75841520>
06 02/06/19 11:33:38.111 Device_Variable::m_szValue_set device: 13539 service: urn:upnp-org:serviceId:Dimming1 variable: LoadLevelStatus was: 100 now: 99 #hooks: 0 upnp: 0 skip: 0 v:0xb467c0/NONE duplicate:0 <0x75841520>
06 02/06/19 11:33:38.112 Device_Variable::m_szValue_set device: 13539 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: Watts was: 0 now: 7.92 #hooks: 0 upnp: 0 skip: 0 v:0xa1fe68/NONE duplicate:0 <0x75841520>
06 02/06/19 11:33:38.113 Device_Variable::m_szValue_set device: 13539 service: urn:micasaverde-com:serviceId:EnergyMetering1 variable: Log was: 0,0,0,1549449000,1 now: 7,0,7,1549449218,219 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x75841520>
06 02/06/19 11:33:48.111 Device_Variable::m_szValue_set device: 13539 service: urn:micasaverde-com:serviceId:Color1 variable: CurrentColor was: 0=0,1=0,2=255,3=26,4=109 now: 0=0,1=0,2=255,3=13,4=111 #hooks: 0 upnp: 0 skip: 0 v:0xb64d60/NONE duplicate:0 <0x75841520>Cheers Rene
epkulse
February 6, 2019, 5:31pm
#9
Well, I had it working OK for a while. Then I ended up in problems after installing AltUI - lack of memory. After resolving this, I got this problem which has not been possible overcome.