Model S MCU1 sleep issues about teslamate HOT 19 CLOSED

I have an upcoming commit to the PR, hopefully today, I just need to get an overview of my changes :)

from teslamate.

My understanding is MCU1 supported streaming fine, that it how it tracks drives. And I have drives recorded from before I upgraded to MCU2, and they appear to be just as detailed as recent drives.

(Unless we really did poll once per second when streaming is non-functional, but that seems excessive)

I tend to wonder what what happen if you downgraded to 1.28.2. This would prove if the problem is due to our changes or Changes Tesla made.

Possible concerns with this:

• I don't think there are any changes to database schema to worry about.

• Version 1.28.2 is before the change to fetch vehicles using the product API. My experience is this it OK for existing installs, TeslaMate will fall back to using the database values (just don't change your cars when doing this!).

If I am wrong, and everything crashes and burns, save the logs, abort, and go back to 1.28.3.

For a full list of changes between 1.28.2 to 1.28.3 see v1.28.2...v1.28.3

from teslamate.

Yeah, I have the streaming API enabled. I will give a spin to that PR tomorrow.

I have deployed it but getting errors so rolled it back to 1.28.3. I put some logs in a comment on the PR.

from teslamate.

I have a 2023 model and observed that the vehicles is waking up randomly as well after the 1.28.3 update

I was trying to analyze the logs for any patterns, the only thing i noticed is the token refresh between each wake up but the times don't exactly match up (i see the same events as your logs)

Pre update my vehicle never woke up on it's own

from teslamate.

Same problem for me in my M3 Highland, since the last update.

from teslamate.

Did you perform a soft reset in car? This solves most of the strange wake-up behavior.
The second point will be a dead 12 V battery.

from teslamate.

Did you perform a soft reset in car? This solves most of the strange wake-up behavior. The second point will be a dead 12 V battery.

Many times in the last couple of months for other reasons: LTE modem not picking up net on country border crossings or just randomly go offline.

I had changed the 12V battery almost exactly a year ago, there were sleep issues then too, but different phenomena. Then the car was not sleeping at all at the end, it deteriorated to a 12V battery warning in a month. This is going on for three months now and is pretty consistent, not deteriorating.

This is a 6 month period from last year (same time interval for comparison), the battery was changed 16th of February 2023:

from teslamate.

@micves may you look into this?
Perhaps our ghcr build of #3262 can help here as well

from teslamate.

@JakobLichterfeld That PR is very dependent on streaming API.
And isn't it correct that the MCU 1 doesnt support the streaming API?

I might be wrong, @czras do you have streaming API enabled in settings?
If you do and that works for MCU1 it could make sense to try out the PR

from teslamate.

@JakobLichterfeld That PR is very dependent on streaming API. And isn't it correct that the MCU 1 doesnt support the streaming API?

I might be wrong, @czras do you have streaming API enabled in settings? If you do and that works for MCU1 it could make sense to try out the PR

Yeah, I have the streaming API enabled. I will give a spin to that PR tomorrow.

My understanding is MCU1 supported streaming fine, that it how it tracks drives. And I have drives recorded from before I upgraded to MCU2, and they appear to be just as detailed as recent drives.

(Unless we really did poll once per second when streaming is non-functional, but that seems excessive)

I tend to wonder what what happen if you downgraded to 1.28.2. This would prove if the problem is due to our changes or Changes Tesla made.

For my specific case, the issue started when I was using 1.27.3 and persisted through 1.28.2 and 1.28.3, that periodic wakeup thing was only a single night, so I am not concerned about that (lets put it as a red herring for the moment). The 4:50 AMish wakeups and general not sleeping enough through the day is my real issue.

For the other commenters that might be an option though.

from teslamate.

Did you perform a soft reset in car? This solves most of the strange wake-up behavior. The second point will be a dead 12 V battery.

I rolled back to 1.28.3 and haven't had any random wake ups

from teslamate.

my bad, I rolled back to 1.28.2

from teslamate.

I have deployed it but getting errors so rolled it back to 1.28.3. I put some logs in a comment on the PR.

I am running the PR from a local build now for some days.
Here are the logs from this night:

2024-03-06T00:14:44.834 app[4d89270a633287] otp [info] 2024-03-06 00:14:44.833 car_id=1 [info] Suspending logging
2024-03-06T01:14:59.030 app[4d89270a633287] otp [info] 2024-03-06 01:14:59.030 car_id=1 [info] Stream disconnecting ...
2024-03-06T01:14:59.033 app[4d89270a633287] otp [info] 2024-03-06 01:14:59.030 car_id=1 [info] Start / :asleep
2024-03-06T03:52:35.521 app[4d89270a633287] otp [info] 2024-03-06 03:52:35.521 car_id=1 [info] Vehicle online, connect stream to check for real online
2024-03-06T03:52:35.522 app[4d89270a633287] otp [info] 2024-03-06 03:52:35.521 car_id=1 [info] Stream connecting ...
2024-03-06T03:52:40.100 app[4d89270a633287] otp [info] 2024-03-06 03:52:40.099 car_id=1 [info] Real online detected: power is a number
2024-03-06T03:52:40.686 app[4d89270a633287] otp [info] 2024-03-06 03:52:40.686 car_id=1 [info] Start / :online
2024-03-06T03:53:44.289 app[4d89270a633287] otp [info] 2024-03-06 03:53:44.289 car_id=1 [info] Suspending logging

It is the same sleeping behavior as with 1.28.3, although I do not see the error logs and disconnects. So as I see, it does not help.

Here are the states of the last 24 hour:

Note: logs are in UTC states are in CET (+01:00)

from teslamate.

I tinkered with logging a bit, and it seems the vehicle keeps disconnecting the stream and Teslamate resubscribes. Can this keep the car awake?

2024-03-08 09:07:30.779 [info] calling /api/1/vehicles/<REDACTED>
2024-03-08 09:07:31.131 car_id=1 [info] Vehicle online at startup, connect stream to check for real online
2024-03-08 09:07:31.131 car_id=1 [info] Stream connecting ...
2024-03-08 09:07:31.368 [info] Connection established
2024-03-08 09:07:31.369 [info] Stream frame: control:hello – 0
2024-03-08 09:07:31.369 [info] Subscribing …
2024-03-08 09:07:41.370 [info] Stream.Timeout / 0
2024-03-08 09:07:41.429 [info] Connection was closed (a:1|t:1|d:0). Reconnecting …
2024-03-08 09:07:41.665 [info] Connection established
2024-03-08 09:07:41.665 [info] Stream frame: control:hello – 0
2024-03-08 09:07:41.665 [info] Subscribing …
2024-03-08 09:07:47.391 [info] Stream frame: data:update
2024-03-08 09:07:47.391 car_id=1 [info] Real online detected: power is a number
2024-03-08 09:07:47.391 [info] calling /api/1/vehicles/<REDACTED>/vehicle_data
2024-03-08 09:07:48.038 car_id=1 [info] Start / :online
2024-03-08 09:07:50.404 [info] Stream frame: data:update
2024-03-08 09:08:00.404 [info] Stream frame: data:error vehicle_disconnected
2024-03-08 09:08:03.414 [info] calling /api/1/vehicles/<REDACTED>/vehicle_data
2024-03-08 09:08:15.405 [info] Subscribing …
2024-03-08 09:08:16.156 [info] Stream frame: data:update
2024-03-08 09:08:19.038 [info] calling /api/1/vehicles/<REDACTED>/vehicle_data
2024-03-08 09:08:26.157 [info] Stream frame: data:error vehicle_disconnected
2024-03-08 09:08:35.759 [info] calling /api/1/vehicles/<REDACTED>/vehicle_data
2024-03-08 09:08:41.158 [info] Subscribing …
2024-03-08 09:08:41.876 [info] Stream frame: data:update
2024-03-08 09:08:51.345 [info] calling /api/1/vehicles/<REDACTED>/vehicle_data
2024-03-08 09:08:51.876 [info] Stream frame: data:error vehicle_disconnected
2024-03-08 09:08:52.209 car_id=1 [info] Suspending logging
2024-03-08 09:09:06.877 [info] Subscribing …
2024-03-08 09:09:07.693 [info] Stream frame: data:update
2024-03-08 09:09:17.694 [info] Stream frame: data:error vehicle_disconnected
2024-03-08 09:09:32.694 [info] Subscribing …
2024-03-08 09:09:33.666 [info] Stream frame: data:update
2024-03-08 09:09:43.667 [info] Stream frame: data:error vehicle_disconnected
2024-03-08 09:09:45.207 [info] GET /
2024-03-08 09:09:45.270 [info] Sent 200 in 62ms
2024-03-08 09:09:52.212 [info] calling /api/1/vehicles/<REDACTED>
2024-03-08 09:09:58.668 [info] Subscribing …
2024-03-08 09:09:59.462 [info] Stream frame: data:update
2024-03-08 09:10:09.463 [info] Stream frame: data:error vehicle_disconnected
2024-03-08 09:10:22.573 [info] calling /api/1/vehicles/<REDACTED>
2024-03-08 09:10:24.465 [info] Subscribing …
2024-03-08 09:10:25.573 [info] Stream frame: data:update
2024-03-08 09:10:35.574 [info] Stream frame: data:error vehicle_disconnected
2024-03-08 09:10:50.574 [info] Subscribing …
2024-03-08 09:10:51.486 [info] Stream frame: data:update
2024-03-08 09:10:52.428 [info] Stream frame: data:update
2024-03-08 09:10:52.931 [info] calling /api/1/vehicles/<REDACTED>
2024-03-08 09:11:02.429 [info] Stream frame: data:error vehicle_disconnected
2024-03-08 09:11:17.430 [info] Subscribing …
2024-03-08 09:11:18.691 [info] Stream frame: data:update
2024-03-08 09:11:23.289 [info] calling /api/1/vehicles/<REDACTED>
2024-03-08 09:11:28.692 [info] Stream frame: data:error vehicle_disconnected
2024-03-08 09:11:43.694 [info] Subscribing …
2024-03-08 09:11:44.499 [info] Stream frame: data:update

Sometimes there are timeouts too:

2024-03-08 09:18:41.540 [info] Subscribing …
2024-03-08 09:18:51.541 [info] Stream.Timeout / 0
2024-03-08 09:18:51.599 [info] Connection was closed (a:1|t:1|d:1). Reconnecting …
2024-03-08 09:18:52.401 [info] Connection established
2024-03-08 09:18:52.401 [info] Stream frame: control:hello – 0
2024-03-08 09:18:52.401 [info] Subscribing …
2024-03-08 09:18:58.897 [info] calling /api/1/vehicles/<REDACTED>
2024-03-08 09:19:02.403 [info] Stream.Timeout / 1
2024-03-08 09:19:02.594 [info] Connection was closed (a:1|t:2|d:1). Reconnecting …
2024-03-08 09:19:03.353 [info] Connection established
2024-03-08 09:19:03.353 [info] Stream frame: control:hello – 0
2024-03-08 09:19:03.353 [info] Subscribing …
2024-03-08 09:19:13.354 [info] Stream.Timeout / 2
2024-03-08 09:19:13.543 [info] Connection was closed (a:1|t:3|d:1). Reconnecting …
2024-03-08 09:19:14.312 [info] Connection established
2024-03-08 09:19:14.312 [info] Stream frame: control:hello – 0
2024-03-08 09:19:14.313 [info] Subscribing …
2024-03-08 09:19:20.238 [info] Stream frame: data:update
2024-03-08 09:19:29.264 [info] calling /api/1/vehicles/<REDACTED>
2024-03-08 09:19:30.238 [info] Stream frame: data:error vehicle_disconnected
2024-03-08 09:19:45.239 [info] Subscribing …
2024-03-08 09:19:48.978 [info] Stream frame: data:update
2024-03-08 09:19:58.978 [info] Stream frame: data:error vehicle_disconnected
2024-03-08 09:19:59.629 [info] calling /api/1/vehicles/<REDACTED>
2024-03-08 09:20:13.979 [info] Subscribing …
2024-03-08 09:20:16.643 [info] Stream frame: data:update
2024-03-08 09:20:26.643 [info] Stream frame: data:error vehicle_disconnected

As it seems when trying to sleep, only the non-vehicle_data endpoint is called, so that should not interfere with sleeping.

from teslamate.

the vehicle keeps disconnecting the stream and Teslamate resubscribes. Can this keep the car awake?

Not to my knowledge, but my experience is based only on MCU2 upgraded car.

Maybe even non-vehicle_data on MCU1 can keep the car awake.

During my initial testing I turned off teslamate and used TeslaPy trying to figure things out. Maybe that could help you as well. I posted some testcode here: #3084 (comment)

Do you have anything else connected to the car? Like home assistant? Any 3rd party software could keep the car awake.
Advise on this kind of issues are often to change the password on your tesla account to make sure everything is disconnected.

Last resort is to just upgrade to MCU2 ;)

from teslamate.

Do you have anything else connected to the car?

I have nothing else connected to the car. As I mentioned in my original post, shutting down Teslamate for overnight results in the car sleeping until I unlock it in the morning.

Last resort is to just upgrade to MCU2 ;)

Actually my instrument screen has the fluid dripping already. But dropping 1500 EUR + VAT for the MCU2 upgrade as troubleshooting seems a bit steep :D

Thanks for the TeslaPy hint, if I have some time I will get into that too.

As an SW engineer, I am totally baffled by this whole issue. No Teslamate nor Car SW version was changed when this started to happen. It just started to happen, which seems counterintuitive. Something changed which causes this behaviour. Most probably something I am totally discounting.

One thing I did not re-check are the car settings mentioned in the FAQ 🤦‍♂️ . I will do that this evening.

from teslamate.

Well, energy saving was switched off. I guess accidentally... 🤦‍♂️ 🤦‍♂️ 🤦‍♂️

I switched back on, lets see whats happening 😄

from teslamate.

Well the car is sleeping half an hour after suspending.

Sorry for the useless rounds and thank you for the constructive support!

Conclusion: double check settings even if one thinks nothing was changed.

from teslamate.

Ah yeah, there are extra settings for MCU1 :) Forgot about those.

Well, at least we learned something and got a little more test on my PR ;)

from teslamate.