Ecobee - Missing Updates?

I’m currently running openhab 1.8.3 with three thermostats at my house. I have three “program.currentClimateRef” items, one for each thermostat: (1) tDiningRoomCurrentClimate, (2) tMBRCurrentClimate, and (3) tKitchenCurrentClimate. With my configuration set to the default update period, I’m seeing missing updates from different items through the day:

7:30:42 - away for other two
7:33:39 - to away

7:27:36 - 7:33:39 – skipped one update period

2016-06-07 07:21:34 - tDiningRoomCurrentClimate state updated to home
2016-06-07 07:21:34 - tMBRCurrentClimate state updated to home
2016-06-07 07:24:35 - tKitchenCurrentClimate state updated to home
2016-06-07 07:27:36 - tDiningRoomCurrentClimate state updated to home
2016-06-07 07:27:36 - tMBRCurrentClimate state updated to home
2016-06-07 07:27:36 - tKitchenCurrentClimate state updated to home
2016-06-07 07:30:37 - tDiningRoomCurrentClimate state updated to away
2016-06-07 07:30:37 - tMBRCurrentClimate state updated to away
2016-06-07 07:33:39 - tDiningRoomCurrentClimate state updated to away
2016-06-07 07:33:39 - tMBRCurrentClimate state updated to away
2016-06-07 07:33:39 - tKitchenCurrentClimate state updated to away
2016-06-07 07:36:40 - tDiningRoomCurrentClimate state updated to away
2016-06-07 07:36:40 - tMBRCurrentClimate state updated to away
2016-06-07 07:39:42 - tMBRCurrentClimate state updated to away
2016-06-07 07:39:42 - tKitchenCurrentClimate state updated to away
2016-06-07 07:42:43 - tDiningRoomCurrentClimate state updated to away
2016-06-07 07:42:43 - tMBRCurrentClimate state updated to away
2016-06-07 07:42:43 - tKitchenCurrentClimate state updated to away
2016-06-07 07:45:45 - tDiningRoomCurrentClimate state updated to away
2016-06-07 07:45:45 - tMBRCurrentClimate state updated to away
2016-06-07 07:48:45 - tMBRCurrentClimate state updated to away
2016-06-07 07:51:47 - tDiningRoomCurrentClimate state updated to away
2016-06-07 07:51:47 - tMBRCurrentClimate state updated to away
2016-06-07 07:54:48 - tDiningRoomCurrentClimate state updated to away
2016-06-07 07:54:48 - tKitchenCurrentClimate state updated to away
2016-06-07 07:57:49 - tDiningRoomCurrentClimate state updated to away
2016-06-07 07:57:49 - tMBRCurrentClimate state updated to away
2016-06-07 08:00:51 - tDiningRoomCurrentClimate state updated to away
2016-06-07 08:00:51 - tMBRCurrentClimate state updated to away
2016-06-07 08:03:52 - tDiningRoomCurrentClimate state updated to away
2016-06-07 08:03:52 - tMBRCurrentClimate state updated to away
2016-06-07 08:03:52 - tKitchenCurrentClimate state updated to away

For example, at 07:30:37, tKitchenCurrentClimate is not updated. It is updated at 07:33:39, but interestingly a rule that I have setup to trigger on a change to “away” for tKitchenCurrentClimate is not triggered. Thoughts?

I’ve just looked through my MySQL database at the saved climateRefs since February 1, persisting them when they change, for both my Smart SI and ecobee3 thermostats. The only odd thing is that (very rarely) it saved the same climateRef again after its normal scheduled change. This may coincide with me restarting the openHAB server. But it never missed a transition from Feb. 1 through today on either thermostat.

One difference that might exist between our setups is that I have two separate ecobee.com accounts, with one thermostat on one account, and the other thermostat on the other account, running under the single binding but using the ecobee:condo.appkey= syntax example for the second instance. You may have all three of your thermostats under the single account at ecobee.com. I’ve looked just now at the binding code to see if this could possibly be relevant, but I can’t see a reason just yet. Here is the heart of the code, in case you want to have a look yourself.

I don’t know if rules or other configuration could possibly cause an update to be lost. This is completely out of left field, but are you running the Oracle JDK or OpenJDK (Oracle JDK being superior).

Upon reading your post again, is it just that (1) the climate state change doesn’t happen until the poll after the one you expected it to appear, and (2) your rule isn’t triggering? If this is an accurate summary, then (1) is perfectly normal, as there are latencies all along the line from the thermostat to its servers, to the API, to the polling cycle. The infrastructure does eventually catch up, but there may be some normal reason that your kitchen thermostat lags the others sometimes. As for (2), I would have to look at your item and rule definitions (with anything sensitive redacted) in order to offer more advice.

Thank you for the second look, and please allow me to clarify.

Under my setup, all three thermostats are under the same account.

I believe that I am running Oracle JDK based on the following output from java -version:

java version "1.7.0_60"
Java™ SE Runtime Environment (build 1.7.0_60-b19)
Java HotSpot™ Client VM (build 24.60-b09, mixed mode)

My item definitions are as follows:

String tDiningRoomCurrentClimate “[%s]” { ecobee="<[XXX#program.currentClimateRef]" }
String tMBRCurrentClimate “[%s]” { ecobee="=[YYY#program.currentClimateRef]" }
String tKitchenCurrentClimate “[%s]” { ecobee="=[ZZZ#program.currentClimateRef]" }

I have the following trigger for a rule:

when
Item tDiningRoomCurrentClimate changed to “away” OR
Item tMBRCurrentClimate changed to “away” OR
Item tKitchenCurrentClimate changed to "away"
then

This is the “public holiday” rule I posted a little while ago. I wrote the trigger this way so that it will work with multiple thermostats that may or may not the same schedule. If certain conditions are met, the rule goes through and checks each climate item to determine whether it is in the status of “away.” If so, it sets a temporary hold at the “home” climate setting.

The problem I am seeing is that the rule is triggered once at 07:30:37 and the tDiningRoomCurrentClimate and tMBRCurrentClimate item states show as “away” so temporary holds are created at the “home” climate as I would like. tKitchenCurrentClimate is still in the “home” state, so no hold is generated. This would be fine if the rule was triggered again at 07:33:39, which is the time my logs first show tKitchenCurrentClimate in the state “away.” But for some reason the rule is not triggered at that point.

That led me to look through the logs and notice the missing updates. I expect to see three updates every three minutes, but it seems like the tKitchenCurrentClimate update is skipped fairly frequently. And I note that my kitchen items are the last Ecobee items in my .items file. I don’t mind if it takes an additional cycle for the tKitchenCurrentClimate item to update due to latencies in the system, but the issue is that the “changed” trigger is never triggered. That led me to question whether the missing update is a symptom related to the rule not being triggered.

Hi John,

I think you are running the Oracle JDK, so that’s good, and I don’t think having all three thermostats under the one account should make a difference (at least I’ve re-read the code and I don’t see it).

The program.currentClimateRef property is read-only, so it should only be specified with the < character, not the = character. I don’t think it matters for this situation, but just for good measure please change those items to:

String tDiningRoomCurrentClimate "[%s]" { ecobee="<[XXX#program.currentClimateRef]" }
String tMBRCurrentClimate "[%s]" { ecobee="<[YYY#program.currentClimateRef]" }
String tKitchenCurrentClimate "[%s]" { ecobee="<[ZZZ#program.currentClimateRef]" }

I don’t see how your rule’s when clause would not catch the kitchen climate ref changing sometimes but not miss the others, or how the change often comes in on the next poll from the other two tstats would somehow skip triggering the rule.

Just to observe if there is a difference, could you reorder the when clause to put the kitchen above the other tests?

when
Item tKitchenCurrentClimate changed to "away" OR
Item tDiningRoomCurrentClimate changed to "away" OR
Item tMBRCurrentClimate changed to "away"
then

It would be interesting to see if this has any effect on when the rule is triggered.

By “skipped,” I would instead say “didn’t make it into the changes known at the time the binding polled the API.” It’s actually reasonable for this change to not make it into a poll’s update, but to appear a bit later. Since the Ecobee API only supports polling and is not trying to be real-time, the binding can only gather the changes that have been reported and processed by Ecobee’s servers up to the point in time of the poll, any change that just missed being reported into Ecobee’s servers at the time the binding polled ought to be reflected on the next poll, which is 3 minutes later. It looks like this is happening here, or am I wrong?

So my focus would be more on the rule logic, perhaps adding a logInfo call or two or three between the then and the end, just to log what the rule is being triggered by and when.

Thank you. I already had some log lines in place to try to analyze the issue. Here is the entry from 7:30:

2016-06-07 07:30:37.329 [INFO ] [o.model.script.HVAC Controller] - DR: tDiningRoomCurrentClimate (Type=StringItem, State=away) MBR: tMBRCurrentClimate (Type=StringItem, State=away) Kit: tKitchenCurrentClimate (Type=StringItem, State=home)
2016-06-07 07:30:42.344 [INFO ] [o.model.script.HVAC Controller] - DR: tDiningRoomCurrentClimate (Type=StringItem, State=away) MBR: tMBRCurrentClimate (Type=StringItem, State=away) Kit: tKitchenCurrentClimate (Type=StringItem, State=home)

Please note that the rule is actually only triggered once. The second entry is because I added a five second timer with a second log entry to see if there was some sort of delay/race condition causing the issue.

I’ve made the changes to the item definitions so that they are all read-only to see if that makes a difference. I’d like to go through your suggested changes piecemeal to track down exactly what the issue is, rather than make all the changes at once. I’ll keep everyone posted!

1 Like

Today the rule triggered once with all three items in the “away” state, so I can’t tell whether the changes to the item definitions helped:

2016-06-08 07:32:01.077 [INFO ] [o.model.script.HVAC Controller] - DR: tDiningRoomCurrentClimate (Type=StringItem, State=away) MBR: tMBRCurrentClimate (Type=StringItem, State=away) Kit: tKitchenCurrentClimate (Type=StringItem, State=away)
2016-06-08 07:32:06.826 [INFO ] [o.model.script.HVAC Controller] - DR: tDiningRoomCurrentClimate (Type=StringItem, State=away) MBR: tMBRCurrentClimate (Type=StringItem, State=away) Kit: tKitchenCurrentClimate (Type=StringItem, State=away)

That is reflected in the events.log file showing all three items receiving an update at the same time:

2016-06-08 07:32:00 - tDiningRoomCurrentClimate state updated to away
2016-06-08 07:32:00 - tMBRCurrentClimate state updated to away
2016-06-08 07:32:00 - tKitchenCurrentClimate state updated to away
2016-06-08 07:35:02 - tDiningRoomCurrentClimate state updated to away
2016-06-08 07:35:02 - tMBRCurrentClimate state updated to away
2016-06-08 07:38:04 - tDiningRoomCurrentClimate state updated to away
2016-06-08 07:38:04 - tMBRCurrentClimate state updated to away
2016-06-08 07:38:04 - tKitchenCurrentClimate state updated to away
2016-06-08 07:41:06 - tDiningRoomCurrentClimate state updated to away
2016-06-08 07:41:06 - tKitchenCurrentClimate state updated to away
2016-06-08 07:44:08 - tDiningRoomCurrentClimate state updated to away
2016-06-08 07:47:09 - tDiningRoomCurrentClimate state updated to away
2016-06-08 07:47:09 - tMBRCurrentClimate state updated to away
2016-06-08 07:47:09 - tKitchenCurrentClimate state updated to away

Interestingly, tKitchenCurrentClimate is the item that most often does not have an update during polling, but the other items show it as well.

Well, I tracked the error down and it has nothing to do with the Ecobee binding.

The “or” in the trigger section of the rule is case sensitive (feel free to kick me if I should have known this). My previous trigger had a capitalized “OR,” so only the first condition (Item tKitchenCurrentClimate changed to “away”) would trigger the rule:

when
Item tKitchenCurrentClimate changed to “away” OR
Item tDiningRoomCurrentClimate changed to “away” OR
Item tMBRCurrentClimate changed to “away”
then

I observed this by individually flipping each item back and forth between “home” and “away.” The rule was only triggered when I flipped “tKitchenCurrentClimate.” After changing each instance of “OR” to “or,” the rule works when I flip any of the items:

when
Item tDiningRoomCurrentClimate changed to “away” or
Item tMBRCurrentClimate changed to “away” or
Item tKitchenCurrentClimate changed to “away”
then

1 Like

Mystery solved!!! That escaped my notice, too. The openHAB Designer ought to catch that sort of thing. :slight_smile: