Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Tesla] binding going offline permanently every day #11636

Open
ipweb2000 opened this issue Nov 24, 2021 · 11 comments
Open

[Tesla] binding going offline permanently every day #11636

ipweb2000 opened this issue Nov 24, 2021 · 11 comments
Labels
awaiting feedback bug An unexpected problem or unintended behavior of an add-on stale As soon as a PR is marked stale, it can be removed 6 months later.

Comments

@ipweb2000
Copy link

Current Behavior

Hey There. Love the Tesla Binding but it goes offline roughly every single or second day. Tried both username as well as generated refresh token. Only thing that helps is to restart the binding. Using 3.1.0.

Your Environment

  • Version used: (e.g., openHAB and add-on versions)
  • Environment name and version (e.g. Chrome 76, Java 8, Node.js 12.9, ...):
  • Operating System and version (desktop or mobile, Windows 10, Raspbian Buster, ...):
  • openHAB 3.1.0
  • RPi 4B, 8GB
  • Raspbian Buster
@ipweb2000 ipweb2000 added the bug An unexpected problem or unintended behavior of an add-on label Nov 24, 2021
@logos37
Copy link

logos37 commented Jan 6, 2022

Hi everybody, have the same is also with OH3.2
Any news on that?

@kaikreuzer
Copy link
Member

kaikreuzer commented Jan 11, 2022

Might this be a duplicate of #10264? Have you checked your log files?

@logos37
Copy link

logos37 commented Jan 12, 2022

@kaikreuzer: thanks to take a look a this. My logfile looks like this( WARN and ERROR messages are repeated thereafter):

2022-01-12 06:12:07.625 [WARN ] [internal.handler.TeslaAccountHandler] - Reached the maximum number of errors (2) for the current interval (15 seconds)
2022-01-12 06:12:07.630 [DEBUG] [internal.handler.TeslaAccountHandler] - An error occurred while communicating with the vehicle during request drive_state: 401:org.apache.cxf.jaxrs.impl.ResponseImpl$1@f5cfab
2022-01-12 06:12:12.938 [DEBUG] [internal.handler.TeslaAccountHandler] - Setting up an authenticated connection to the Tesla back-end
2022-01-12 06:12:12.955 [DEBUG] [internal.handler.TeslaAccountHandler] - Found a request token created at 2022-01-11 07:46:12
2022-01-12 06:12:13.184 [ERROR] [internal.handler.TeslaAccountHandler] - Error fetching the list of vehicles : 401:org.apache.cxf.jaxrs.impl.ResponseImpl$1@1eccc3c
2022-01-12 06:12:21.154 [DEBUG] [internal.handler.TeslaVehicleHandler] - Querying the vehicle : Response : 401:org.apache.cxf.jaxrs.impl.ResponseImpl$1@74331f
2022-01-12 06:12:21.308 [WARN ] [internal.handler.TeslaVehicleHandler] - Got an unsuccessful result, setting vehicle to offline and will try again
2022-01-12 06:12:21.311 [ERROR] [internal.handler.TeslaVehicleHandler] - An error occurred while querying the vehicle
2022-01-12 06:12:28.191 [DEBUG] [internal.handler.TeslaAccountHandler] - Setting up an authenticated connection to the Tesla back-end
2022-01-12 06:12:28.203 [DEBUG] [internal.handler.TeslaAccountHandler] - Found a request token created at 2022-01-11 07:46:12
2022-01-12 06:12:28.446 [ERROR] [internal.handler.TeslaAccountHandler] - Error fetching the list of vehicles : 401:org.apache.cxf.jaxrs.impl.ResponseImpl$1@17562d5
2022-01-12 06:12:43.453 [DEBUG] [internal.handler.TeslaAccountHandler] - Setting up an authenticated connection to the Tesla back-end
2022-01-12 06:12:43.457 [DEBUG] [internal.handler.TeslaAccountHandler] - Found a request token created at 2022-01-11 07:46:12
2022-01-12 06:12:43.699 [ERROR] [internal.handler.TeslaAccountHandler] - Error fetching the list of vehicles : 401:org.apache.cxf.jaxrs.impl.ResponseImpl$1@b0fa1b
2022-01-12 06:12:58.702 [DEBUG] [internal.handler.TeslaAccountHandler] - Setting up an authenticated connection to the Tesla back-end
2022-01-12 06:12:58.845 [DEBUG] [internal.handler.TeslaAccountHandler] - Found a request token created at 2022-01-11 07:46:12
2022-01-12 06:12:59.112 [ERROR] [internal.handler.TeslaAccountHandler] - Error fetching the list of vehicles : 401:org.apache.cxf.jaxrs.impl.ResponseImpl$1@328025
2022-01-12 06:13:14.117 [DEBUG] [internal.handler.TeslaAccountHandler] - Setting up an authenticated connection to the Tesla back-end
2022-01-12 06:13:14.120 [DEBUG] [internal.handler.TeslaAccountHandler] - Found a request token created at 2022-01-11 07:46:12
2022-01-12 06:13:14.356 [ERROR] [internal.handler.TeslaAccountHandler] - Error fetching the list of vehicles : 401:org.apache.cxf.jaxrs.impl.ResponseImpl$1@a6fd5c
2022-01-12 06:13:21.529 [DEBUG] [internal.handler.TeslaVehicleHandler] - Querying the vehicle : Response : 401:org.apache.cxf.jaxrs.impl.ResponseImpl$1@dff0f1
2022-01-12 06:13:21.542 [WARN ] [internal.handler.TeslaVehicleHandler] - Got an unsuccessful result, setting vehicle to offline and will try again
2022-01-12 06:13:21.546 [ERROR] [internal.handler.TeslaVehicleHandler] - An error occurred while querying the vehicle
2022-01-12 06:13:29.360 [DEBUG] [internal.handler.TeslaAccountHandler] - Setting up an authenticated connection to the

any hints on this issue?

@kaikreuzer
Copy link
Member

What would be of most interest are the lines in the log before "Reached the maximum number of errors" entry. 😄

@logos37
Copy link

logos37 commented Jan 13, 2022

@kaikreuzer Thanks for the reply and yes that would be of biggest interest, but there are no ERROR messages before, at least for more then half an hour before (not even speaking about 15 seconds). See below the messages before the first WARN (there are only DEBUG entries)

2022-01-12 06:09:36.711 [DEBUG] [internal.handler.TeslaVehicleHandler] - Vehicle is neither charging nor moving, skipping updates to allow it to sleep
2022-01-12 06:09:51.716 [DEBUG] [internal.handler.TeslaVehicleHandler] - Vehicle is neither charging nor moving, skipping updates to allow it to sleep
2022-01-12 06:10:06.858 [DEBUG] [internal.handler.TeslaVehicleHandler] - Vehicle is neither charging nor moving, skipping updates to allow it to sleep
2022-01-12 06:10:20.625 [DEBUG] [internal.handler.TeslaVehicleHandler] - Querying the vehicle : Response : 200:org.apache.cxf.jaxrs.impl.ResponseImpl$1@b4a40a
2022-01-12 06:10:20.646 [DEBUG] [internal.handler.TeslaVehicleHandler] - Querying the vehicle: VIN 5YJSA7H23FFP76556
2022-01-12 06:10:20.654 [DEBUG] [internal.handler.TeslaVehicleHandler] - Vehicle did not fall asleep within sleep period, checking again
2022-01-12 06:10:20.660 [DEBUG] [internal.handler.TeslaAccountHandler] - Invoking: charge_state
2022-01-12 06:10:20.660 [DEBUG] [internal.handler.TeslaAccountHandler] - Invoking: climate_state
2022-01-12 06:10:21.662 [DEBUG] [internal.handler.TeslaAccountHandler] - Invoking: gui_settings
2022-01-12 06:10:22.663 [DEBUG] [internal.handler.TeslaAccountHandler] - Invoking: mobile_enabled
2022-01-12 06:10:23.664 [DEBUG] [internal.handler.TeslaAccountHandler] - Invoking: drive_state
2022-01-12 06:10:24.125 [DEBUG] [internal.handler.TeslaVehicleHandler] - Vehicle moved, resetting last location timestamp
2022-01-12 06:10:24.665 [DEBUG] [internal.handler.TeslaAccountHandler] - Invoking: vehicle_state
2022-01-12 06:10:36.996 [DEBUG] [internal.handler.TeslaAccountHandler] - Invoking: drive_state
2022-01-12 06:10:37.996 [DEBUG] [internal.handler.TeslaAccountHandler] - Invoking: vehicle_state
2022-01-12 06:10:51.996 [DEBUG] [internal.handler.TeslaAccountHandler] - Invoking: drive_state
2022-01-12 06:10:52.998 [DEBUG] [internal.handler.TeslaAccountHandler] - Invoking: vehicle_state
2022-01-12 06:11:06.997 [DEBUG] [internal.handler.TeslaAccountHandler] - Invoking: drive_state
2022-01-12 06:11:07.998 [DEBUG] [internal.handler.TeslaAccountHandler] - Invoking: vehicle_state
2022-01-12 06:11:20.899 [DEBUG] [internal.handler.TeslaVehicleHandler] - Querying the vehicle : Response : 200:org.apache.cxf.jaxrs.impl.ResponseImpl$1@fac70a
2022-01-12 06:11:20.920 [DEBUG] [internal.handler.TeslaVehicleHandler] - Querying the vehicle: VIN 5YJSA7H23FFP76556
2022-01-12 06:11:20.927 [DEBUG] [internal.handler.TeslaAccountHandler] - Invoking: charge_state
2022-01-12 06:11:20.928 [DEBUG] [internal.handler.TeslaAccountHandler] - Invoking: climate_state
2022-01-12 06:11:21.929 [DEBUG] [internal.handler.TeslaAccountHandler] - Invoking: gui_settings
2022-01-12 06:11:22.930 [DEBUG] [internal.handler.TeslaAccountHandler] - Invoking: mobile_enabled
2022-01-12 06:11:23.930 [DEBUG] [internal.handler.TeslaAccountHandler] - Invoking: drive_state
2022-01-12 06:11:24.931 [DEBUG] [internal.handler.TeslaAccountHandler] - Invoking: vehicle_state
2022-01-12 06:11:36.997 [DEBUG] [internal.handler.TeslaAccountHandler] - Invoking: drive_state
2022-01-12 06:11:37.999 [DEBUG] [internal.handler.TeslaAccountHandler] - Invoking: vehicle_state
2022-01-12 06:11:51.998 [DEBUG] [internal.handler.TeslaAccountHandler] - Invoking: drive_state
2022-01-12 06:11:52.999 [DEBUG] [internal.handler.TeslaAccountHandler] - Invoking: vehicle_state
2022-01-12 06:12:06.998 [DEBUG] [internal.handler.TeslaAccountHandler] - Invoking: drive_state
2022-01-12 06:12:07.625 [WARN ] [internal.handler.TeslaAccountHandler] - Reached the maximum number of errors (2) for the current interval (15 seconds)

Somehow strange....Do you have any ideas? Thanks in advance for your suppoert on this

@ipweb2000
Copy link
Author

Some details in my case when it goes offline every other day or so. I see error message below. Restarting the binding sometimes helps. Sometimes it doesn't but then I can open the Tesla Account thing and click "save" and both account and Car thing come online again. FYI - I have generated a refresh token from a helper app and put it in the account thing (plus my account name + password as well).

09:19:43.123 [DEBUG] [.internal.handler.TeslaAccountHandler] - Setting up an authenticated connection to the Tesla back-end
09:19:43.126 [DEBUG] [esla.internal.handler.TeslaSSOHandler] - Exchanging SSO refresh token for API access token
09:19:43.130 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'tesla:account:94f3fb05' changed from INITIALIZING to UNKNOWN
09:19:43.135 [DEBUG] [esla.internal.handler.TeslaSSOHandler] - An exception occurred while invoking a HTTP request: 'java.io.EOFException: HttpConnectionOverHTTP@1e69f94::DecryptedEndPoint@130786a{l=/192.168.178.6:34140,r=auth.tesla.com/184.50.116.96:443,OPEN,fill=-,flush=-,to=130075432/0}'
09:19:43.137 [DEBUG] [esla.internal.handler.TeslaSSOHandler] - An error occurred during refresh of SSO token: no response
09:19:43.141 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'tesla:account:94f3fb05' changed from UNKNOWN to OFFLINE (CONFIGURATION_ERROR): Failed to obtain access token for API.
09:19:43.143 [INFO ] [hab.event.ThingStatusInfoChangedEvent] - Thing 'tesla:account:94f3fb05' changed from OFFLINE (CONFIGURATION_ERROR): Failed to obtain access token for API. to OFFLINE (CONFIGURATION_ERROR)

Any thoughts? Thanks a lot. Patrick

@Dbzman
Copy link
Contributor

Dbzman commented Apr 30, 2022

I've had the same issue that the binding goes offline after a couple of days. After upgrading to 3.3.0.M3 I don't see any errors anymore, but the binding still refuses to work after a couple of days. Those are my last logs:

2022-04-29 17:58:06.340 [DEBUG] [internal.handler.TeslaVehicleHandler] - Querying the vehicle, response : 401, Unauthorized
2022-04-29 17:58:06.341 [DEBUG] [internal.handler.TeslaVehicleHandler] - The access token has expired, trying to get a new one.
2022-04-29 17:58:06.342 [DEBUG] [internal.handler.TeslaAccountHandler] - Found a request token created at 2022-04-29 09:57:54
2022-04-29 17:58:06.344 [DEBUG] [internal.handler.TeslaAccountHandler] - The token has expired at 2022-04-29 10:26:42
2022-04-29 17:58:06.345 [DEBUG] [sla.internal.handler.TeslaSSOHandler] - Exchanging SSO refresh token for API access token
2022-04-29 17:58:06.360 [DEBUG] [sla.internal.handler.TeslaSSOHandler] - An exception occurred while invoking a HTTP request: 'java.io.EOFException: HttpConnectionOverHTTP@1ee1f4d::DecryptedEndPoint@be407{l=/192.168.178.56:59734,r=auth.tesla.com/184.30.223.10:443,OPEN,fill=-,flush=-,to=28812016/0}'
2022-04-29 17:58:06.361 [DEBUG] [sla.internal.handler.TeslaSSOHandler] - An error occurred during refresh of SSO token: no response
2022-04-29 17:58:06.362 [DEBUG] [internal.handler.TeslaVehicleHandler] - An error occurred while querying the vehicle

The bridge and car are still marked as ONLINE, though, but no updates are incoming anymore. (and no logs as well) My guess is that #12530 broke the retry mechanism and error handling, somehow. (That PR seems to be the only recent one related to calling the API)

@oOMagicOo
Copy link

oOMagicOo commented Jul 25, 2022

I have exactly the same behaviour as @Dbzman. Binding remains online but does not report any values after some while. Also could trace it down to the following:

2022-07-25 15:59:07.315 [TRACE] [internal.handler.TeslaVehicleHandler] - Vehicle is id **hidden**/vehicle_id **hidden**/tokens [**********, **********]
2022-07-25 15:59:07.317 [TRACE] [internal.handler.TeslaVehicleHandler] - The variable/value pair 'display_name':'"M3"' is successfully used to set property 'name'
2022-07-25 15:59:07.318 [TRACE] [internal.handler.TeslaVehicleHandler] - The variable/value pair 'id':'"**********"' is not (yet) supported
2022-07-25 15:59:07.319 [TRACE] [internal.handler.TeslaVehicleHandler] - The variable/value pair 'vehicle_id':'"1689167514******"' is not (yet) supported
2022-07-25 15:59:07.320 [TRACE] [internal.handler.TeslaVehicleHandler] - The variable/value pair 'vin':'"LRW3*********"' is successfully used to set property 'vin'
2022-07-25 15:59:07.321 [TRACE] [internal.handler.TeslaVehicleHandler] - The variable/value pair 'tokens':'["*********","**********"]' is not (yet) supported
2022-07-25 15:59:07.322 [TRACE] [internal.handler.TeslaVehicleHandler] - The variable/value pair 'state':'"asleep"' is successfully processed
2022-07-25 15:59:07.323 [TRACE] [internal.handler.TeslaVehicleHandler] - The variable/value pair 'remote_start_enabled':'false' is successfully processed
2022-07-25 15:59:07.325 [TRACE] [internal.handler.TeslaVehicleHandler] - The variable/value pair 'calendar_enabled':'true' is successfully processed
2022-07-25 15:59:07.326 [TRACE] [internal.handler.TeslaVehicleHandler] - The variable/value pair 'notifications_enabled':'false' is successfully processed
2022-07-25 16:00:17.632 [DEBUG] [internal.handler.TeslaVehicleHandler] - Querying the vehicle, response : 401, Unauthorized
2022-07-25 16:00:17.633 [DEBUG] [internal.handler.TeslaVehicleHandler] - The access token has expired, trying to get a new one.
2022-07-25 16:00:17.635 [DEBUG] [internal.handler.TeslaAccountHandler] - Found a request token created at 2022-07-25 14:37:46
2022-07-25 16:00:17.636 [DEBUG] [internal.handler.TeslaAccountHandler] - The token has expired at 2022-07-25 15:06:34
2022-07-25 16:00:17.637 [DEBUG] [sla.internal.handler.TeslaSSOHandler] - Exchanging SSO refresh token for API access token
2022-07-25 16:00:27.640 [DEBUG] [sla.internal.handler.TeslaSSOHandler] - An exception occurred while invoking a HTTP request: 'Total timeout 10000 ms elapsed'
2022-07-25 16:00:27.642 [DEBUG] [sla.internal.handler.TeslaSSOHandler] - An error occurred during refresh of SSO token: no response
2022-07-25 16:00:27.643 [DEBUG] [internal.handler.TeslaVehicleHandler] - An error occurred while querying the vehicle

Any help would be appreciated!

@openhab-bot
Copy link
Collaborator

This issue has been mentioned on openHAB Community. There might be relevant details there:

https://community.openhab.org/t/tesla-items-not-updated/138374/1

@lsiepel
Copy link
Contributor

lsiepel commented Oct 28, 2023

If i look at the changed comitted to this binding after 3.1.0, it might allready be fixed.

Can you verify this issue still exists with the current snapshot verison of openHAB?

Copy link

stale bot commented Mar 2, 2024

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

@stale stale bot added the stale As soon as a PR is marked stale, it can be removed 6 months later. label Mar 2, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
awaiting feedback bug An unexpected problem or unintended behavior of an add-on stale As soon as a PR is marked stale, it can be removed 6 months later.
Projects
None yet
Development

No branches or pull requests

7 participants