teslamate icon indicating copy to clipboard operation
teslamate copied to clipboard

Handle sleep behavior of MCU2 upgraded cars

Open micves opened this issue 1 year ago β€’ 37 comments

There is a lot more info in this issue: https://github.com/adriankumpf/teslamate/issues/3084

The short story is: Older cars upgraded to MCU2 have a little wakeup every hour to check subsystems. They report online but if vehicle_data is requested they wake up completely (cars clicks) and is awake for 15 minutes instead of a 2-3 minutes. The only difference (known at this moment) is stream reports power=nil in subsystem online and reports power as a number when it is a real online.

Fix implemented by staying in state :start when online is detected on non-vehicle_data. Stream receives data and new variable fake_online is set dependent on power is nil or a number. The variable fake_online is used to decide whether to get only non-vehicle_data or the full blown wakeup vehicle_data In suspended only non-vehicle_data is allowed to be better at going to sleep. Usage is detected if power>0 to go back to online state.

Other things:

  • Handle stream getting vehicle offline and change to state :offline in vehicle
  • Try to suspend in online when getting error on fetch_result This will lay of vehicle_data and use non-vehicle_data instead and hopefully not keep the car awake when errors suddenly stop again
  • I'm not quite into nice coding guidelines for Elixir, so some code-review might be good :)
  • I don't have possibility to test on other types of cars than my own 2017 Model S with upgraded MCU2.

micves avatar Jun 26 '23 18:06 micves

This is Beautiful - I've been wondering about this for a couple of years now but never thought to dig more into why the MCU2 upgraded car behaved differently to the other MCU2 car in the account

oivindoh avatar Nov 17 '23 17:11 oivindoh

Would it make sense to make different PR's to the things that are not directly related to the MCU2 issue? Especially the first to points in the PR description/comment under "other things":

  • Handle stream getting vehicle offline and change to state :offline in vehicle
  • Try to suspend in online when getting error on fetch_result This will lay of vehicle_data and use non-vehicle_data instead and hopefully not keep the car awake when errors suddenly stop again

Just to make it easier to review this, but also for me to actually get CI tests working for both this MCU2 issue and the other things

micves avatar Nov 19 '23 15:11 micves

Is this PR still active?

USAFPride avatar Nov 19 '23 20:11 USAFPride

Is this PR still active?

Yes, it just fails some of the workflow tests, so I think I need to figure that out.

Besides that I once in a while merge teslamate:master in to keep the PR up-to-date

micves avatar Nov 19 '23 21:11 micves

Currently installing 2023.38.9. Will report back

Works fine with 2023.38.9

USAFPride avatar Nov 24 '23 13:11 USAFPride

I can’t see any runs on this PR - @JakobLichterfeld do we have any elixir gurus who could take a look at this one?

oivindoh avatar Nov 25 '23 17:11 oivindoh

I can’t see any runs on this PR - @JakobLichterfeld do we have any elixir gurus who could take a look at this one?

Run needs manual approval. I didn't push the button till now since this branch seems outdated in regards to workflow files

JakobLichterfeld avatar Nov 26 '23 02:11 JakobLichterfeld

I just synced the fork, but I know from last run that there are a lot of test failures. I just set up an test environment next to my running environment to try to fix those failures.

Previously I used WSL on windows for test, but it seems to fail even on master. I think there is some timing that doesn't match. And it's also insanely slow to test on WSL

micves avatar Nov 26 '23 09:11 micves

Deploy Preview for teslamate ready!

Name Link
Latest commit a45505aeb7bb9cd716d32837e04731c8a4228c23
Latest deploy log https://app.netlify.com/sites/teslamate/deploys/66bd2104ad96f80008aaaed4
Deploy Preview https://deploy-preview-3262--teslamate.netlify.app
Preview on mobile
Toggle QR Code...

QR Code

Use your smartphone camera to open QR code link.

To edit notification comments on pull requests, go to your Netlify site configuration.

netlify[bot] avatar Dec 07 '23 21:12 netlify[bot]

Can we get this merged into the master?

USAFPride avatar Dec 19 '23 01:12 USAFPride

Can we get this merged into the master?

Once our 321 test cases run successfully and we are sure that we are not breaking anything with non-MCU2 upgraded cars, the answer will be yes.

JakobLichterfeld avatar Dec 19 '23 13:12 JakobLichterfeld

I deployed: ghcr.io/teslamate-org/teslamate:pr-3262@sha256:aef423f3ff54fa3452d05b94c51bbd884fd425d3b867d8ec57ceef0be8b80176

Getting errors like this:

2024-02-20T10:57:40.761 app[4d89270a633287] otp [info] 2024-02-20 10:57:40.760 [info] GET /
2024-02-20T10:57:40.791 app[4d89270a633287] otp [info] 2024-02-20 10:57:40.790 [error] GenStateMachine :"1" terminating
2024-02-20T10:57:40.791 app[4d89270a633287] otp [info] ** (FunctionClauseError) no function clause matching in TeslaMate.Vehicles.Vehicle.Summary.format_vehicle/1
2024-02-20T10:57:40.791 app[4d89270a633287] otp [info] (teslamate 1.28.3) lib/teslamate/vehicles/vehicle/summary.ex:72: TeslaMate.Vehicles.Vehicle.Summary.format_vehicle(nil)
2024-02-20T10:57:40.791 app[4d89270a633287] otp [info] (teslamate 1.28.3) lib/teslamate/vehicles/vehicle/summary.ex:44: TeslaMate.Vehicles.Vehicle.Summary.into/2
2024-02-20T10:57:40.791 app[4d89270a633287] otp [info] (teslamate 1.28.3) lib/teslamate/vehicles/vehicle.ex:196: TeslaMate.Vehicles.Vehicle.handle_event/4
2024-02-20T10:57:40.791 app[4d89270a633287] otp [info] (stdlib 5.2) gen_statem.erl:1397: :gen_statem.loop_state_callback/11
2024-02-20T10:57:40.791 app[4d89270a633287] otp [info] (stdlib 5.2) proc_lib.erl:241: :proc_lib.init_p_do_apply/3
2024-02-20T10:57:40.795 app[4d89270a633287] otp [info] 2024-02-20 10:57:40.792 [error] Task #PID<0.2930.0> started from #PID<0.2924.0> terminating
2024-02-20T10:57:40.795 app[4d89270a633287] otp [info] ** (stop) exited in: :gen_statem.call(#PID<0.2911.0>, :summary, :infinity)
2024-02-20T10:57:40.795 app[4d89270a633287] otp [info] ** (EXIT) an exception was raised:
2024-02-20T10:57:40.795 app[4d89270a633287] otp [info] ** (FunctionClauseError) no function clause matching in TeslaMate.Vehicles.Vehicle.Summary.format_vehicle/1
2024-02-20T10:57:40.795 app[4d89270a633287] otp [info] (teslamate 1.28.3) lib/teslamate/vehicles/vehicle/summary.ex:72: TeslaMate.Vehicles.Vehicle.Summary.format_vehicle(nil)
2024-02-20T10:57:40.795 app[4d89270a633287] otp [info] (teslamate 1.28.3) lib/teslamate/vehicles/vehicle/summary.ex:44: TeslaMate.Vehicles.Vehicle.Summary.into/2
2024-02-20T10:57:40.795 app[4d89270a633287] otp [info] (teslamate 1.28.3) lib/teslamate/vehicles/vehicle.ex:196: TeslaMate.Vehicles.Vehicle.handle_event/4
2024-02-20T10:57:40.795 app[4d89270a633287] otp [info] (stdlib 5.2) gen_statem.erl:1397: :gen_statem.loop_state_callback/11
2024-02-20T10:57:40.795 app[4d89270a633287] otp [info] (stdlib 5.2) proc_lib.erl:241: :proc_lib.init_p_do_apply/3
2024-02-20T10:57:40.795 app[4d89270a633287] otp [info] (stdlib 5.2) gen.erl:246: :gen.do_call/4
2024-02-20T10:57:40.795 app[4d89270a633287] otp [info] (stdlib 5.2) gen_statem.erl:923: :gen_statem.call/3
2024-02-20T10:57:40.795 app[4d89270a633287] otp [info] (elixir 1.16.1) lib/task/supervised.ex:101: Task.Supervised.invoke_mfa/2
2024-02-20T10:57:40.795 app[4d89270a633287] otp [info] (elixir 1.16.1) lib/task/supervised.ex:36: Task.Supervised.reply/4
2024-02-20T10:57:40.795 app[4d89270a633287] otp [info] Function: &:erlang.apply/2
2024-02-20T10:57:40.795 app[4d89270a633287] otp [info] Args: [#Function<4.33331538/1 in TeslaMate.Vehicles.list/0>, [{TeslaMate.Vehicles.Vehicle_1, #PID<0.2911.0>, :worker, [TeslaMate.Vehicles.Vehicle]}]]
2024-02-20T10:57:40.795 app[4d89270a633287] otp [info] 2024-02-20 10:57:40.794 [error] Ranch protocol #PID<0.2924.0> of listener TeslaMateWeb.Endpoint.HTTP (connection #PID<0.2907.0>, stream id 2) terminated
2024-02-20T10:57:40.795 app[4d89270a633287] otp [info] exited in: :gen_statem.call(#PID<0.2911.0>, :summary, :infinity)
2024-02-20T10:57:40.795 app[4d89270a633287] otp [info] ** (EXIT) an exception was raised:
2024-02-20T10:57:40.795 app[4d89270a633287] otp [info] ** (FunctionClauseError) no function clause matching in TeslaMate.Vehicles.Vehicle.Summary.format_vehicle/1
2024-02-20T10:57:40.795 app[4d89270a633287] otp [info] (teslamate 1.28.3) lib/teslamate/vehicles/vehicle/summary.ex:72: TeslaMate.Vehicles.Vehicle.Summary.format_vehicle(nil)
2024-02-20T10:57:40.795 app[4d89270a633287] otp [info] (teslamate 1.28.3) lib/teslamate/vehicles/vehicle/summary.ex:44: TeslaMate.Vehicles.Vehicle.Summary.into/2
2024-02-20T10:57:40.795 app[4d89270a633287] otp [info] (teslamate 1.28.3) lib/teslamate/vehicles/vehicle.ex:196: TeslaMate.Vehicles.Vehicle.handle_event/4
2024-02-20T10:57:40.795 app[4d89270a633287] otp [info] (stdlib 5.2) gen_statem.erl:1397: :gen_statem.loop_state_callback/11
2024-02-20T10:57:40.795 app[4d89270a633287] otp [info] (stdlib 5.2) proc_lib.erl:241: :proc_lib.init_p_do_apply/3

Also trying to load the web interface responds with 500

czras avatar Feb 20 '24 11:02 czras

@czras are you using docker-compose.yml with something like this:

services:
  teslamate:
    image: ghcr.io/teslamate-org/teslamate:pr-3262

I'm not using docker at the moment but a more manual install. But there is at least one that has pulled the latest from docker with no issues.

I can't really figure out what is going on based on the log output :(

Does it happen as soon as you start up or is it triggered by the GET ? That you try to access the web.

Can you post some more of the log? From startup maybe.

micves avatar Feb 20 '24 21:02 micves

@czras are you using docker-compose.yml with something like this:

services:
  teslamate:
    image: ghcr.io/teslamate-org/teslamate:pr-3262

I am using the image with the SHA ghcr.io/teslamate-org/teslamate@sha256:aef423f3ff54fa3452d05b94c51bbd884fd425d3b867d8ec57ceef0be8b80176 from the GithubAction. It pulls the same image as ghcr.io/teslamate-org/teslamate:pr-3262.

Does it happen as soon as you start up or is it triggered by the GET ? That you try to access the web.

As far as I can judge it is happening right after start. Without accessing the web UI, the same error continues to pop up.

Can you post some more of the log? From startup maybe.

Certainly. Hopefully I can retest it this evening to gather all the logs.

czras avatar Feb 21 '24 08:02 czras

My suspicion is that the build information commit may not work correctly when doing the Docker build. As in does the build have access to the git information? If it does work, then disregard :-)

brianmay avatar Feb 22 '24 22:02 brianmay

I'm also anxious to see if it works :) The Build GHCR images do alot of git commands, but that might be in a different scope somehow. And my docker environment doesnt really work right now, so can't even test myself :(

micves avatar Feb 22 '24 23:02 micves

I guess it didn't https://github.com/teslamate-org/teslamate/issues/3084#issuecomment-1960471561

micves avatar Feb 22 '24 23:02 micves

Certainly. Hopefully I can retest it this evening to gather all the logs.

Sorry, got the flu which knocked me out for a bit of time. I deployed now from a local docker build and this works fine. Altough I had to switch from netcat-traditional to netcat-openbsd for IPv6 support but that is a different story.

czras avatar Mar 05 '24 09:03 czras

@micves, am I reading this correct that there are mainly 2 errors and are triggered by Model 3 only?

USAFPride avatar Jul 26 '24 18:07 USAFPride

@micves, am I reading this correct that there are mainly 2 errors and are triggered by Model 3 only?

@USAFPride, I'm not sure what you mean here :/ Where do you read that?

micves avatar Jul 26 '24 20:07 micves

just to restate, I am not at all familiar with Elixir, but the first error below is for "car version" and all results returned nil. It shows a Model 3 (and the 2nd error) , so I made the assumption, and well...

Happy to have an education `

  1. test updates handles unexpected :car_version's (TeslaMate.Vehicles.VehicleTest) Error: test/teslamate/vehicles/vehicle_test.exs:483 Unexpectedly received message {:insert_position, %TeslaMate.Log.Car{meta: #Ecto.Schema.Metadata<:built, "cars">, id: 35042, name: nil, efficiency: nil, model: "3", trim_badging: nil, marketing_name: nil, exterior_color: nil, wheel_type: nil, spoiler_type: nil, eid: 0, vid: 1000, vin: "1000", settings_id: nil, settings: %TeslaMate.Settings.CarSettings{meta: #Ecto.Schema.Metadata<:built, "car_settings">, id: nil, suspend_min: 21, suspend_after_idle_min: 15, req_not_unlocked: true, free_supercharging: false, use_streaming_api: true, enabled: true, lfp_battery: false, car: #Ecto.Association.NotLoaded}, charging_processes: #Ecto.Association.NotLoaded, positions: #Ecto.Association.NotLoaded, drives: #Ecto.Association.NotLoaded, inserted_at: nil, updated_at: nil}, %{date: ~U[2024-07-24 22:14:46.344Z], speed: nil, latitude: 0.0, longitude: 0.0, elevation: nil, power: nil, odometer: nil, ideal_battery_range_km: nil, battery_level: nil, outside_temp: nil, fan_status: nil, driver_temp_setting: nil, passenger_temp_setting: nil, is_climate_on: nil, is_rear_defroster_on: nil, is_front_defroster_on: nil, battery_heater_on: nil, inside_temp: nil, battery_heater: nil, battery_heater_no_power: nil, est_battery_range_km: nil, rated_battery_range_km: nil, usable_battery_level: nil, tpms_pressure_fl: nil, tpms_pressure_fr: nil, tpms_pressure_rl: nil, tpms_pressure_rr: nil}} (which matched _) code: refute_receive _ stacktrace: test/teslamate/vehicles/vehicle_test.exs:495: (test)

    The following output was logged: Warning: 4:46.460 car_id=35042 [warning] Unexpected software version: %TeslaApi.Vehicle.State.VehicleState{ api_version: nil, autopark_state_v3: nil, autopark_style: nil, calendar_supported: nil, car_version: nil, center_display_state: nil, df: nil, dr: nil, ft: nil, homelink_device_count: nil, homelink_nearby: nil, is_user_present: nil, last_autopark_error: nil, locked: nil, notifications_supported: nil, odometer: nil, parsed_calendar_supported: nil, pf: nil, pr: nil, remote_start: nil, remote_start_enabled: nil, remote_start_supported: nil, rt: nil, fd_window: nil, fp_window: nil, rd_window: nil, rp_window: nil, sentry_mode: nil, sentry_mode_available: nil, smart_summon_available: nil, software_update: nil, summon_standby_mode_enabled: nil, sun_roof_percent_open: nil, sun_roof_state: nil, timestamp: nil, valet_mode: nil, valet_pin_needed: nil, vehicle_name: nil, tpms_pressure_fl: nil, tpms_pressure_fr: nil, tpms_pressure_rl: nil, tpms_pressure_rr: nil, tpms_soft_warning_fl: nil, tpms_soft_warning_fr: nil, tpms_soft_warning_rl: nil, tpms_soft_warning_rr: nil } `

USAFPride avatar Jul 27 '24 11:07 USAFPride

just to restate, I am not at all familiar with Elixir, but the first error below is for "car version" and all results returned nil. It shows a Model 3 (and the 2nd error) , so I made the assumption, and well...

Happy to have an education

We do use Model 3 values in our 321 automated test cases, that's right. The changes made by micves do break the automated tests. So we need to either adapt the tests or change the code to do not break the tests. Thats the reasons for automated tests: make sure changes do not break the system, nor other parts of the software.

JakobLichterfeld avatar Jul 27 '24 12:07 JakobLichterfeld

@USAFPride, Ah okay, I see where you saw that now :) I was confused as there are alot more than 2 errors. If you use github to show it, it might stall due to the large size of the logs. And I hadn't noticed the model 3.

I have changed internal conditions for when the vehicle goes online that needs to be adapted in the tests. I have started to look into it.

micves avatar Jul 27 '24 22:07 micves

@micves I'm impressed by your perseverance to get to the bottom of this! It looks like you've diagnosed the problem precisely and already got it working on your branch, it's just the tests messing things up to get it merged into the main distribution, right?

cinamo avatar Aug 16 '24 14:08 cinamo

@micves I'm impressed by your perseverance to get to the bottom of this! It looks like you've diagnosed the problem precisely and already got it working on your branch, it's just the tests messing things up to get it merged into the main distribution, right?

Passing the automated tests is not the challenge, it can be easily solved. It is important that the changes do not lead to any undesirable behavior in non MCU2 upgraded cars or Model 3, Y, CT etc.

JakobLichterfeld avatar Aug 16 '24 15:08 JakobLichterfeld

Yes the automated tests is one thing, but more real life testing on different cars would also help. I know that @VKrapalis is running on my branch with a MCU2 upgraded model s and a model 3 in same teslamate instance with no issues.

micves avatar Aug 16 '24 19:08 micves

I can verify that a model s 2015 with mcu 2 and a model 3 2021 SR work on this version

VKrapalis avatar Aug 16 '24 19:08 VKrapalis

If another datapoint helps, I can confirm that this PR's image had been working great and been very stable on my MC2 upgraded model S.

Thanks very much for your work!

fetzu avatar Aug 17 '24 09:08 fetzu

If another datapoint helps, I can confirm that this PR's image had been working great and been very stable on my MC2 upgraded model S.

Thanks for confirmation. We are confident this branch solves the issues with Model S MCU2 upgraded cars. As there are around 22 Million docker pulls, we need to be confident all vehicles run fine with it. We do ensure a good grade of confidence with our 321+ automated test cases. As this PR breaks a lot of tests, we can update the tests if we are sure this is the desired behavior.

JakobLichterfeld avatar Aug 17 '24 11:08 JakobLichterfeld

Of course, I wasn't suggesting to merge this PR based on two random comments ;)...

fetzu avatar Aug 17 '24 17:08 fetzu