We have moved at community.getvera.com

Author Topic: Guidance for nest plugin?  (Read 26511 times)

Offline garrettwp

  • Master Member
  • *******
  • Posts: 6371
  • Karma: +227/-128
  • Vera 3, Lite, ISY994
Re: Guidance for nest plugin?
« Reply #30 on: December 10, 2012, 02:17:53 am »
Saw the other thread, plugin is looking good. Making me want to spend some money! Also glad to hear that my app is working with your nest plugin. Are all of the functions working in my app or are you experiencing any issues? I need to tweak the HVAC device to prevent some crash issues with different brand thermostat (more or less need to put in some better checks).

- Garrett

Offline watou

  • Moderator
  • Hero Member
  • *****
  • Posts: 889
  • Karma: +44/-12
Re: Guidance for nest plugin?
« Reply #31 on: December 10, 2012, 07:46:11 am »
Hi Garrett,

Your app is working great with the plugin, except I'm still fiddling a bit with the C-to-F conversion, and when the temperature or set points are not an integer, the app crashes when I open the thermostat device.  The Nest gives temperatures in Celsius with three places of precision, which isn't so good for the UI.  So I'm now rounding off the decimals on conversion to Fahrenheit, but converting to C with 3 places of precision.  If my Vera were set to use C instead of F, app crashing and Vera UI issues would probably show themselves again.

The Nest is able to separate its UI from the actual temperature values, so that it presents whole numbers even when the temperature values are in fact not whole numbers.  I can't do that with the plugin (without storing two sets of temperatures -- the fully precise temperature as a sidecar to the rounded-off one, which I would rather not do).

Any enlightenment on better handling of temperature and conversion would be appreciated.

Regards, watou

Offline watou

  • Moderator
  • Hero Member
  • *****
  • Posts: 889
  • Karma: +44/-12
Re: Guidance for nest plugin?
« Reply #32 on: December 10, 2012, 03:18:23 pm »
Several days ago I was messing around with apps.mios.com and managed to create a broken plugin entry.  I see it from my account when I go to https://apps.mios.com/view-plugins-details.php?&npage=2.  It has this link on it: https://apps.mios.com/plugin.php?id=3116 but then it says "Plugin specified not found." when I go to the link.

It appears on the Plugin Details page so it's partially in the database.  Does anyone here know what's going on, or how to ask whomever is in charge of that site to clean up this broken plugin entry?  I want to create a fresh one with the same name, so I'm a bit stuck.

Offline garrettwp

  • Master Member
  • *******
  • Posts: 6371
  • Karma: +227/-128
  • Vera 3, Lite, ISY994
Re: Guidance for nest plugin?
« Reply #33 on: December 10, 2012, 04:16:11 pm »
Contact MCVFlorin via pm.

- Garrett


Offline watou

  • Moderator
  • Hero Member
  • *****
  • Posts: 889
  • Karma: +44/-12
Re: Guidance for nest plugin?
« Reply #34 on: December 12, 2012, 04:05:53 pm »
Thanks, Garrett.  MCVFlorin fixed up that entry and I submitted a plugin yesterday morning.  I hope they can review it soon, but I know they can't drop everything to check it out.  Just eager to get feedback!  Thanks for your help.

Offline guessed

  • Community Beta
  • Master Member
  • ******
  • Posts: 5301
  • Karma: +92/-22
  • Release compat is not a bolted-on afterthought
Re: Guidance for nest plugin?
« Reply #35 on: December 14, 2012, 01:50:08 am »
@watou,
There's definitely something whacked in the poll() logic. I haven't narrowed it down yet, but figured you should know.  Even with 120s polling interval, it's actually calling a bunch faster than that, as can be seen in this snippet of my logs:

Code: [Select]
35 12/13/12 22:22:05.433 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:22:12.804 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:22:40.638 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:23:21.402 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:23:26.444 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:24:06.501 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:24:13.663 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:24:41.533 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:25:22.542 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:25:27.571 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:26:07.484 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:26:14.490 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:26:42.504 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:27:23.869 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:27:28.533 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:28:08.660 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:28:15.967 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:28:43.536 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:29:24.472 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:29:29.469 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:30:15.807 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:30:21.941 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:30:44.987 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:31:25.615 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:31:30.753 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:32:16.706 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:32:22.607 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:32:45.517 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:33:26.472 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:33:31.499 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:34:17.489 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>
35 12/13/12 22:34:23.537 luup_log:333: Nest: debug: polling device 333 again in 120 seconds <0x2de4b680>

I can't tell for sure, but it may have restarted a few times, potentially as a result of the "on-the-fly" calls to create the child-devices (which I've not seen done before)



As a side-effect of this, you end up printing this stuff a lot:
Code: [Select]
06 12/13/12 22:48:53.574 Device_Variable::m_szValue_set device: 334 service: urn:upnp-org:serviceId:HouseStatus1 variable: OccupancyState was: Occupied now: Occupied #hooks: 0 upnp: 0 v:0x1010270/NONE duplicate:1 <0x2de4b680>
06 12/13/12 22:48:53.575 Device_Variable::m_szValue_set device: 334 service: urn:upnp-org:serviceId:SwitchPower1 variable: Status was: 1 now: 1 #hooks: 0 upnp: 0 v:0xe7a5e8/NONE duplicate:1 <0x2de4b680>
06 12/13/12 22:48:53.576 Device_Variable::m_szValue_set device: 335 service: urn:upnp-org:serviceId:TemperatureSensor1 variable: CurrentTemperature was: 66 now: 66 #hooks: 0 upnp: 0 v:0xe92828/NONE duplicate:1 <0x2de4b680>
06 12/13/12 22:48:53.577 Device_Variable::m_szValue_set device: 335 service: urn:upnp-org:serviceId:TemperatureSetpoint1_Heat variable: CurrentSetpoint was: 50 now: 50 #hooks: 0 upnp: 0 v:0x106cf80/NONE duplicate:1 <0x2de4b680>
06 12/13/12 22:48:53.577 Device_Variable::m_szValue_set device: 335 service: urn:upnp-org:serviceId:TemperatureSetpoint1_Cool variable: CurrentSetpoint was: 75 now: 75 #hooks: 0 upnp: 0 v:0x106f500/NONE duplicate:1 <0x2de4b680>
06 12/13/12 22:48:53.578 Device_Variable::m_szValue_set device: 335 service: urn:upnp-org:serviceId:HVAC_FanOperatingMode1 variable: Mode was: Auto now: Auto #hooks: 0 upnp: 0 v:0x1057b70/NONE duplicate:1 <0x2de4b680>
06 12/13/12 22:48:53.578 Device_Variable::m_szValue_set device: 335 service: urn:upnp-org:serviceId:HVAC_FanOperatingMode1 variable: FanStatus was: Off now: Off #hooks: 0 upnp: 0 v:0x1057b50/NONE duplicate:1 <0x2de4b680>
06 12/13/12 22:48:53.579 Device_Variable::m_szValue_set device: 335 service: urn:upnp-org:serviceId:HVAC_UserOperatingMode1 variable: ModeStatus was: HeatOn now: HeatOn #hooks: 0 upnp: 0 v:0x1063030/NONE duplicate:1 <0x2de4b680>
06 12/13/12 22:48:53.580 Device_Variable::m_szValue_set device: 335 service: urn:micasaverde-com:serviceId:HVAC_OperatingState1 variable: ModeState was: Idle now: Idle #hooks: 0 upnp: 0 v:0x1061fe8/NONE duplicate:1 <0x2de4b680>
06 12/13/12 22:48:53.580 Device_Variable::m_szValue_set device: 335 service: urn:micasaverde-com:serviceId:HaDevice1 variable: BatteryLevel was: 100 now: 100 #hooks: 0 upnp: 0 v:0xe88910/NONE duplicate:1 <0x2de4b680>
06 12/13/12 22:48:53.581 Device_Variable::m_szValue_set device: 335 service: urn:micasaverde-com:serviceId:HaDevice1 variable: BatteryDate was: 1355463019 now: 1355463019 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0x2de4b680>
06 12/13/12 22:48:53.582 Device_Variable::m_szValue_set device: 336 service: urn:upnp-org:serviceId:TemperatureSensor1 variable: CurrentTemperature was: 65 now: 65 #hooks: 0 upnp: 0 v:0xe92828/NONE duplicate:1 <0x2de4b680>
06 12/13/12 22:48:53.583 Device_Variable::m_szValue_set device: 336 service: urn:upnp-org:serviceId:TemperatureSetpoint1_Heat variable: CurrentSetpoint was: 50 now: 50 #hooks: 0 upnp: 0 v:0x106cf80/NONE duplicate:1 <0x2de4b680>
06 12/13/12 22:48:53.584 Device_Variable::m_szValue_set device: 336 service: urn:upnp-org:serviceId:TemperatureSetpoint1_Cool variable: CurrentSetpoint was: 75 now: 75 #hooks: 0 upnp: 0 v:0x106f500/NONE duplicate:1 <0x2de4b680>
06 12/13/12 22:48:53.584 Device_Variable::m_szValue_set device: 336 service: urn:upnp-org:serviceId:HVAC_FanOperatingMode1 variable: Mode was: Auto now: Auto #hooks: 0 upnp: 0 v:0x1057b70/NONE duplicate:1 <0x2de4b680>
06 12/13/12 22:48:53.585 Device_Variable::m_szValue_set device: 336 service: urn:upnp-org:serviceId:HVAC_FanOperatingMode1 variable: FanStatus was: Off now: Off #hooks: 0 upnp: 0 v:0x1057b50/NONE duplicate:1 <0x2de4b680>
06 12/13/12 22:48:53.585 Device_Variable::m_szValue_set device: 336 service: urn:upnp-org:serviceId:HVAC_UserOperatingMode1 variable: ModeStatus was: HeatOn now: HeatOn #hooks: 0 upnp: 0 v:0x1063030/NONE duplicate:1 <0x2de4b680>


You could change your writeVariable function to do a conditional-set if you wanted to cutdown on the overall log-level output, and write volume.

Offline watou

  • Moderator
  • Hero Member
  • *****
  • Posts: 889
  • Karma: +44/-12
Re: Guidance for nest plugin?
« Reply #36 on: December 14, 2012, 05:00:01 pm »
guessed, I just now saw your post!  I must have gotten unsubscribed from this thread somehow...ugh.....

1. I would like to know what you mean by "on-the-fly" calls to create the child devices.  What is the typical way this is done?  If feasible, I would change my logic to go about device creation the mundane way.

2. My observations of luup.call_timer don't jibe at all with your log output.  In my case, when I call luup.call_timer to run the function in 120 seconds, that's what it does.  How poll() can be called so many times to produce that debug message is mysterious to me.  How can I try to recreate this situation over here?

3. Are you saying that this high rate of polling is constant in your Vera, or that it was observed during startup when it first discovered the devices?

This is potentially a serious issue so I want to track it down sooner rather than later!

Thanks again for your help,
watou

Offline watou

  • Moderator
  • Hero Member
  • *****
  • Posts: 889
  • Karma: +44/-12
Re: Guidance for nest plugin?
« Reply #37 on: December 14, 2012, 05:32:18 pm »
I see in my two calls to luup.call_timer I had omitted the 'days' and 'data' parameters, which I've now added as empty strings, and added the useless 'data' argument to the poll function (just to match the docs exactly).  Not sure if this was screwing up the implementation somehow, but that's changed.
« Last Edit: December 14, 2012, 07:03:07 pm by watou »

Offline watou

  • Moderator
  • Hero Member
  • *****
  • Posts: 889
  • Karma: +44/-12
Re: Guidance for nest plugin?
« Reply #38 on: December 14, 2012, 05:58:40 pm »
Looking at your second log a little closer, it shows that you have (at least) two thermostats (65 degrees in one part of the house and 66 in another part), so the log output doesn't look redundant to me.  I see similar log output from the Heliotrope plugin, showing variable writes every polling cycle.  Wouldn't there be a Luup-wide way to cut down on this type of log message, since it's coming from code I don't control?  My preference would be to control the logging at the source, instead of reworking my code to do my own old/new variable comparisons.  Am I missing something?

Offline watou

  • Moderator
  • Hero Member
  • *****
  • Posts: 889
  • Karma: +44/-12
Re: Guidance for nest plugin?
« Reply #39 on: December 14, 2012, 08:40:05 pm »
My current theory is that there are either some rules I don't know about when it's safe to call the luup.chdev.start/append/sync functions, or there is a bug, like a thread safety issue, that shows up when calling these functions from a luup.call_timer function.  I think plugin code ought to be able to safely call the luup.chdev.start/append/sync functions from any context in the plugin code.  But if it's not, what are the restrictions?

Offline guessed

  • Community Beta
  • Master Member
  • ******
  • Posts: 5301
  • Karma: +92/-22
  • Release compat is not a bolted-on afterthought
Re: Guidance for nest plugin?
« Reply #40 on: December 15, 2012, 12:24:40 pm »
Looking at your second log a little closer, it shows that you have (at least) two thermostats (65 degrees in one part of the house and 66 in another part), so the log output doesn't look redundant to me.  I see similar log output from the Heliotrope plugin, showing variable writes every polling cycle.  Wouldn't there be a Luup-wide way to cut down on this type of log message, since it's coming from code I don't control?  My preference would be to control the logging at the source, instead of reworking my code to do my own old/new variable comparisons.  Am I missing something?
It's not a problem with the two "blocks" of log output here.  My comment was about the contents of each block.

These are shown when running in Verbose mode logging (my machine is permanently locked in this mode).  More recently, when I'm doing luup.variable_set on a polled/periodic basis, I've moved to performing data writes in a conditional if-value-changed manner*.  This greatly cuts down on the number of log-entries that are written as the polling loops execute.

This becomes handy when you have a few plugins polling "largish" amounts of data, on a frequent basis, since the logs don't scroll by quite as fast (and they're not rotated out quite as quickly either)

The first one I did this cutover on was the Brultech.   In that case, it was a little extreme as I had 32 channels of constant value changes, every 5 seconds.  The logs were blowing by at quite a rate.  After that, it was done in the Sonos & SQBlaster for similar reasoning. 

At some point I need to do it in on the Weather Plugin...  ;)

It also makes debugging a lot easier, as you only see output when something changes (which is handy in itself  8) )


* The Lua code we're writing is executed serially, so there really aren't the normal concurrency considerations with doing this sort of thing.

Offline guessed

  • Community Beta
  • Master Member
  • ******
  • Posts: 5301
  • Karma: +92/-22
  • Release compat is not a bolted-on afterthought
Re: Guidance for nest plugin?
« Reply #41 on: December 15, 2012, 12:43:40 pm »
My current theory is that there are either some rules I don't know about when it's safe to call the luup.chdev.start/append/sync functions, or there is a bug, like a thread safety issue, that shows up when calling these functions from a luup.call_timer function.  I think plugin code ought to be able to safely call the luup.chdev.start/append/sync functions from any context in the plugin code.  But if it's not, what are the restrictions?
Historically, luup.chdev.* calls were only made in startup code.  At the end of Startup if something had been structurally changed in the device hierarchy, via luup.chdev commands, then Vera would internally restart the entire startup sequence*

There was supposed to be an internal effort to minimize/reduce/eliminate the need for these restarts (and new-Device restarts in general).  I believe it was originally targeted for UI5, but I'm not sure how far they got with that effort.

Given the above, folks tended to create devices during startup and have [generally] adopted approaches like these:
  • a) Dynamically acquire the relevant information from the dataSource
    This requires making a callout to the dataSource during startup.  The downside here is that you block/slow the overall startup of Vera, and the dataSource must be fully available/performant at the exact time of Vera restart.
  • b) Statically acquire the information from serviceVariables
    This forces the user to do some sort of manual configuration in order to get going.  Things like the DSC put in some default here to give the user an initial experience that they can tailor once they're started.
  • c) Hybridize (a) and (b)
    metaData from the dataSource is acquired "at anytime", but stored in serviceVariables for pickup at the next restart.  The SQBlaster plugin does this to determine whether the user is running a SQBlaster or SQBlaster+ model.  Unfortunately, the user has to go through 2x restart cycles to get the correct data, but this is a one-time deal

There may be other models, but these ones definitely work in both UI4 and UI5.

I wouldn't be surprised if you're running into some sort of on-the-fly creation bug that, in some crazy way, causes the timer-based issues listed above.  I've definitely seen my Vera spontaneously restart the LuaUPnP stack.


* This is not a precise definition, but near enough for the purposes of this discussion.

Offline guessed

  • Community Beta
  • Master Member
  • ******
  • Posts: 5301
  • Karma: +92/-22
  • Release compat is not a bolted-on afterthought
Re: Guidance for nest plugin?
« Reply #42 on: December 15, 2012, 12:46:09 pm »
I see in my two calls to luup.call_timer I had omitted the 'days' and 'data' parameters, which I've now added as empty strings, and added the useless 'data' argument to the poll function (just to match the docs exactly).  Not sure if this was screwing up the implementation somehow, but that's changed.
Ok, I'll wait until that one cycles through the apps store.  There were definitely problems in the past with "undefined" values, and how Vera handled these...or didn't, in some cases  it wasn't handling varArgs stuff correctly and would grab the next bit of memory instead... sometimes with interesting results  8)

Offline watou

  • Moderator
  • Hero Member
  • *****
  • Posts: 889
  • Karma: +44/-12
Re: Guidance for nest plugin?
« Reply #43 on: December 15, 2012, 01:54:23 pm »
The first one I did this cutover on was the Brultech.   In that case, it was a little extreme as I had 32 channels of constant value changes, every 5 seconds.  The logs were blowing by at quite a rate.  After that, it was done in the Sonos & SQBlaster for similar reasoning. 
Thank you for that.  I will take a look at your code and try to replicate the if-value-changed style for writeVariable to cut down on the log output.  I'm using the default logging and it is quite a volume, and I only have the one thermostat.

Offline watou

  • Moderator
  • Hero Member
  • *****
  • Posts: 889
  • Karma: +44/-12
Re: Guidance for nest plugin?
« Reply #44 on: December 15, 2012, 02:02:15 pm »
Historically, luup.chdev.* calls were only made in startup code.  At the end of Startup if something had been structurally changed in the device hierarchy, via luup.chdev commands, then Vera would internally restart the entire startup sequence*
I'm going to have to do a big think on how to tackle this.  Even as the code currently stands, I know it's not right, because I am trying to detect if new devices were added during the poll, and skip out of the poll at that point.  But the code isn't trying to detect if devices were removed, which I presume would also trigger a restart.  And lastly, the next poll is still scheduled even after devices were added or removed, which, if a restart is imminent, then there is no reason to do.  So if I can figure out if the list of devices were changed in any way which would trigger a restart (basically what luup.chdev.sync must know but won't share with the plugin code since it returns nothing), then I can just skip out of the poll code altogether, and not schedule another poll.  Maybe that would quiet it down?  I will experiment...