search

FlyingDiver / Indigo-Ecobee-2

Ecobee thermostat plugin for Indigo Home Automation System
The Unlicense
0 stars 0 forks source link

token expired #11

Closed smuseby closed 3 years ago

smuseby commented 3 years ago

renewed within last 7(?) days - certainly within last 30 days. Yesterday, from event log:

2020-11-15 19:01:13.985 Ecobee 2 Error Token Refresh Error, error = invalid_request 2020-11-15 19:03:14.396 Ecobee 2 Error Ecobee Account (1428206274): Ecobee Account Update failed, response = '{ "status": { "code": 14, "message": "Authentication token has expired. Refresh your tokens. " } }' 2020-11-15 19:06:14.849 Ecobee 2 Error Ecobee Account (1428206274): Authentication lost, please re-authenticate 2020-11-15 19:11:15.308 Ecobee 2 Error Ecobee Account (1428206274): Authentication lost, please re-authenticate 2020-11-15 19:16:15.820 Ecobee 2 Error Ecobee Account (1428206274): Authentication lost, please re-authenticate

FlyingDiver commented 3 years ago

I would have needed the debug logs from before/after that error to have a chance of figuring it out. Error 3 is some sort of catch-all for bad parameters to the Ecobee API, per: https://www.ecobee.com/home/developer/api/documentation/v1/error-codes.shtml

smuseby commented 3 years ago

I'll turn debug back on.

On Thu, Dec 31, 2020 at 10:17 AM Joe Keenan notifications@github.com wrote:

I would have needed the debug logs from before/after that error to have a chance of figuring it out. Error 3 is some sort of catch-all for bad parameters to the Ecobee API, per: https://www.ecobee.com/home/developer/api/documentation/v1/error-codes.shtml

— You are receiving this because you modified the open/close state. Reply to this email directly, view it on GitHub https://github.com/FlyingDiver/Indigo-Ecobee-2/issues/11#issuecomment-753020519, or unsubscribe https://github.com/notifications/unsubscribe-auth/AH5RS3EFSBOMYJ2E2P3KTFTSXS54LANCNFSM4TXQQORQ .

FlyingDiver commented 3 years ago

And move this to a new issue. It's not a token issue.

smuseby commented 3 years ago

This morning, I discovered on an iOS device that my Ecobee account at home was no longer authenticated. The event log where the failure is first posted, is included below. What I also noticed is that connecting with Indigo on my computer, the device (account) indicates that it is authenticated, while I have the red dot on the iOS indigo, indicating that the device (account) is not authenticated. I am unable to manage the device from Indigo, the indigo device itself shows the settings that would have been consistent with those for when the authentication was lost - I believe the iOS report is accurate, and Indigo/computer is not updating. I have no recollection of anything that I may have done that may have caused this.

2021-01-02 18:09:32.439 Action Group LED fYrd path, hse ON 2021-01-02 19:01:05.493 Ecobee 2 Error Token Refresh Error, error = invalid_request 2021-01-02 19:06:06.687 Ecobee 2 Error Ecobee Account (1428206274): Authentication lost, please re-authenticate

smuseby commented 3 years ago

Home - as in my main residence that is occupied.

FlyingDiver commented 3 years ago

I would just wait a couple hours for it to retry the authentication and see if it's a server problem on their end.

Turning on debug logging in the mean time is a good idea.

FlyingDiver commented 3 years ago

I need to check to see if the code retries after that error. It should.

FlyingDiver commented 3 years ago

Yeah, with that error it should retry every 5 minutes.

FlyingDiver commented 3 years ago

Though I have no idea why Indigo touch shows one status and Indigo client shows a different one. Have you tried restarting the client (not the server)? Or trying the client from a different computer?

FlyingDiver commented 3 years ago

Also, can you check the logs on the Tahoe property and see if it's getting errors?

smuseby commented 3 years ago

debugging turned on, and I am now going to re-authorize the account.

FlyingDiver commented 3 years ago

No! Don't do that

FlyingDiver commented 3 years ago

Are you getting log entries showing it's retrying the authentication on it's own? Is Tahoe still authenticated OK?

smuseby commented 3 years ago

No, and I've restarted it, so I'm afraid it's too late to investigate.

FlyingDiver commented 3 years ago

I don't know how you expect me to figure out the issues when you keep stomping all over the evidence...

smuseby commented 3 years ago

Tahoe log:

Jan 4, 2021 at 15:15:26 Ecobee 2 Debug Ecobee Account (1691628447): Ecobee Account Update OK, got info on 2 thermostats Ecobee 2 Debug Ecobee Account (1691628447): getting data for 'Front Hall', 521703550260 Ecobee 2 Debug Ecobee Account (1691628447): getting data for remote sensor 'North Office', C5SW Ecobee 2 Debug Ecobee Account (1691628447): getting data for 'Stairs', 521781046633 Ecobee 2 Debug Ecobee Account (1691628447): getting data for remote sensor 'Office', C49X Ecobee 2 Debug Ecobee Stairs: Updating device Ecobee 2 Debug Ecobee Stairs Remote - Office: Updating device

Jan 4, 2021 at 15:27:26 Ecobee 2 Debug Token Request with refresh_token = MYG7hdhO9SI-PHLsOYvHAnWtEEWMJfHE1OqxfRAaI3pJS Ecobee 2 Debug Token Refresh OK, new access_token = eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCIsImtpZCI6IlJFWXhNVEpDT0Rnek9UaERRelJHTkRCRlFqZEdNVGxETnpaR1JUZzRNalEwTmtWR01UQkdPQSJ9.eyJpc3MiOiJodHRwczovL2F1dGguZWNvYmVlLmNvbS8iLCJzdWIiOiJhdXRoMHxlNzAyOWMwMi1mYmVlLTQ3NWQtOTNlYS1lNWJkZjJiY2VlYmMiLCJhdWQiOlsiaHR0cHM6Ly9kZXZlbG9wZXItYXBwcy5lY29iZWUuY29tL2FwaS92MSIsImh0dHBzOi8vZWNvYmVlLXByb2QuYXV0aDAuY29tL3VzZXJpbmZvIl0sImlhdCI6MTYwOTgwMjg0NiwiZXhwIjoxNjA5ODA2NDQ2LCJhenAiOiJvcFNNTzZSdG9VbGhvQXRsUWVoTlpkYU9aNkVRQk82USIsInNjb3BlIjoib3BlbmlkIHNtYXJ0V3JpdGUgb2ZmbGluZV9hY2Nlc3MifQ.Ha1CpyykaKrK3O8ZAUCYO99JggB5yaX1ykSc82nfC4HxVZ9tSfqashGo-sgcjhxHU-EAYxuqU1fMiU9BpnQcKYHo27O8otPTqb9UzT0h-nktL4RkKODy0xHLxESAljnm0gToKAZFNNztRqzR4t7D01W_ySQhlsaOajp_2TUAH4WlOzYNhq0W-jIy2fryXGtg6ODv6NAkxcyYa4wZqf3uKxcB899T7jGueBxfdhUIubl7XKlRpvkLxR7H-Ih_Kp63v-OWh_htm07KK3yoPz-hsAyKLkl46OWD9GOaXkG4fa-gIStpOaa7MztuACuEUWPzNtCKEslGCw0XVLBXKClZTA, new refresh_token = MYG7hdhO9SI-PHLsOYvHAnWtEEWMJfHE1OqxfRAaI3pJS, expires_in = 3600

smuseby commented 3 years ago

Sorry - I have the log. What other evidence would you like me to gather for the next crash? - next time, I'll restart the server. Anything else? You're very prompt, so next time, I'll also wait for your approval before restarting. I'm very sorry to be a source of frustration.

FlyingDiver commented 3 years ago

How does the timing of that refresh (and maybe the one before it) line up with the Home system? What I'm really wondering is if the access_token or (more likely) the refresh_token are getting shared between the two systems. Then if they get out of sync, one gets a new refresh token and the other tries to use the old one. If you watch the logs, you'll see that the refresh token doesn't change very often. I added a line of code to check that. Look for:

Ecobee 2 Debug Refresh Token did not change

See, yours is the only setup using this plugin (that I know of) that's using it on two different Indigo servers, with the same Ecobee account. I've always wondered if their system would have problems with two different instances of the same "app" connecting to it.

FlyingDiver commented 3 years ago

And I don't want you to restart the server either. At least not until the plugin retries the authentication a couple of times and gets the same failure. Then restart the plugin and see if there's any change. I doubt restarting the server will do anything different. If all those fail, then it might be appropriate to re-authenticate.

What I really want to see is if there's any "sharing" of access or refresh tokens between the two machines.

smuseby commented 3 years ago

You've mentioned the sharing issue. How can I detect this? I just took the relevant lines from each event log, and aren't the tokens different? Actually, the refresh tokens differ, but the other, sampling only, looks the same. That's some token - I bet even the Russians couldn't break into my thermostat. Whew!

From the Tahoe log:

Jan 4, 2021 at 5:49:01 PM
   Ecobee 2 Debug                  Token Request with refresh_token = iF9WPG7GVf-JSVJ0dxqvlbY0r-wLRVtEDWf4uYc6fD-y5
   Ecobee 2 Debug                  Token Refresh OK, new access_token = eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCIsImtpZCI6IlJFWXhNVEpDT0Rnek9UaERRelJHTkRCRlFqZEdNVGxETnpaR1JUZzRNalEwTmtWR01UQkdPQSJ9.eyJpc3MiOiJodHRwczovL2F1dGguZWNvYmVlLmNvbS8iLCJzdWIiOiJhdXRoMHxlNzAyOWMwMi1mYmVlLTQ3NWQtOTNlYS1lNWJkZjJiY2VlYmMiLCJhdWQiOlsiaHR0cHM6Ly9kZXZlbG9wZXItYXBwcy5lY29iZWUuY29tL2FwaS92MSIsImh0dHBzOi8vZWNvYmVlLXByb2QuYXV0aDAuY29tL3VzZXJpbmZvIl0sImlhdCI6MTYwOTgxMTM0MSwiZXhwIjoxNjA5ODE0OTQxLCJhenAiOiJvcFNNTzZSdG9VbGhvQXRsUWVoTlpkYU9aNkVRQk82USIsInNjb3BlIjoib3BlbmlkIHNtYXJ0V3JpdGUgb2ZmbGluZV9hY2Nlc3MifQ.irPYIEfh4VgvljccUUHzySHCPCxbtPJlwo6akzzGVOpUPFkmgmOKi_cMYwbw9dF1lialv9eC9P-qFznNTlmJ0243CH2N7WeKIz98rxJgeu5VORfK03spZj1wxZUPuOmLnL2X63mxypU6eZTQS1UHqFOhXoYTXGjGrNbt6NO0XHxk0WjYPe5zGBpf04ksnP1cAEgpPR7nM17us6yo4LrR05OQozr5t9flDm2LYZTY1r7St79K0otLMb8cCzx_4iOQAOQH6WEtzqwxGcieiC2V9euMzmT0nWtisp3uFiTqiUbxs39Pzw6iWt1cCRc5MNlglledGgwofjylSF2_4wVeCg, new refresh_token = iF9WPG7GVf-JSVJ0dxqvlbY0r-wLRVtEDWf4uYc6fD-y5, expires_in = 3600

From the Berkeley log:

Jan 4, 2021 at 5:49:01 PM
   Ecobee 2 Debug                  Token Request with refresh_token = iF9WPG7GVf-JSVJ0dxqvlbY0r-wLRVtEDWf4uYc6fD-y5
   Ecobee 2 Debug                  Token Refresh OK, new access_token = eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCIsImtpZCI6IlJFWXhNVEpDT0Rnek9UaERRelJHTkRCRlFqZEdNVGxETnpaR1JUZzRNalEwTmtWR01UQkdPQSJ9.eyJpc3MiOiJodHRwczovL2F1dGguZWNvYmVlLmNvbS8iLCJzdWIiOiJhdXRoMHxlNzAyOWMwMi1mYmVlLTQ3NWQtOTNlYS1lNWJkZjJiY2VlYmMiLCJhdWQiOlsiaHR0cHM6Ly9kZXZlbG9wZXItYXBwcy5lY29iZWUuY29tL2FwaS92MSIsImh0dHBzOi8vZWNvYmVlLXByb2QuYXV0aDAuY29tL3VzZXJpbmZvIl0sImlhdCI6MTYwOTgxMTM0MSwiZXhwIjoxNjA5ODE0OTQxLCJhenAiOiJvcFNNTzZSdG9VbGhvQXRsUWVoTlpkYU9aNkVRQk82USIsInNjb3BlIjoib3BlbmlkIHNtYXJ0V3JpdGUgb2ZmbGluZV9hY2Nlc3MifQ.irPYIEfh4VgvljccUUHzySHCPCxbtPJlwo6akzzGVOpUPFkmgmOKi_cMYwbw9dF1lialv9eC9P-qFznNTlmJ0243CH2N7WeKIz98rxJgeu5VORfK03spZj1wxZUPuOmLnL2X63mxypU6eZTQS1UHqFOhXoYTXGjGrNbt6NO0XHxk0WjYPe5zGBpf04ksnP1cAEgpPR7nM17us6yo4LrR05OQozr5t9flDm2LYZTY1r7St79K0otLMb8cCzx_4iOQAOQH6WEtzqwxGcieiC2V9euMzmT0nWtisp3uFiTqiUbxs39Pzw6iWt1cCRc5MNlglledGgwofjylSF2_4wVeCg, new refresh_token = iF9WPG7GVf-JSVJ0dxqvlbY0r-wLRVtEDWf4uYc6fD-y5, expires_in = 3600
FlyingDiver commented 3 years ago

I need to do an actual string compare, but by eye it looks like both are identical. Which is confirming my suspicion. Keep the debug logs on, and the next time one of them fails, grab the update previous to the failure and see if one changed and the other did not. I suspect that the one that did not change will fail authentication.

FlyingDiver commented 3 years ago

And those tokens are much longer than they used to be. There was an API change last month that changed the format. Since the plugin just stores them as strings, I didn't need to change anything.

FlyingDiver commented 3 years ago

I'm submitting this to Ecobee Developer support now.

One last question (for now) - you're not running a VPN linking the two sites, are you? So that the requests to the Ecobee servers look like they're coming from the same IP address?

smuseby commented 3 years ago

I like your theory. The two sites are linked by a VPN, but each indigo server is on its own LAN IP address. This issue on Github, #11, shows as Closed. - but it doesn't seem to be.

FlyingDiver commented 3 years ago

Yeah, the LAN addresses are different, but the IP address that the Ecobee servers see is the same? Because all VPN traffic is routed through one LAN? Or is only intra-LAN traffic routed over the VPN?

Also, are you doing anything that attempts to synchronize the Indigo installations between the two sites?

I don't have a lot of confidence that Ecobee's going to give me any answers on this. They really don't pay attention to support tickets from developers.

smuseby commented 3 years ago

I understand your question, but not certain how to answer - both sites have a modem, each with its own ISP. Both servers are independent, with no communication between them. Can I help with Ecobee - they do respond to my requests for help. It's convenient when using the website to be able to switch between houses, but should I ask for separate accounts? - happy to do that to get off your back.

FlyingDiver commented 3 years ago

I understand your question, but not certain how to answer - both sites have a modem, each with its own ISP.

How do you have the connecting VPN configured? Is one of the sites (the "secondary") using a "send all traffic" option for the VPN? If so, then all traffic to the internet (from both sites) will look like it's coming from the "primary" site.

should I ask for separate accounts? - happy to do that to get off your back.

It may come down to that, if their system can't differentiate clients.

smuseby commented 3 years ago

I don't see anything like 'send all traffic', but I have no confidence that I know where to look for that sort of setting. (I looked at the VPN and SSL/VPN settings in the router configuration). When someone set the VPN up for me, it was for the express purposes of being able to access one house from the other.

FlyingDiver commented 3 years ago

Yeah, then it's probably not set. That's a common setting when using a VPN with a remote client, to make sure all traffic goes through the VPN. It's not common with a site-to-site VPN like you're using.

Do you have a way to run a browser on the remote machine? Like using Screen Sharing? If so, open a browser on a local and remote machine to this site: https://whatismyipaddress.com

If the results are different, then you're not routing all traffic.

smuseby commented 3 years ago

I don't need to do that. I know they definitely have different IPs because they are dynamic, and I use dyndns.com to access them. They resolve to unique IPs.

FlyingDiver commented 3 years ago

I'm talking to one of the Ecobee support team now. I'm going to have a special version of the plugin for you to run on both machines to make it easier to log just the info we need for this. I'm working on it now and will have it for you tomorrow.

smuseby commented 3 years ago

You're the best, particularly since I'm not always very helpful. I owe you. Thanks.

On Tue, Jan 5, 2021 at 3:00 PM Joe Keenan notifications@github.com wrote:

I'm talking to one of the Ecobee support team now. I'm going to have a special version of the plugin for you to run on both machines to make it easier to log just the info we need for this. I'm working on it now and will have it for you tomorrow.

— You are receiving this because you modified the open/close state. Reply to this email directly, view it on GitHub https://github.com/FlyingDiver/Indigo-Ecobee-2/issues/11#issuecomment-754953183, or unsubscribe https://github.com/notifications/unsubscribe-auth/AH5RS3D25I6VUELV7SFLAX3SYOKYNANCNFSM4TXQQORQ .

FlyingDiver commented 3 years ago

Here's the special version: https://github.com/FlyingDiver/Indigo-Ecobee-2/releases/tag/2.2.8

Install this on both systems, and turn debug logging off. This one writes the info I need to the normal log. That way we're not digging through mountains of debug files, because it might be days before the bug rears it's head.

Re-authenticate both systems too. Best if you disable the plugin in one location, re-authenticate the other, then the reverse. That way the other isn't running during the process. Then enable both and let them run.

smuseby commented 3 years ago

I can't get an ecobee account code for either site. Is this because it is already authenticated? If so, is there a delicate way to de-authenticate?

On Wed, Jan 6, 2021 at 12:59 PM Joe Keenan notifications@github.com wrote:

Here's the special version: https://github.com/FlyingDiver/Indigo-Ecobee-2/releases/tag/2.2.8

Install this on both systems, and turn debug logging off. This one writes the info I need to the normal log. That way we're not digging through mountains of debug files, because it might be days before the bug rears it's head.

Re-authenticate both systems too. Best if you disable the plugin in one location, re-authenticate the other, then the reverse. That way the other isn't running during the process. Then enable both and let them run.

— You are receiving this because you modified the open/close state. Reply to this email directly, view it on GitHub https://github.com/FlyingDiver/Indigo-Ecobee-2/issues/11#issuecomment-755687202, or unsubscribe https://github.com/notifications/unsubscribe-auth/AH5RS3B2W75BLNTGGSSFZHDSYTFLTANCNFSM4TXQQORQ .

smuseby commented 3 years ago

Event log after 'get code' in 'edit device settings' for ecobee account. - the code field remains blank. This looks like my kind of error...

Jan 8, 2021 at 8:04:31 PM Ecobee 2 Error Error in plugin execution UiAction:

Traceback (most recent call last): File "plugin.py", line 592, in request_pin AttributeError: EcobeeAccount instance has no attribute 'dev'

FlyingDiver commented 3 years ago

I just remembered, it's only going to log when the refresh token changes. Ecobee says that shouldn't happen, but obviously there's something going on with your system they don't understand. But it should be easy to find if/when you loose authentication again. If/When it does happen, grab the logs for both systems for a couple hours before that and see if there's anything logged.

smuseby commented 3 years ago

'wrong issue' issue - I thought that github communications should be limited to those of general interest, and was using email client for the others. Guess it doesn't work that way. Sorry.

FlyingDiver commented 3 years ago

When you reply to a GitHub email, it goes into the GitHub issue. All your emails are there.

FlyingDiver commented 3 years ago

Any occurrences in the last week?

smuseby commented 3 years ago

None.

On Fri, Jan 15, 2021 at 10:10 AM Joe Keenan notifications@github.com wrote:

Any occurrences in the last week?

— You are receiving this because you modified the open/close state. Reply to this email directly, view it on GitHub https://github.com/FlyingDiver/Indigo-Ecobee-2/issues/11#issuecomment-761098808, or unsubscribe https://github.com/notifications/unsubscribe-auth/AH5RS3DKRQFHLFKJMHWPHWDS2CAKPANCNFSM4TXQQORQ .

smuseby commented 3 years ago

Power failure / restored this morning. The event log suggests ecobee plugin is working, but I thought you might want to have a look at it:

    Reloading plugin "Ecobee 2 2.3.0"
   Stopping plugin "Ecobee 2 2.3.0" (pid 621)
   Phidgets Plugin Error           interfaceKit: Could not attach to device SBC3. It has been set to offline
   Ecobee 2 Error                  Token Refresh Error, exception = HTTPSConnectionPool(host='api.ecobee.com', port=443): Max retries exceeded with url: /token?grant_type=refresh_token&client_id=opSMO6RtoUlhoAtlQehNZdaOZ6EQBO6Q&refresh_token=1cATx-5Jq-YGNNP7AwDsZtGOxIdkANA9_wocZzheKUJm8&ecobee_type=jwt (Caused by NewConnectionError('<requests.packages.urllib3.connection.VerifiedHTTPSConnection object at 0x10e56ad10>: Failed to establish a new connection: [Errno 8] nodename nor servname provided, or not known',))
   Ecobee 2                        Ecobee Account (1691628447): Stopping EcobeeAccount Device 1691628447
   Ecobee 2                        Ecobee Stairs: Stopping EcobeeThermostat Device 732922513
   Ecobee 2                        Ecobee Stairs Occupancy: Stopping OccupancySensor Device 1968598180
   Ecobee 2                        Ecobee Stairs Remote - Office: Stopping RemoteSensor Device 1206912034
   Ecobee 2                        Stopping Ecobee
   Stopped plugin "Ecobee 2 2.3.0"
   Starting plugin "Ecobee 2 2.3.0" (pid 806)
   Started plugin "Ecobee 2 2.3.0"
   Ecobee 2                        Starting Ecobee
   Ecobee 2                        Ecobee Account (1691628447): Starting EcobeeAccount Device 1691628447
   Ecobee 2                        Ecobee Account (1691628447): EcobeeAccount created using refresh token = 1cATx-5Jq-YGNNP7AwDsZtGOxIdkANA9_wocZzheKUJm8
   Ecobee 2                        Ecobee Stairs: Starting EcobeeThermostat Device 732922513
   Ecobee 2                        Ecobee Stairs Occupancy: Starting OccupancySensor Device 1968598180
   Ecobee 2                        Ecobee Stairs Remote - Office: Starting RemoteSensor Device 1206912034
FlyingDiver commented 3 years ago

Yeah, that looks like a normal error when the Internet connection is down. Specifically it tried to do the DNS lookup for the server name and that failed.

FlyingDiver commented 3 years ago

Not repeating.