teslamate icon indicating copy to clipboard operation
teslamate copied to clipboard

Published 20 hours ago • verified publisher icon teslamate-org

Intermittent charges incorrectly recorded

Open xxxarmitagexxx opened this issue 1 year ago • 9 comments

Is there an existing issue for this?

  • [X] I have searched the existing issues

What happened?

Our Tesla is charged at home with an EVSE with a Solar Only feature. Consequently it can happen that the charge will stop temporarily if the sun comes down until the solar output reaches the desired 4.5kW level required by the charger.

Teslamate won't record correctly the charges in that case, only the first chunk before the charge is paused by the charger.

Here is today's use case, two charges but each with intermittent pause periods. View from the charger app: 

First Charge: 5.2kWh

Screenshot_20240128_154304_Evnex

Second charge: 11.5kWh upon to 80%

Screenshot_20240128_154030_Evnex

Tesla app view showing the cumulative daily charge of 16kWh:

Screenshot_20240128_154101_Tesla

Teslamate: only reporting 3.12kWh and 5.97kWh with the second charge ending at 77% rather than 80% among other inconsistencies

image

Expected Behavior

Expectation is for Teslamate to record the entire charges output, without as a single charge as long as the car is plugged or multiple charges if the charging is stopped while the car is plugged.

Steps To Reproduce

No response

Relevant log output

2024-01-28 03:53:56.865 car_id=1 [info] Phase correction: 2 -> 3
2024-01-28 03:53:56.869 car_id=1 [info] Derived efficiency factor: 158.0 Wh/km (14x confirmed)
2024-01-28 03:53:56.869 car_id=1 [info] Charging / Stopped / 5.97 kWh – 47 min
2024-01-28 03:53:56.870 car_id=1 [info] Start / :online
2024-01-28 03:53:56.874 car_id=1 [info] Connecting ...
2024-01-28 03:54:01.876 [warning] MQTT publishing failed: :timeout
2024-01-28 03:54:01.876 [warning] MQTT publishing failed: :timeout
2024-01-28 03:54:01.877 [warning] MQTT publishing failed: :timeout
2024-01-28 03:54:01.877 [warning] MQTT publishing failed: :timeout
2024-01-28 03:54:01.877 [warning] MQTT publishing failed: :timeout
2024-01-28 03:54:01.877 [warning] MQTT publishing failed: :timeout
2024-01-28 03:54:01.877 [warning] MQTT publishing failed: :timeout
2024-01-28 03:54:01.877 [warning] MQTT publishing failed: :timeout
2024-01-28 03:54:01.877 [warning] MQTT publishing failed: :timeout
2024-01-28 03:54:01.877 [warning] MQTT publishing failed: :timeout
2024-01-28 03:54:06.376 [error] GenServer TeslaMate.Mqtt.Publisher terminating
** (WithClauseError) no with clause matching: {:error, :timeout}
    (tortoise 0.10.0) lib/tortoise.ex:269: Tortoise.publish/4
    (teslamate 1.28.2) lib/teslamate/mqtt/publisher.ex:41: TeslaMate.Mqtt.Publisher.handle_call/3
    (stdlib 5.1.1) gen_server.erl:1113: :gen_server.try_handle_call/4
    (stdlib 5.1.1) gen_server.erl:1142: :gen_server.handle_msg/6
    (stdlib 5.1.1) proc_lib.erl:241: :proc_lib.init_p_do_apply/3
Last message (from #PID<0.1249662.0>): {:publish, "teslamate/cars/1/est_battery_range_km", "403.58", [retain: true, qos: 1]}
2024-01-28 03:54:06.378 [error] Task #PID<0.1249647.0> started from #PID<0.1249610.0> terminating
** (stop) exited in: GenServer.call(TeslaMate.Mqtt.Publisher, {:publish, "teslamate/cars/1/scheduled_charging_start_time", "", [retain: true, qos: 1]}, 10000)
    ** (EXIT) an exception was raised:
        ** (WithClauseError) no with clause matching: {:error, :timeout}
            (tortoise 0.10.0) lib/tortoise.ex:269: Tortoise.publish/4
            (teslamate 1.28.2) lib/teslamate/mqtt/publisher.ex:41: TeslaMate.Mqtt.Publisher.handle_call/3
            (stdlib 5.1.1) gen_server.erl:1113: :gen_server.try_handle_call/4
            (stdlib 5.1.1) gen_server.erl:1142: :gen_server.handle_msg/6
            (stdlib 5.1.1) proc_lib.erl:241: :proc_lib.init_p_do_apply/3
    (elixir 1.15.7) lib/gen_server.ex:1074: GenServer.call/3
    (elixir 1.15.7) lib/task/supervised.ex:101: Task.Supervised.invoke_mfa/2
    (elixir 1.15.7) lib/task/supervised.ex:36: Task.Supervised.reply/4
Function: &:erlang.apply/2
    Args: [#Function<4.102219062/1 in TeslaMate.Mqtt.PubSub.VehicleSubscriber.handle_info/2>, [scheduled_charging_start_time: nil]]
2024-01-28 03:54:32.575 [warning] MQTT publishing failed: :timeout
2024-01-28 03:54:32.575 [warning] MQTT publishing failed: :timeout
2024-01-28 03:54:32.576 [warning] MQTT publishing failed: :timeout
2024-01-28 03:54:32.576 [warning] MQTT publishing failed: :timeout
2024-01-28 03:54:32.576 [warning] MQTT publishing failed: :timeout
2024-01-28 03:54:32.576 [warning] MQTT publishing failed: :timeout
2024-01-28 03:54:32.577 [warning] MQTT publishing failed: :timeout
2024-01-28 03:54:32.577 [warning] MQTT publishing failed: :timeout
2024-01-28 03:54:32.577 [warning] MQTT publishing failed: :timeout
2024-01-28 03:54:32.577 [warning] MQTT publishing failed: :timeout
2024-01-28 03:54:37.076 [error] GenServer TeslaMate.Mqtt.Publisher terminating
** (WithClauseError) no with clause matching: {:error, :timeout}
    (tortoise 0.10.0) lib/tortoise.ex:269: Tortoise.publish/4
    (teslamate 1.28.2) lib/teslamate/mqtt/publisher.ex:41: TeslaMate.Mqtt.Publisher.handle_call/3
    (stdlib 5.1.1) gen_server.erl:1113: :gen_server.try_handle_call/4
    (stdlib 5.1.1) gen_server.erl:1142: :gen_server.handle_msg/6
    (stdlib 5.1.1) proc_lib.erl:241: :proc_lib.init_p_do_apply/3
Last message (from #PID<0.1249702.0>): {:publish, "teslamate/cars/1/est_battery_range_km", "403.58", [retain: true, qos: 1]}
2024-01-28 03:54:37.078 [error] Task #PID<0.1249728.0> started from #PID<0.1249722.0> terminating
** (stop) exited in: GenServer.call(TeslaMate.Mqtt.Publisher, {:publish, "teslamate/cars/1/display_name", "Bluey", [retain: true, qos: 1]}, 10000)
    ** (EXIT) an exception was raised:
        ** (WithClauseError) no with clause matching: {:error, :timeout}
            (tortoise 0.10.0) lib/tortoise.ex:269: Tortoise.publish/4
            (teslamate 1.28.2) lib/teslamate/mqtt/publisher.ex:41: TeslaMate.Mqtt.Publisher.handle_call/3
            (stdlib 5.1.1) gen_server.erl:1113: :gen_server.try_handle_call/4
            (stdlib 5.1.1) gen_server.erl:1142: :gen_server.handle_msg/6
            (stdlib 5.1.1) proc_lib.erl:241: :proc_lib.init_p_do_apply/3
    (elixir 1.15.7) lib/gen_server.ex:1074: GenServer.call/3
    (elixir 1.15.7) lib/task/supervised.ex:101: Task.Supervised.invoke_mfa/2
    (elixir 1.15.7) lib/task/supervised.ex:36: Task.Supervised.reply/4
Function: &:erlang.apply/2
    Args: [#Function<4.102219062/1 in TeslaMate.Mqtt.PubSub.VehicleSubscriber.handle_info/2>, [display_name: "Bluey"]]
2024-01-28 03:54:37.078 [error] Task #PID<0.1249712.0> started from #PID<0.1249722.0> terminating
** (stop) exited in: GenServer.call(TeslaMate.Mqtt.Publisher, {:publish, "teslamate/cars/1/heading", "189", [retain: true, qos: 1]}, 10000)
    ** (EXIT) an exception was raised:
        ** (WithClauseError) no with clause matching: {:error, :timeout}
            (tortoise 0.10.0) lib/tortoise.ex:269: Tortoise.publish/4
            (teslamate 1.28.2) lib/teslamate/mqtt/publisher.ex:41: TeslaMate.Mqtt.Publisher.handle_call/3
            (stdlib 5.1.1) gen_server.erl:1113: :gen_server.try_handle_call/4
            (stdlib 5.1.1) gen_server.erl:1142: :gen_server.handle_msg/6
            (stdlib 5.1.1) proc_lib.erl:241: :proc_lib.init_p_do_apply/3
    (elixir 1.15.7) lib/gen_server.ex:1074: GenServer.call/3
    (elixir 1.15.7) lib/task/supervised.ex:101: Task.Supervised.invoke_mfa/2
    (elixir 1.15.7) lib/task/supervised.ex:36: Task.Supervised.reply/4
Function: &:erlang.apply/2
    Args: [#Function<4.102219062/1 in TeslaMate.Mqtt.PubSub.VehicleSubscriber.handle_info/2>, [heading: 189]]
2024-01-28 03:54:37.078 [error] Task #PID<0.1249726.0> started from #PID<0.1249722.0> terminating
** (stop) exited in: GenServer.call(TeslaMate.Mqtt.Publisher, {:publish, "teslamate/cars/1/healthy", "true", [retain: true, qos: 1]}, 10000)
    ** (EXIT) an exception was raised:
        ** (WithClauseError) no with clause matching: {:error, :timeout}
            (tortoise 0.10.0) lib/tortoise.ex:269: Tortoise.publish/4
            (teslamate 1.28.2) lib/teslamate/mqtt/publisher.ex:41: TeslaMate.Mqtt.Publisher.handle_call/3
            (stdlib 5.1.1) gen_server.erl:1113: :gen_server.try_handle_call/4
            (stdlib 5.1.1) gen_server.erl:1142: :gen_server.handle_msg/6
            (stdlib 5.1.1) proc_lib.erl:241: :proc_lib.init_p_do_apply/3
    (elixir 1.15.7) lib/gen_server.ex:1074: GenServer.call/3
    (elixir 1.15.7) lib/task/supervised.ex:101: Task.Supervised.invoke_mfa/2
    (elixir 1.15.7) lib/task/supervised.ex:36: Task.Supervised.reply/4
Function: &:erlang.apply/2
    Args: [#Function<4.102219062/1 in TeslaMate.Mqtt.PubSub.VehicleSubscriber.handle_info/2>, [healthy: true]]
2024-01-28 03:54:37.079 [error] Task #PID<0.1249731.0> started from #PID<0.1249722.0> terminating
** (stop) exited in: GenServer.call(TeslaMate.Mqtt.Publisher, {:publish, "teslamate/cars/1/sentry_mode", "false", [retain: true, qos: 1]}, 10000)
    ** (EXIT) an exception was raised:
        ** (WithClauseError) no with clause matching: {:error, :timeout}
            (tortoise 0.10.0) lib/tortoise.ex:269: Tortoise.publish/4
            (teslamate 1.28.2) lib/teslamate/mqtt/publisher.ex:41: TeslaMate.Mqtt.Publisher.handle_call/3
            (stdlib 5.1.1) gen_server.erl:1113: :gen_server.try_handle_call/4
            (stdlib 5.1.1) gen_server.erl:1142: :gen_server.handle_msg/6
            (stdlib 5.1.1) proc_lib.erl:241: :proc_lib.init_p_do_apply/3
    (elixir 1.15.7) lib/gen_server.ex:1074: GenServer.call/3
    (elixir 1.15.7) lib/task/supervised.ex:101: Task.Supervised.invoke_mfa/2
    (elixir 1.15.7) lib/task/supervised.ex:36: Task.Supervised.reply/4
Function: &:erlang.apply/2
    Args: [#Function<4.102219062/1 in TeslaMate.Mqtt.PubSub.VehicleSubscriber.handle_info/2>, [sentry_mode: false]]

Screenshots

No response

Additional data

No response

Type of installation

Docker

Version

v1.28.2

xxxarmitagexxx avatar Jan 28 '24 05:01 xxxarmitagexxx

Can you post the rest of the log from 28th Jan? I think the part you posted doesn't show the time when charging should have started again (I assume your time is currently UTC+11 and the time in the log is UTC).

dyxyl avatar Jan 29 '24 23:01 dyxyl

Hi,

Yes the logs timestamps are in UTC while Teslamate is set as UTC+11.

Please find attached the logs starting on the 27th 1pm UTC up until 28th 1pm UTC which should encapsulate both charges

teslamate.log

xxxarmitagexxx avatar Jan 29 '24 23:01 xxxarmitagexxx

While yesterday charge lined up well between the charger data and Teslamate, today's charge is missing 20+ minutes at the start in Teslamate and is thus under reported: 

WhatsApp Image 2024-01-30 à 13 47 43_c1359fa6

image

teslamate_30.log

The Tesla app is correctly reporting 9kWh similar to the charger.

Any idea what's causing the erratic behavior as the charge reporting cannot be trusted as it stands ? This time the charge once started was continuous unlike the prior examples.

xxxarmitagexxx avatar Jan 30 '24 03:01 xxxarmitagexxx

Intermitted charging and driving logging is possibly related to a change in the API endpoint, see https://github.com/teslamate-org/teslamate/issues/3629. However, your charging durations are longer as "typical" for this issue, see https://github.com/teslamate-org/teslamate/discussions/3635.

A fix for the API endpoint change in the works, https://github.com/teslamate-org/teslamate/pull/3630.

wooter avatar Jan 30 '24 08:01 wooter

It looks like communication errors between the car and Tesla:

2024-01-30 00:39:50.107 [warning] GET https://owner-api.teslamotors.com/api/1/vehicles/.../vehicle_data -> 540 (2975.551 ms)
2024-01-30 00:39:50.107 [warning] TeslaApi.Error / vehicle error: it is online but not responsive
2024-01-30 00:39:50.107 car_id=1 [error] Error / :unknown
2024-01-30 00:40:10.617 car_id=1 [info] Suspending logging
2024-01-30 00:40:32.921 [warning] Too many disconnects from streaming API

I think the vehicle error: it is online but not responsive comes from the Tesla server.

Maybe a weak WiFi signal where the car is parked?

dyxyl avatar Jan 30 '24 11:01 dyxyl

The car is connected to a dedicated AP in the garage less than 5 meters from it so I don't the wi-fi strength would be the issue.

On Tue, 30 Jan 2024, 10:34 pm dyxyl, @.***> wrote:

It looks like communication errors between the car and Tesla:

2024-01-30 00:39:50.107 [warning] GET https://owner-api.teslamotors.com/api/1/vehicles/.../vehicle_data -> 540 (2975.551 ms) 2024-01-30 00:39:50.107 [warning] TeslaApi.Error / vehicle error: it is online but not responsive 2024-01-30 00:39:50.107 car_id=1 [error] Error / :unknown 2024-01-30 00:40:10.617 car_id=1 [info] Suspending logging 2024-01-30 00:40:32.921 [warning] Too many disconnects from streaming API

I think the vehicle error: it is online but not responsive comes from the Tesla server.

Maybe a weak WiFi signal where the car is parked?

— Reply to this email directly, view it on GitHub https://github.com/teslamate-org/teslamate/issues/3634#issuecomment-1916651009, or unsubscribe https://github.com/notifications/unsubscribe-auth/AWS2JM4FGRTMOPPNUROHT33YRDLFNAVCNFSM6AAAAABCN4OD6SVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTSMJWGY2TCMBQHE . You are receiving this because you authored the thread.Message ID: @.***>

xxxarmitagexxx avatar Jan 30 '24 11:01 xxxarmitagexxx

While they aren't related to the car, are the large number of MQTT timeouts expected?

dyxyl avatar Jan 30 '24 11:01 dyxyl

I was wondering that as well. I am using the same mosquito broker as my home assistant instance and can't say I ever had any issue on that end.

On Tue, 30 Jan 2024, 10:46 pm dyxyl, @.***> wrote:

While they aren't related to the car, are the large number of MQTT timeouts expected?

— Reply to this email directly, view it on GitHub https://github.com/teslamate-org/teslamate/issues/3634#issuecomment-1916668908, or unsubscribe https://github.com/notifications/unsubscribe-auth/AWS2JM22ZVDIAUV4EFOYMVLYRDMR7AVCNFSM6AAAAABCN4OD6SVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTSMJWGY3DQOJQHA . You are receiving this because you authored the thread.Message ID: @.***>

xxxarmitagexxx avatar Jan 30 '24 19:01 xxxarmitagexxx

TeslaMate wait for the car to fall asleep when the charge has stopped, and thus can be still in the state of waiting for sleep when you start charging again. This can only be prevented when forcing the car to be awake, or resume TeslaMate logging before start the charge again.

JakobLichterfeld avatar Feb 03 '24 13:02 JakobLichterfeld

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

github-actions[bot] avatar Mar 05 '24 01:03 github-actions[bot]

TeslaMate wait for the car to fall asleep when the charge has stopped, and thus can be still in the state of waiting for sleep when you start charging again. This can only be prevented when forcing the car to be awake, or resume TeslaMate logging before start the charge again.

If streaming is enabled it should automatically start logging again on its own: https://github.com/teslamate-org/teslamate/blob/3ecd85736adf9bc8dad933aa47dcff80a3e1fafe/lib/teslamate/vehicles/vehicle.ex#L484-L487

micves avatar Mar 05 '24 15:03 micves

Streaming is enabled on my setup.

Usually the start of a charge would be missing if the charge won't start soon after plugging the car in (as dependent on a solar export threshold).

On Wed, 6 Mar 2024, 2:12 am Michael Vestergaard, @.***> wrote:

TeslaMate wait for the car to fall asleep when the charge has stopped, and thus can be still in the state of waiting for sleep when you start charging again. This can only be prevented when forcing the car to be awake, or resume TeslaMate logging before start the charge again.

If streaming is enabled it should automatically start logging again on its own:

https://github.com/teslamate-org/teslamate/blob/3ecd85736adf9bc8dad933aa47dcff80a3e1fafe/lib/teslamate/vehicles/vehicle.ex#L484-L487

— Reply to this email directly, view it on GitHub https://github.com/teslamate-org/teslamate/issues/3634#issuecomment-1978998829, or unsubscribe https://github.com/notifications/unsubscribe-auth/AWS2JMZXOMYN636S5UO5ITTYWXOFNAVCNFSM6AAAAABCN4OD6SVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTSNZYHE4TQOBSHE . You are receiving this because you authored the thread.Message ID: @.***>

xxxarmitagexxx avatar Mar 05 '24 21:03 xxxarmitagexxx

Maybe you have streaming connection problems when the charge start, which of course would make it not detect the charge.

Maybe the MQTT errors also causes issues. In the log it only seems to be [error] GenServer TeslaMate.Mqtt.Publisher terminating, but it could still mess up the rest of the system.

If you have an interface to the charger, it could help to wake up teslamate, similar to this: https://github.com/teslamate-org/teslamate/issues/3701

micves avatar Mar 08 '24 07:03 micves

I have solved the MQTT error since sharing the logs, it was an issue with the docker network configuation.

My guess is that if the start of the charge is too much delayed due to insufficient solar export, the car would be attempting to sleep or potentially being asleep.

Same things when the charge drops in the middle.

Last few days, with a consistent solar output and above minimum threshold soon after plugging it in, teslamate captured the whole charges.

Thanks for the link, I will take a look. I have the charger integrated in Home Assistant.

On Fri, 8 Mar 2024, 6:50 pm Michael Vestergaard, @.***> wrote:

Maybe you have streaming connection problems when the charge start, which of course would make it not detect the charge.

Maybe the MQTT errors also causes issues. In the log it only seems to be [error] GenServer TeslaMate.Mqtt.Publisher terminating, but it could still mess up the rest of the system.

If you have an interface to the charger, it could help to wake up teslamate, similar to this: #3701 https://github.com/teslamate-org/teslamate/issues/3701

— Reply to this email directly, view it on GitHub https://github.com/teslamate-org/teslamate/issues/3634#issuecomment-1985209234, or unsubscribe https://github.com/notifications/unsubscribe-auth/AWS2JM75HCD46O74UUHSGMTYXFUUXAVCNFSM6AAAAABCN4OD6SVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTSOBVGIYDSMRTGQ . You are receiving this because you authored the thread.Message ID: @.***>

xxxarmitagexxx avatar Mar 08 '24 08:03 xxxarmitagexxx

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

github-actions[bot] avatar Apr 08 '24 01:04 github-actions[bot]