Honeywell server rejects command when sending commands in high frequency

[plangin]

When changing the temperature too quick, Honewell's server does reject the request.

You get messages like this:

[2018-1-11 08:09:01] [Evohome] Evohome Failed: TypeError: Cannot read property 'userID' of undefined at new UserInfo (/usr/local/lib/node_modules/homebridge-evohome/lib/evohome.js:6:24) at new Session (/usr/local/lib/node_modules/homebridge-evohome/lib/evohome.js:26:18) at /usr/local/lib/node_modules/homebridge-evohome/lib/evohome.js:194:11 at _fulfilled (/usr/local/lib/node_modules/homebridge-evohome/node_modules/q/q.js:787:54) at self.promiseDispatch.done (/usr/local/lib/node_modules/homebridge-evohome/node_modules/q/q.js:816:30) at Promise.promise.promiseDispatch (/usr/local/lib/node_modules/homebridge-evohome/node_modules/q/q.js:749:13) at /usr/local/lib/node_modules/homebridge-evohome/node_modules/q/q.js:557:44 at flush (/usr/local/lib/node_modules/homebridge-evohome/node_modules/q/q.js:108:17) at _combinedTickCallback (internal/process/next_tick.js:131:7) at process._tickCallback (internal/process/next_tick.js:180:9)

Idea for fix: Introduce some kind of communication intervals / delay to avoid server rejections.

I believe to reduce the communications to 2-3 sec. steps would already help. Because when changing the temperature slowly in the GUI (e.g. in Elgato EVE), the server does accept the temperature changes.

[luc-ass]

Hey there. I just published a new version (0.2.0) to NPM. Give it a try. Let me know wether the problem persists.

[plangin]

Tried the new version and everything works great now. Thank you for fixing so fast! I also noticed you changed the target time until next scheduled event. Very nice.

[plangin]

OK, so I was able to break it again: When changing temperatures fast in different rooms, Honeywell's server does still reject access after a certain time / amount of commands. I used Elgato's Eve app to adjust temperatures quickly. Tested with 0.2.2.

Log:

[2018-1-22 09:56:58] [Evohome] The current time is 10:56:58
[2018-1-22 09:56:58] [Evohome] Schedule points for today (Monday)
[2018-1-22 09:56:58] [Evohome] - 00:00:00
[2018-1-22 09:56:58] [Evohome] Setting target temperature for Bad Thermostat to 20° until 00:00:00
[2018-1-22 09:56:58] [Evohome] The current time is 10:56:58
[2018-1-22 09:56:58] [Evohome] Schedule points for today (Monday)
[2018-1-22 09:56:58] [Evohome] - 00:00:00
[2018-1-22 09:56:58] [Evohome] Setting target temperature for WC Thermostat to 15.5° until 00:00:00
[2018-1-22 09:56:58] [Evohome] Successfully changed temperature!
[2018-1-22 09:56:58] [Evohome] { id: '4234717' }
[2018-1-22 09:56:58] [Evohome] Successfully changed temperature!
[2018-1-22 09:56:58] [Evohome] { id: '4234718' }
[2018-1-22 09:57:03] [Evohome] The current time is 10:57:03
[2018-1-22 09:57:03] [Evohome] Schedule points for today (Monday)
[2018-1-22 09:57:03] [Evohome] - 00:00:00
[2018-1-22 09:57:03] [Evohome] Setting target temperature for Arbeitszimmer Thermostat to 18.5° until 00:00:00
[2018-1-22 09:57:03] [Evohome] The current time is 10:57:03
[2018-1-22 09:57:03] [Evohome] Schedule points for today (Monday)
[2018-1-22 09:57:03] [Evohome] - 00:00:00
[2018-1-22 09:57:03] [Evohome] - 20:00:00 -> next change
[2018-1-22 09:57:03] [Evohome] Setting target temperature for Kinderzimmer Thermostat to 15.5° until 20:00:00
[2018-1-22 09:57:03] [Evohome] Successfully changed temperature!
[2018-1-22 09:57:03] [Evohome] { id: '4234740' }
[2018-1-22 09:57:03] [Evohome] Successfully changed temperature!
[2018-1-22 09:57:04] [Evohome] { id: '4234744' }
[2018-1-22 09:57:04] [Evohome] Successfully changed temperature!
[2018-1-22 09:57:04] [Evohome] { id: '4234745' }
[2018-1-22 09:57:07] [Evohome] The current time is 10:57:07
[2018-1-22 09:57:07] [Evohome] Schedule points for today (Monday)
[2018-1-22 09:57:07] [Evohome] - 00:00:00
[2018-1-22 09:57:07] [Evohome] - 23:00:00 -> next change
[2018-1-22 09:57:07] [Evohome] Setting target temperature for Schlafzimmer Thermostat to 19° until 23:00:00
[2018-1-22 09:57:08] [Evohome] The current time is 10:57:08
[2018-1-22 09:57:08] [Evohome] Schedule points for today (Monday)
[2018-1-22 09:57:08] [Evohome] - 00:00:00
[2018-1-22 09:57:08] [Evohome] Setting target temperature for Küche Thermostat to 18° until 00:00:00
[2018-1-22 09:57:08] [Evohome] Successfully changed temperature!
[2018-1-22 09:57:08] [Evohome] { id: '4234767' }
[2018-1-22 09:57:08] [Evohome] Successfully changed temperature!
[2018-1-22 09:57:08] [Evohome] { id: '4234768' }
[2018-1-22 09:57:28] [Evohome] The current time is 10:57:28
[2018-1-22 09:57:28] [Evohome] Schedule points for today (Monday)
[2018-1-22 09:57:28] [Evohome] - 00:00:00
[2018-1-22 09:57:28] [Evohome] Setting target temperature for Küche Thermostat to 16° until 00:00:00
[2018-1-22 09:57:28] [Evohome] Successfully changed temperature!
[2018-1-22 09:57:28] [Evohome] { id: '4234891' }
[2018-1-22 09:57:33] [Evohome] The current time is 10:57:33
[2018-1-22 09:57:33] [Evohome] Setting target temperature for Wohnzimmer Thermostat to 16.5° until
[2018-1-22 09:57:33] [Evohome] The current time is 10:57:33
[2018-1-22 09:57:33] [Evohome] Setting target temperature for Küche Thermostat to 14° until
[2018-1-22 09:57:33] [Evohome] Successfully changed temperature!
[2018-1-22 09:57:33] [Evohome] [ { code: 'Unauthorized', message: 'Unauthorized.' } ]
[2018-1-22 09:57:33] [Evohome] Successfully changed temperature!
[2018-1-22 09:57:33] [Evohome] [ { code: 'Unauthorized', message: 'Unauthorized.' } ]
[2018-1-22 09:57:38] [Evohome] The current time is 10:57:38

Cheers plangin

[fredericvl]

The interval to set a new temperature can be changed in index.js: this.interval_setTemperature = 5; // seconds

By default it's set to 5 seconds, maybe it doesn't need to check each 5 seconds to change the temperature. Can you try changing it to 60 seconds and then try again to simulate this?

In my opinion 60 seconds is still a reasonable value to wait until changing the target temperature.

[plangin]

I set it 60 secs. Looked good in the beginning, in the second round I was able to break it again. Heavy changing on my 9 thermostats led to the "Unauthorized" message.

I'll make further investigations.

Technical question: Does your module create a queue with the latest values (9 ones in my case) and send them to the server? Or does it queue up all the values I selected within 60 secs and batch send all of them?

[fredericvl]

Each zone has a timer (interval you can change), let's say 60 seconds. Then every 60 seconds it will check if a new target has to be send to Honeywell or not. So if you change the target temperature for a zone to 15°C and 10 seconds later to 17°C then it should only send 17°C to Honeywell when the timer hits 60 seconds. (Unless the timer hits 60 seconds between the two changes)

I'm currently working on persisting the Honeywell login session and renew it when it is almost expired. Now it does a login request on each change (not so efficient)... Maybe that will help to mitigate the Unauthorized messages too.

[fredericvl]

I've created a pull request (#26) with the renewal of the session/token instead of signing in each web call request. Maybe you can test again once it's merged back here.

[plangin]

Thank you for your participation here! Great enhancements coming up. I'll test it as soon as possible. (Tried it with 0.2.3. Same behavior.)

[luc-ass]

;) there was a little bug (in my brain)... Version is now 0.3.1. Should work.

[plangin]

... and I'm testing it already. :-)

I stressed it a lot with batch changes in 5 sec. intervals. Worked fine until this hiccup:

[2018-1-23 17:02:14] [Evohome] Successfully changed temperature!
[2018-1-23 17:02:14] [Evohome] { id: '5299537' }
[2018-1-23 17:02:15] [Evohome] Successfully changed temperature!
[2018-1-23 17:02:15] [Evohome] { id: '5299544' }
[2018-1-23 17:02:23] [Evohome] Evohome failed: { Error: getaddrinfo EAI_AGAIN tccna.honeywell.com:443
at Object._errnoException (util.js:1031:13)
at errnoException (dns.js:60:15)
at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:97:26)
errno: 'EAI_AGAIN',
code: 'EAI_AGAIN',
syscall: 'getaddrinfo',
hostname: 'tccna.honeywell.com',
host: 'tccna.honeywell.com',
port: 443 }
[2018-1-23 17:02:23] [Evohome] The current time is 18:02:23
[2018-1-23 17:02:23] [Evohome] Schedule points for today (Tuesday)
[2018-1-23 17:02:23] [Evohome] - 00:00:00
[2018-1-23 17:02:23] [Evohome] Setting target temperature for Wohnzimmer Thermostat to 19° until 00:00:00
[2018-1-23 17:02:23] [Evohome] The current time is 18:02:23
[2018-1-23 17:02:23] [Evohome] Schedule points for today (Tuesday)
[2018-1-23 17:02:23] [Evohome] - 00:00:00
[2018-1-23 17:02:23] [Evohome] - 23:00:00 -> next change

[fredericvl]

Don't think we can do much about that error, it looks like it cannot resolve DNS of honeywell server at some point. (Reference: https://stackoverflow.com/questions/40182121/error-getaddrinfo-eai-again) Is this the only error you get, or do you still have the unauthorized ones?

[plangin]

Sorry for the late feedback.

You are right, looks like a network issue. On the other hand, the 'unauthorized' issues seem to be fixed. :-)

So I'm going to close this issue.