openLuup: Illumination (Philips Hue/LIFX etc.)

Yes, the logs never indicate a failure. In fact, I don’t want to call it a failure at all - rather an issue with the plugin not polling (what initiates a poll ?). At first, yes - I was concerned with the icon but after reviewing Vera’s logs, my understanding of how things work has changed (the logs are on page 1 of this thread; reply #11).

When openLuup creates the bulbs, the bulb starts out with one variable - ‘BulbModelID’. If a poll were to occur, then other variables would be set and maintained by the plugin.
For example, IconValue, LampValue, Status, Configured, LoadLevelStatus, LoadLevelTarget etc…

[quote=“akbooer, post:19, topic:189406”]Nothing in the openLuup log that indicates anything has failed, then?

Remind me what problem we’re chasing - it’s just the icon is it?

Edit: can you check and compare the attributes for the plugin on both Vera and openLuup ?[/quote]

The polling is done by the function pollHueDevice(), appropriately enough. It is scheduled to run at the POLLING_RATE of 10 seconds, and this is initiated in the Init() function by this code:

local bridgeLink = luup.variable_get(SID.HUE, "BridgeLink", device) or ""
if bridgeLink == "1" then
	pollHueDevice()
end

So if the device variable BridgeLink doesn’t exist, or have the value “1”, then the polling will never start.

That definitely helps. Honestly, I’m almost positive that my bridge is linked - has a ‘1’ and log data has shown me nothing (even have debug set to 1 on the bridge). I can control the lights and the only log data is a change of state that I invoke - never from a poll. So before I start lying, I’ll go home tonight and give it another go. I might just overwrite the ‘1’ with a ‘1’ and see if that invokes the process…

I’ll update with detailed information tonight…

The polling is done by the function pollHueDevice(), appropriately enough. It is scheduled to run at the POLLING_RATE of 10 seconds, and this is initiated in the Init() function by this code:

local bridgeLink = luup.variable_get(SID.HUE, "BridgeLink", device) or ""
if bridgeLink == "1" then
	pollHueDevice()
end

So if the device variable BridgeLink doesn’t exist, or have the value “1”, then the polling will never start.[/quote]

I am confused by the openLuup log (abridged) that you posted…
…although it may just be the way you filtered it (these don’t seem to be in chronological order?)

I see:
[tt]
786 2015-11-03 19:41:48.345 luup.variable_set:7: 7.urn:micasaverde-com:serviceId:PhilipsHue1.Status was: now: Philips Hue Bridge has been discovered! #hooks:0
787 2015-11-03 19:41:48.346 luup.variable_set:7: 7.urn:micasaverde-com:serviceId:PhilipsHue1.BridgeLink was: 1 now: 0 #hooks:0
788 2015-11-03 19:41:48.346 luup.task:7: status=1 Philips Hue by MiOS : Philips Hue bridge was detected. Please hit ‘Pair with the Bridge’ button!
[/tt]

and then
[tt]
790 2015-11-03 19:41:48.854 luup.variable_set:7: 7.urn:micasaverde-com:serviceId:PhilipsHue1.Status was: Philips Hue bridge was detected. Please hit ‘Pair with the Bridge’ button! now: Philips Hue Connected! #hooks:0
791 2015-11-03 19:41:48.854 luup.variable_set:7: 7.urn:micasaverde-com:serviceId:PhilipsHue1.BridgeLink was: 0 now: 1 #hooks:0
792 2015-11-03 19:41:48.854 luup.task:7: status=1 Philips Hue by MiOS : Philips Hue Connected!
[/tt]

and then
[tt]
32 2015-11-03 19:41:30.998 luup.variable_set:7: 7.urn:micasaverde-com:serviceId:PhilipsHue1.BridgeLink was: EMPTY now: 0 #hooks:0
33 2015-11-03 19:41:31.788 luup_log:7: (Hue2 Plugin)::(findBridge) : Philips Hue Bridge found with IP address: 10.0.4.40
[/tt]

and then
[tt]
37 2015-11-03 19:41:31.794 luup.variable_set:7: 7.urn:micasaverde-com:serviceId:PhilipsHue1.BridgeLink was: 0 now: 0 #hooks:0
[/tt]

So, really, I am totally confused about what the code is thinking it’s doing.

Do you, by any chance, have BOTH the bridged clone devices AND the locally installed Hue plugin devices, on openLuup at the same time? This might confuse the Hue bridge code too. So I would be in good company.

The order result was due to a WinGrep program I quickly installed and used (was rushing out the door that day) as I wanted all the results from the log files.

I am confused by the openLuup log (abridged) that you posted... ...although it may just be the way you filtered it (these don't seem to be in chronological order?)

I do happen to have both local and bridged running on the same unit so I’ll remove the plugin off of Vera when I get home tonight.

Do you, by any chance, have BOTH the bridged clone devices AND the locally installed Hue plugin devices, on openLuup at the same time? This might confuse the Hue bridge code too. So I would be in good company.

[1] Removed plugin from Vera3.
[2] Removed plugin from openLuup.
[3] Restarted openLuup, confirmed the devices were no longer loaded locally or remotely.
[4] Installed plugin on openLuup:

do -- Philips Hue by MiOS
  	local dev = luup.create_device ('', "PhilipsHue2", "PhilipsHue2", "D_PhilipsHue2.xml")  
  	local sid = "urn:micasaverde-com:serviceId:PhilipsHue1"
end

[5] Log data, see phue_install_1.txt
[6] Pressing the pair button on the bridge. Then reload.

2015-11-06 20:01:58.570   openLuup.server:: /data_request?id=action&output_format=json&DeviceNum=57&serviceId=urn:micasaverde-com:serviceId:PhilipsHue1&action=BridgeConnect tcp{client}: 0x2937e48
2015-11-06 20:01:58.572   luup.call_action:: 57.urn:micasaverde-com:serviceId:PhilipsHue1.BridgeConnect 
2015-11-06 20:01:58.576   openLuup.server:: request completed (62 bytes, 1 chunks, 5 ms) tcp{client}: 0x2937e48
2015-11-06 20:01:58.576   luup_log:57: (Hue2 Plugin)::(bridgeConnect) : Linking with the Bridge device
2015-11-06 20:01:58.639   luup.variable_set:57: 57.urn:micasaverde-com:serviceId:PhilipsHue1.Status was: Philips Hue Connected! now: Please press the link button on the Bridge and hit the Pair button again! #hooks:0
2015-11-06 20:01:58.640   luup.variable_set:57: 57.urn:micasaverde-com:serviceId:PhilipsHue1.BridgeLink was: 1 now: 0 #hooks:0

[7] Changed debug mode on device from 0 to 1.

2015-11-06 20:07:59.290   openLuup.server:: /data_request?id=variableset&DeviceNum=57&serviceId=urn:micasaverde-com:serviceId:PhilipsHue1&Variable=DebugMode&Value=1 tcp{client}: 0x1e7c798
2015-11-06 20:07:59.291   luup.variable_set:: 57.urn:micasaverde-com:serviceId:PhilipsHue1.DebugMode was: 0 now: 1 #hooks:0

[8] And we wait for any polling activity… Log data, see phue_install_2.txt

[9] And the remaining images from the install…
[10] If I attempt to re-enter the ip address for the bridge device I get
? 11/6/2015, 8:30:11 PM Error in PhilipsHue2.setPhilyHueIp(): TypeError: Utils.trim is not a function
[11] And the Java console says:
INIT
J_PhilipsHue2.js:43 bridgeLink: 1, status: Philips Hue Connected!

The thing that it making the logs so extensive is that you are testing this on a fully configured system. I see: VeraBridge linking to a remote Vera with Zwave activity, scenes running, the Extensions plugin, System monitor plugin? …

To make it much simpler, could we test on a system with just AltUI and the Hue Bridge? I’m imagining a startup.lua file like this:

luup.create_device ('', '', nil, "D_ALTUI.xml")
luup.create_device ('', '', nil, "D_PhilipsHue2.xml")

I don’t expect that this will change anything (although there is the remotest possibility that several plugins are, somehow, interfering) but it will make things a whole lot easier to understand. Then we can look at a complete log and not miss anything. Debugging turned on for the Hue is indeed a good plan.

Not a problem, I’ll start a clean install on the rPi2.

[quote=“akbooer, post:28, topic:189406”]The thing that it making the logs so extensive is that you are testing this on a fully configured system. I see: VeraBridge linking to a remote Vera with Zwave activity, scenes running, the Extensions plugin, System monitor plugin? …

To make it much simpler, could we test on a system with just AltUI and the Hue Bridge? I’m imagining a startup.lua file like this:

luup.create_device ('', '', nil, "D_ALTUI.xml")
luup.create_device ('', '', nil, "D_PhilipsHue2.xml")

I don’t expect that this will change anything (although there is the remotest possibility that several plugins are, somehow, interfering) but it will make things a whole lot easier to understand. Then we can look at a complete log and not miss anything. Debugging turned on for the Hue is indeed a good plan.[/quote]

[1] Removed all log files.
[2] Init using a clean startupNew.lua

luup.create_device ('', '', nil, "D_ALTUI.xml")
luup.create_device ('', '', nil, "D_PhilipsHue2.xml")

[3] Console

cuda@Ubuntu:/etc/cmh-ludl$ ./openLuup_reload startupNew.lua
device 3 'ALTUI' requesting reload
device 4 'Philips Hue by MiOS' requesting reload
device 0 '_system_' requesting reload
device 0 '_system_' requesting reload

[4] Enabled debug mode (observed bridged link was set to 1). Reloaded engine.
[5] Turned on office lamp (device 5) using iPad.
[6] Waited 5 minutes for a poll.
[7] Set bridge link to ‘1’ by overwriting the ‘1’ that was already there.

OK, thanks for that - a full picture of what is going on.

For a start, this is interesting (from v.2 of the logfile)

2015-11-07 09:47:08.742   luup.variable_get:4: NO SUCH DEVICE: nil

This actually needs a better diagnostic. It would help, for example, to know the serviceId and the variable name!

Here’s a replacement for openLuup/devices.lua to fix that. Can you run up to that stage again?

Looks like this was the offender. I performed the same process as previous, log files attached.

2015-11-07 11:33:54.159   luup.variable_get:4: No such device ?.urn:micasaverde-com:serviceId:PhilipsHue1.BridgeLink

Edit: Going to run this again, even though the log says it’s linked I’m going to press the link button again… Will post new logs.

If you’re running the same version of the Hue code as I am, then there is an error on line #925

This:

		local bridgeLink = luup.variable_get(SID.HUE, "BridgeLink", device) or ""

should be:

		local bridgeLink = luup.variable_get(SID.HUE, "BridgeLink", lug_device) or ""

Since it appears to work on a real Vera, I can only suppose that there is an undocumented feature (I think) that missing out the device number in such a call defaults to the current running device.

This would stop the polling from ever happening…

Making the change…

[quote=“akbooer, post:33, topic:189406”]If you’re running the same version of the Hue code as I am, then there is an error on line #925

This:

		local bridgeLink = luup.variable_get(SID.HUE, "BridgeLink", device) or ""

should be:

		local bridgeLink = luup.variable_get(SID.HUE, "BridgeLink", lug_device) or ""

Since it appears to work on a real Vera, I can only suppose that there is an undocumented feature (I think) that missing out the device number in such a call defaults to the current running device.

This would stop the polling from ever happening…[/quote]

Hmm, appears we may have different files… My files has two entries matching at lines 907 and 949.
Edit: The file was an edit by a member to allow support for Cree and Lux bulbs - that would be the reason for the difference.

Yes, these are vastly different versions.

[quote=“CudaNet, post:35, topic:189406”]Hmm, appears we may have different files… My files has two entries matching at lines 907 and 949.
Edit: The file was an edit by a member to allow support for Cree and Lux bulbs - that would be the reason for the difference.[/quote]

Line #907 is correct - ‘device’ is defined in that function’s parameter list.

Line #949 does need changing - as previously indicated.

You never cease to amaze me… Lamp was turned on via my iPad.

Edit: Had to update the log data to show the lamp was on…

2015-11-07 12:45:39.738   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[1] ON - No UI update needed!
2015-11-07 12:45:39.738   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[2] OFF - No UI update needed!
2015-11-07 12:45:39.739   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[3] OFF - No UI update needed!
2015-11-07 12:45:39.739   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[4] OFF - No UI update needed!
2015-11-07 12:45:39.739   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[5] OFF - No UI update needed!
2015-11-07 12:45:39.739   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[6] OFF - No UI update needed!
2015-11-07 12:45:39.739   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[7] OFF - No UI update needed!
2015-11-07 12:45:39.739   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[8] OFF - No UI update needed!
2015-11-07 12:45:39.739   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[9] OFF - No UI update needed!
2015-11-07 12:45:39.740   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[10] OFF - No UI update needed!
2015-11-07 12:45:39.740   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[11] OFF - No UI update needed!
2015-11-07 12:45:39.740   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[12] OFF - No UI update needed!
2015-11-07 12:45:39.740   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[13] OFF - No UI update needed!
2015-11-07 12:45:39.740   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[14] OFF - No UI update needed!
2015-11-07 12:45:39.740   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[15] OFF - No UI update needed!
2015-11-07 12:45:39.741   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[16] OFF - No UI update needed!
2015-11-07 12:45:39.741   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[17] OFF - No UI update needed!
2015-11-07 12:45:39.741   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[18] OFF - No UI update needed!
2015-11-07 12:45:39.741   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[19] OFF - No UI update needed!
2015-11-07 12:45:39.741   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[20] OFF - No UI update needed!
2015-11-07 12:45:39.741   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[21] OFF - No UI update needed!
2015-11-07 12:45:39.742   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[22] OFF - No UI update needed!
2015-11-07 12:45:39.742   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[23] OFF - No UI update needed!
2015-11-07 12:45:39.742   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[24] OFF - No UI update needed!
2015-11-07 12:45:39.742   luup_log:4: (Hue2 Plugin)::(pollHueDevice) : Lamp[25] OFF - No UI update needed!

[quote=“akbooer, post:37, topic:189406”][quote=“CudaNet, post:35, topic:189406”]Hmm, appears we may have different files… My files has two entries matching at lines 907 and 949.
Edit: The file was an edit by a member to allow support for Cree and Lux bulbs - that would be the reason for the difference.[/quote]

Line #907 is correct - ‘device’ is defined in that function’s parameter list.

Line #949 does need changing - as previously indicated.[/quote]

Excellent news… thank goodness for that!

Actually, I’m extremely annoyed at myself because I actually quoted the errant line in this earlier post http://forum.micasaverde.com/index.php/topic,34477.msg255327.html#msg255327, but didn’t recognise it for what it was.

I also now have the dilemma of whether or not to emulate this undocumented behaviour. I also have to see if it holds for other luup calls.

Vera/MiOS never ceases to amaze me (in a bad sort of way.)

BTW, who wrote this? Perhaps you should tell the author.