Hi everyone,
I had the nest binding previously working on openhab 1.6 with the 1.7 add on.
This weekend I installed openhab 1.7.1 with 1.7.1 add on.
I am using the same item definition that I was using previously but no data is showing up in openhab.
Did anything change in the new version?
Thanks
Check your logs for error messages. I’ve been receiving a lot of `Unable to get state from data model’ error messages the past few days. It is possible Google changed something on their end. I know they announced a new API so maybe they disabled the old one, though I never received notification. that was going to happen. I’ve not had time to research the problem yet.
the logs with 1.7.1 are a bit different. I have looked at the events, openhab and the date logs but nothing is showing up for nest.
This would be in the openhab.log. Search for anything coming from “NestBinding”. If you don’t see anything then perhaps your install of the binding is messed up.
Likewise, in your events.log you should see a line indicating your items are being updated once per polling period. If you don’t see that something is wrong.
To my knowledge, nothing changed with the format of the item binding string.
Thank, will post an update when i get home in the evening.
thought i should post this while i troubleshoot
2015-10-12 17:20:08.859 [WARN ] [b.n.i.messages.AbstractRequest] - Method failed: HTTP/1.1 400 Bad Request
2015-10-12 17:20:08.860 [ERROR] [.o.b.nest.internal.NestBinding] - Error retrieving access token: AccessTokenResponse[accessToken=,expiresIn=,error=oauth2_error,errorDescription=authorization code not found]’
2015-10-12 17:20:08.861 [WARN ] [.o.b.nest.internal.NestBinding] - Periodic poll skipped.
2015-10-12 17:21:10.226 [WARN ] [b.n.i.messages.AbstractRequest] - Method failed: HTTP/1.1 400 Bad Request
2015-10-12 17:21:10.228 [ERROR] [.o.b.nest.internal.NestBinding] - Error retrieving access token: AccessTokenResponse[accessToken=,expiresIn=,error=oauth2_error,errorDescription=authorization code not found]’
2015-10-12 17:21:10.229 [WARN ] [.o.b.nest.internal.NestBinding] - Periodic poll skipped.
2015-10-12 17:21:31.559 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2015-10-12 17:22:10.667 [WARN ] [b.n.i.messages.AbstractRequest] - Method failed: HTTP/1.1 400 Bad Request
2015-10-12 17:22:10.668 [ERROR] [.o.b.nest.internal.NestBinding] - Error retrieving access token: AccessTokenResponse[accessToken=,expiresIn=,error=oauth2_error,errorDescription=authorization code not found]’
2015-10-12 17:22:10.669 [WARN ] [.o.b.nest.internal.NestBinding] - Periodic poll skipped.
2015-10-12 17:23:11.056 [WARN ] [b.n.i.messages.AbstractRequest] - Method failed: HTTP/1.1 400 Bad Request
2015-10-12 17:23:11.058 [ERROR] [.o.b.nest.internal.NestBinding] - Error retrieving access token: AccessTokenResponse[accessToken=,expiresIn=,error=oauth2_error,errorDescription=authorization code not found]’
2015-10-12 17:23:11.058 [WARN ] [.o.b.nest.internal.NestBinding] - Periodic poll skipped.
2015-10-12 17:24:11.474 [WARN ] [b.n.i.messages.AbstractRequest] - Method failed: HTTP/1.1 400 Bad Request
2015-10-12 17:24:11.475 [ERROR] [.o.b.nest.internal.NestBinding] - Error retrieving access token: AccessTokenResponse[accessToken=,expiresIn=,error=oauth2_error,errorDescription=authorization code not found]’
2015-10-12 17:24:11.476 [WARN ] [.o.b.nest.internal.NestBinding] - Periodic poll skipped.
2015-10-12 17:25:11.911 [WARN ] [b.n.i.messages.AbstractRequest] - Method failed: HTTP/1.1 400 Bad Request
2015-10-12 17:25:11.913 [ERROR] [.o.b.nest.internal.NestBinding] - Error retrieving access token: AccessTokenResponse[accessToken=,expiresIn=,error=oauth2_error,errorDescription=authorization code not found]’
2015-10-12 17:25:11.913 [WARN ] [.o.b.nest.internal.NestBinding] - Periodic poll skipped.
2015-10-12 17:26:12.388 [WARN ] [b.n.i.messages.AbstractRequest] - Method failed: HTTP/1.1 400 Bad Request
2015-10-12 17:26:12.390 [ERROR] [.o.b.nest.internal.NestBinding] - Error retrieving access token: AccessTokenResponse[accessToken=,expiresIn=,error=oauth2_error,errorDescription=authorization code not found]’
2015-10-12 17:26:12.390 [WARN ] [.o.b.nest.internal.NestBinding] - Periodic poll skipped.
I think that one of the following might have happened:
ls -al ~/.java and see if you see a .userPrefs directory listed. The auth tokens are stored in an .xml file, one directory below there.nest:client_id, nest:client_secret and nest:pin_code may no longer be pointing at a valid client or hold a valid PIN. If you change permissions in your Nest client, for example, your clients all need new PINs.I did obtain a new pin, actually i have tried 4-5 different new ones. also reset the permissions as mentioned on the binding github page and got another pin but still nothing.
i dont see the .java folder. where is it located? in openhab or raspbian?
edit: so a new pin with a reboot seems to have fixed the issue.
current problem: String hallway_hvac_mode “HVAC Mode” (GF_Hall) {nest="=[thermostats(Hallway).hvac_mode]"}
is not showing up as empty. do i need to change anything? also currently it is showing temp settings in both C and F. do i need to redefine them in the sitemap? currently i have just added them to GF_Hall group.
Glad it sorted itself out.
I don’t know what you mean about the hvac_mode not showing up as empty. It should always show some value. Have a look at the Nest Examples for ideas about how you might want your sitemap to look.
I have a folder that looks like it was named by smashing my hands on the keyboard under .userPrefs and it has the configXML file in that subdirectory. Is that normal?
I never changed anything but I decided to generate a new key anyway. I’m not seeing the error I posted above in the logs any longer.
What is odd is that I never actually made any changes in Nest Developer but I did install the new Nest 5.0 app on my phone. Maybe that cause the binding to get kicked off, as little sense as that makes.
Sorry I meant now. I will pray around with the sitemap tomorrow.
Yes. I think they thought there was a good reason to obfuscate the directory name like that. I just find it annoying.
It’s hard to say, especially in the case of a cloud service. Glad you’re not seeing the error any longer.
Thank goodness for tab completion. 
I spoke too soon. 
The error is back. However, it does seem like I’m getting some data from it during startup and then it craps out with the Unable to update data model message.
When I get a chance I’ll turn up debug logging and see if I can find out more.
On a side note, have you looked into Nest Weave?
Thanks, Rich. If you could send some log samples when you have them, I can see better what might be happening. I suspect the HTTP read timeout is sometimes too short to receive a response, but the logs will help confirm that.
No, not yet; hope to.
Below are my logs showing from startup to the first time the error is generated. I put the logging level on TRACE.
My config has
nest:refresh=300000
I did scrub it of anything that looked like a key, token, etc, replacing the random string with XXX.
2015-10-13 08:18:03.023 [TRACE] [veController$WatchDogTimerTask:1595]- Watchdog: Checking Serial threads
2015-10-13 08:18:13.024 [TRACE] [veController$WatchDogTimerTask:1595]- Watchdog: Checking Serial threads
2015-10-13 08:18:23.024 [TRACE] [veController$WatchDogTimerTask:1595]- Watchdog: Checking Serial threads
2015-10-13 08:18:33.025 [TRACE] [veController$WatchDogTimerTask:1595]- Watchdog: Checking Serial threads
2015-10-13 08:18:43.025 [TRACE] [veController$WatchDogTimerTask:1595]- Watchdog: Checking Serial threads
2015-10-13 08:18:53.025 [TRACE] [veController$WatchDogTimerTask:1595]- Watchdog: Checking Serial threads
2015-10-13 08:19:25.128 [DEBUG] [.b.nest.internal.NestActivator:33 ]- Nest binding has been started.
2015-10-13 08:19:25.148 [TRACE] [n.i.NestGenericBindingProvider:148 ]- validateItemType called with bindingConfig=<[thermostats(Entryway).humidity]
2015-10-13 08:19:25.149 [TRACE] [n.i.NestGenericBindingProvider:157 ]- validateItemType called with property=thermostats(Entryway).humidity
2015-10-13 08:19:25.149 [DEBUG] [n.i.NestGenericBindingProvider:111 ]- Processing binding configuration: '<[thermostats(Entryway).humidity]'
2015-10-13 08:19:25.149 [TRACE] [n.i.NestGenericBindingProvider:148 ]- validateItemType called with bindingConfig=<[thermostats(Entryway).ambient_temperature_f]
2015-10-13 08:19:25.150 [TRACE] [n.i.NestGenericBindingProvider:157 ]- validateItemType called with property=thermostats(Entryway).ambient_temperature_f
2015-10-13 08:19:25.150 [DEBUG] [n.i.NestGenericBindingProvider:111 ]- Processing binding configuration: '<[thermostats(Entryway).ambient_temperature_f]'
2015-10-13 08:19:25.150 [TRACE] [n.i.NestGenericBindingProvider:148 ]- validateItemType called with bindingConfig==[thermostats(Entryway).target_temperature_f]
2015-10-13 08:19:25.150 [TRACE] [n.i.NestGenericBindingProvider:157 ]- validateItemType called with property=thermostats(Entryway).target_temperature_f
2015-10-13 08:19:25.151 [DEBUG] [n.i.NestGenericBindingProvider:111 ]- Processing binding configuration: '=[thermostats(Entryway).target_temperature_f]'
2015-10-13 08:19:25.151 [TRACE] [n.i.NestGenericBindingProvider:148 ]- validateItemType called with bindingConfig==[structures(Home).away]
2015-10-13 08:19:25.151 [TRACE] [n.i.NestGenericBindingProvider:157 ]- validateItemType called with property=structures(Home).away
2015-10-13 08:19:25.151 [DEBUG] [n.i.NestGenericBindingProvider:111 ]- Processing binding configuration: '=[structures(Home).away]'
2015-10-13 08:19:25.152 [TRACE] [n.i.NestGenericBindingProvider:148 ]- validateItemType called with bindingConfig==[thermostats(Entryway).fan_timer_active]
2015-10-13 08:19:25.152 [TRACE] [n.i.NestGenericBindingProvider:157 ]- validateItemType called with property=thermostats(Entryway).fan_timer_active
2015-10-13 08:19:25.152 [DEBUG] [n.i.NestGenericBindingProvider:111 ]- Processing binding configuration: '=[thermostats(Entryway).fan_timer_active]'
2015-10-13 08:19:25.153 [TRACE] [n.i.NestGenericBindingProvider:148 ]- validateItemType called with bindingConfig=<[thermostats(Entryway).is_online]
2015-10-13 08:19:25.153 [TRACE] [n.i.NestGenericBindingProvider:157 ]- validateItemType called with property=thermostats(Entryway).is_online
2015-10-13 08:19:25.153 [DEBUG] [n.i.NestGenericBindingProvider:111 ]- Processing binding configuration: '<[thermostats(Entryway).is_online]'
2015-10-13 08:19:26.072 [TRACE] [.o.b.nest.internal.NestBinding:128 ]- Querying Nest API
2015-10-13 08:19:26.321 [TRACE] [b.n.i.messages.AbstractRequest:125 ]- About to execute 'https://developer-api.nest.com/?auth=XXX
2015-10-13 08:19:27.168 [TRACE] [b.n.i.messages.AbstractRequest:166 ]- {"devices":{"thermostats":{"XXX":{"humidity":30,"locale":"en-US","temperature_scale":"F","is_using_emergency_heat":false,"has_fan":true,"software_version":"4.5.1","has_leaf":true,"device_id":"XXX","name":"Entryway","can_heat":true,"can_cool":false,"hvac_mode":"heat","target_temperature_c":16.5,"target_temperature_f":63,"target_temperature_high_c":24.0,"target_temperature_high_f":75,"target_temperature_low_c":20.0,"target_temperature_low_f":68,"ambient_temperature_c":17.0,"ambient_temperature_f":63,"away_temperature_high_c":24.0,"away_temperature_high_f":76,"away_temperature_low_c":10.0,"away_temperature_low_f":50,"structure_id":"XXX","fan_timer_active":false,"name_long":"Entryway Thermostat","is_online":true,"last_connection":"2015-10-13T14:09:37.256Z"}}},"structures":{"XXX":{"name":"XXX","country_code":"US","postal_code":"80921","time_zone":"America/Denver","away":"home","thermostats":["XXX"],"structure_id":"XXX"}},"metadata":{"access_token":"XXX","client_version":1}}
2015-10-13 08:19:27.323 [TRACE] [.o.b.nest.internal.NestBinding:175 ]- Updating itemName 'S_V_NestTargetTemp' with newState '63'
2015-10-13 08:19:27.323 [TRACE] [.o.b.nest.internal.NestBinding:182 ]- Added event (item='S_V_NestTargetTemp', newState='63') to the ignore event list
2015-10-13 08:19:27.323 [TRACE] [.o.b.nest.internal.NestBinding:175 ]- Updating itemName 'S_C_NestFan' with newState 'OFF'
2015-10-13 08:19:27.323 [TRACE] [.o.b.nest.internal.NestBinding:265 ]- Received update (item='S_V_NestTargetTemp', state='63')
2015-10-13 08:19:27.324 [TRACE] [.o.b.nest.internal.NestBinding:182 ]- Added event (item='S_C_NestFan', newState='OFF') to the ignore event list
2015-10-13 08:19:27.324 [DEBUG] [.o.b.nest.internal.NestBinding:288 ]- We received this event (item='S_V_NestTargetTemp', state='63') from Nest, so we don't send it back again -> ignore!
2015-10-13 08:19:27.324 [TRACE] [.o.b.nest.internal.NestBinding:175 ]- Updating itemName 'N_V_NestHumidity' with newState '30'
2015-10-13 08:19:27.324 [TRACE] [.o.b.nest.internal.NestBinding:182 ]- Added event (item='N_V_NestHumidity', newState='30') to the ignore event list
2015-10-13 08:19:27.325 [TRACE] [.o.b.nest.internal.NestBinding:175 ]- Updating itemName 'N_V_NestCurrTemp' with newState '63'
2015-10-13 08:19:27.325 [TRACE] [.o.b.nest.internal.NestBinding:182 ]- Added event (item='N_V_NestCurrTemp', newState='63') to the ignore event list
2015-10-13 08:19:27.325 [TRACE] [.o.b.nest.internal.NestBinding:265 ]- Received update (item='S_C_NestFan', state='OFF')
2015-10-13 08:19:27.326 [DEBUG] [.o.b.nest.internal.NestBinding:288 ]- We received this event (item='S_C_NestFan', state='OFF') from Nest, so we don't send it back again -> ignore!
2015-10-13 08:19:27.327 [TRACE] [.o.b.nest.internal.NestBinding:265 ]- Received update (item='N_V_NestHumidity', state='30')
2015-10-13 08:19:27.328 [DEBUG] [.o.b.nest.internal.NestBinding:288 ]- We received this event (item='N_V_NestHumidity', state='30') from Nest, so we don't send it back again -> ignore!
2015-10-13 08:19:27.329 [TRACE] [.o.b.nest.internal.NestBinding:265 ]- Received update (item='N_V_NestCurrTemp', state='63')
2015-10-13 08:19:27.329 [ERROR] [.o.b.nest.internal.NestBinding:206 ]- Unable to get state from data model
org.apache.commons.beanutils.NestedNullException: Null property value for 'structures(Home).away' on bean class 'class org.openhab.binding.nest.internal.messages.DataModelResponse'
at org.apache.commons.beanutils.PropertyUtilsBean.getNestedProperty(PropertyUtilsBean.java:755) ~[commons-beanutils-1.8.3.jar:1.8.3]
at org.apache.commons.beanutils.PropertyUtilsBean.getProperty(PropertyUtilsBean.java:846) ~[commons-beanutils-1.8.3.jar:1.8.3]
at org.openhab.binding.nest.internal.messages.DataModel.getProperty(DataModel.java:302) ~[bundlefile:na]
at org.openhab.binding.nest.internal.NestBinding.getState(NestBinding.java:204) [bundlefile:na]
at org.openhab.binding.nest.internal.NestBinding.readNest(NestBinding.java:173) [bundlefile:na]
at org.openhab.binding.nest.internal.NestBinding.execute(NestBinding.java:141) [bundlefile:na]
at org.openhab.core.binding.AbstractActiveBinding$BindingActiveService.execute(AbstractActiveBinding.java:156) [org.openhab.core_1.7.1.jar:na]
at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:173) [org.openhab.core_1.7.1.jar:na]
2015-10-13 08:19:27.330 [DEBUG] [.o.b.nest.internal.NestBinding:288 ]- We received this event (item='N_V_NestCurrTemp', state='63') from Nest, so we don't send it back again -> ignore!
2015-10-13 08:19:27.330 [TRACE] [.o.b.nest.internal.NestBinding:175 ]- Updating itemName 'S_C_NestAway' with newState 'Uninitialized'
2015-10-13 08:19:27.330 [TRACE] [.o.b.nest.internal.NestBinding:182 ]- Added event (item='S_C_NestAway', newState='Uninitialized') to the ignore event list
2015-10-13 08:19:27.331 [TRACE] [.o.b.nest.internal.NestBinding:175 ]- Updating itemName 'N_NestOnline' with newState 'ON'
2015-10-13 08:19:27.331 [TRACE] [.o.b.nest.internal.NestBinding:182 ]- Added event (item='N_NestOnline', newState='ON') to the ignore event list
2015-10-13 08:19:27.331 [TRACE] [.o.b.nest.internal.NestBinding:265 ]- Received update (item='S_C_NestAway', state='Uninitialized')
2015-10-13 08:19:27.332 [DEBUG] [.o.b.nest.internal.NestBinding:288 ]- We received this event (item='S_C_NestAway', state='Uninitialized') from Nest, so we don't send it back again -> ignore!
2015-10-13 08:19:27.334 [TRACE] [.o.b.nest.internal.NestBinding:265 ]- Received update (item='N_NestOnline', state='ON')
2015-10-13 08:19:27.334 [DEBUG] [.o.b.nest.internal.NestBinding:288 ]- We received this event (item='N_NestOnline', state='ON') from Nest, so we don't send it back again -> ignore!Hi Rich,
I would say that either 1) the name of your structure is not “Home” but is set to some other string, or, less likely, 2) your client at developer.nest.com is not authorized for the “Away read/write v1” permission. It looks like the only binding config string that’s not working is "<[structures(Home).away]", and it’s the only one referencing the structure.
Let me know if it’s neither option and I will look some more.
John
Indeed, the structure name was wrong. I while back I installed an update to Nest that went bad and I had to reconfigure everything, including the name. I must have picked a different name at that time and never noticed that it was causing errors in opneHAB until recently.
Thanks!
Rich
Glad there was a fix, Rich!
I’ve got a similar problem to this thread. I’m running openhab 1.8 on a Mac. I’m trying the Nest binding example at https://github.com/openhab/openhab/wiki/Nest-Binding-Example
In openhab.cfg I’ve got:
#
# the Nest Client ID needed to use the API, must be supplied
nest:client_id=2c4c4adb-d90a-4bf6-a480-9002c00a1xxx
# the Nest Client Secret needed to use the API, must be supplied
nest:client_secret=wfBRy8zdAdfWccxTtAusKXxxx
# the PIN code that Nest presented when you authorized the above client, must be supplied
nest:pin_code=V946Txxx
But in the log I see:
2016-03-15 18:23:50.347 [WARN ] [b.n.i.messages.AbstractRequest] - Method failed: HTTP/1.1 400 Bad Request
2016-03-15 18:23:50.347 [ERROR] [.o.b.nest.internal.NestBinding] - Error retrieving access token: AccessTokenResponse[accessToken=,expiresIn=,error=oauth2_error,errorDescription=authorization code not found]'
2016-03-15 18:23:50.348 [WARN ] [.o.b.nest.internal.NestBinding] - Periodic poll skipped.
Any suggestions? The credentials and pin seem right to me but it looks like a login error. In an earlier post someone suggested a persistence issue? I haven’t touched the persistence from the demo code.
Thanks, Jim
Hi Jim, I recommend making sure you exactly copied the client_id, client_secret and pin_code into openhab.cfg. Also make sure that there are no leading or trailing whitespace characters on any lines in openhab.cfg.
If you have verified all of that, then try the step to generate a new pin_code and paste that in place of the previous pin_code value in openhab.cfg, stop and restart openHAB. The binding will get try to get a new access token if it sees that you changed the PIN.