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

Daheimladen WB produces charger out of sync messages during start and termination of charge. #2273

Closed
ExecuteGK opened this issue Jan 12, 2022 · 9 comments · Fixed by #2858
Closed

Comments

@ExecuteGK
Copy link

During the start of a charging process, the daheimladen WB creates the following log entries:
(SW Version: Release 0.81)

Jan 12 12:39:47 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:39:47 charger status: A
Jan 12 12:39:49 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:39:49 charge power: 0W
Jan 12 12:39:49 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:39:49 charge currents: [0 0 0]A
Jan 12 12:40:06 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:40:06 charge power: 0W
Jan 12 12:40:07 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:40:07 charge currents: [0 0 0]A
Jan 12 12:40:07 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:40:07 charger status: B
Jan 12 12:40:08 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:40:08 charge start energy: 173kWh
Jan 12 12:40:08 flowcontrol evcc[46040]: [lp-2 ] INFO 2022/01/12 12:40:08 car connected
Jan 12 12:40:08 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:40:08 vehicle api refresh
Jan 12 12:40:08 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:40:08 pv action: inactive
Jan 12 12:40:09 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:40:09 vehicle soc: 37%
Jan 12 12:40:09 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:40:09 vehicle range: 153km
Jan 12 12:40:09 flowcontrol evcc[46040]: [lp-2 ] WARN 2022/01/12 12:40:09 charger out of sync: expected disabled, got enabled
Jan 12 12:40:10 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:40:10 charge power: 0W
Jan 12 12:40:11 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:40:11 charge currents: [0 0 0]A
Jan 12 12:40:26 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:40:26 charge power: 0W
Jan 12 12:40:27 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:40:27 charge currents: [0 0 0]A
Jan 12 12:40:28 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:40:28 charger status: B
Jan 12 12:40:28 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:40:28 next soc poll remaining time: 59m39s
Jan 12 12:40:28 flowcontrol evcc[46040]: [lp-2 ] WARN 2022/01/12 12:40:28 charger out of sync: expected disabled, got enabled
Jan 12 12:40:29 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:40:29 charge power: 0W
Jan 12 12:40:30 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:40:30 charge currents: [0 0 0]A
Jan 12 12:40:46 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:40:46 charge power: 0W
Jan 12 12:40:47 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:40:47 charge currents: [0 0 0]A
Jan 12 12:40:48 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:40:48 charger status: B
Jan 12 12:40:48 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:40:48 next soc poll remaining time: 59m20s
Jan 12 12:40:48 flowcontrol evcc[46040]: [lp-2 ] WARN 2022/01/12 12:40:48 charger out of sync: expected disabled, got enabled
Jan 12 12:40:49 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:40:49 charge power: 0W
Jan 12 12:40:50 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:40:50 charge currents: [0 0 0]A
Jan 12 12:41:06 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:06 charge power: 0W
Jan 12 12:41:07 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:07 charge currents: [0 0 0]A
Jan 12 12:41:08 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:08 charger status: B
Jan 12 12:41:08 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:08 next soc poll remaining time: 58m59s
Jan 12 12:41:08 flowcontrol evcc[46040]: [lp-2 ] WARN 2022/01/12 12:41:08 charger out of sync: expected disabled, got enabled
Jan 12 12:41:09 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:09 charge power: 0W
Jan 12 12:41:10 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:10 charge currents: [0 0 0]A
Jan 12 12:41:26 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:26 charge power: 0W
Jan 12 12:41:27 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:27 charge currents: [0 0 0]A
Jan 12 12:41:28 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:28 charger status: B
Jan 12 12:41:28 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:28 next soc poll remaining time: 58m39s
Jan 12 12:41:28 flowcontrol evcc[46040]: [lp-2 ] WARN 2022/01/12 12:41:28 charger out of sync: expected disabled, got enabled
Jan 12 12:41:29 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:29 charge power: 0W
Jan 12 12:41:30 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:30 charge currents: [0 0 0]A
Jan 12 12:41:35 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:35 set charge mode: now
Jan 12 12:41:35 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:35 pv action: inactive
Jan 12 12:41:35 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:35 charge power: 0W
Jan 12 12:41:36 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:36 charge currents: [0 0 0]A
Jan 12 12:41:37 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:37 charger status: B
Jan 12 12:41:37 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:37 next soc poll remaining time: 58m30s
Jan 12 12:41:41 flowcontrol evcc[46040]: [lp-2 ] WARN 2022/01/12 12:41:41 charger out of sync: expected disabled, got enabled
Jan 12 12:41:42 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:42 max charge current: 16A
Jan 12 12:41:42 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:42 charger enable
Jan 12 12:41:42 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:42 charge power: 0W
Jan 12 12:41:43 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:43 charge currents: [0 0 0]A
Jan 12 12:41:46 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:46 charge power: 0W
Jan 12 12:41:47 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:47 charge currents: [0 0 0]A
Jan 12 12:41:49 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:49 charger status: C
Jan 12 12:41:50 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:50 charge start energy: 173kWh
Jan 12 12:41:50 flowcontrol evcc[46040]: [lp-2 ] INFO 2022/01/12 12:41:50 start charging ->
Jan 12 12:41:50 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:50 vehicle soc: 37%
Jan 12 12:41:50 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:50 vehicle range: 153km
Jan 12 12:41:51 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:51 charge power: 10100W
Jan 12 12:41:51 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:51 charge currents: [15.2 15.1 15.2]A
Jan 12 12:41:51 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 12:41:51 detected phases: 3p [15.2 15.1 15.2]A
.
.
.
During the charging process, no error messages are shown.
At termination, the following log entries are shown:
.
.
.
Jan 12 14:05:08 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 14:05:08 charger status: C
Jan 12 14:05:08 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 14:05:08 next soc poll remaining time: 59m40s
Jan 12 14:05:08 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 14:05:08 vehicle soc: 54%
Jan 12 14:05:08 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 14:05:08 vehicle range: 218km
Jan 12 14:05:09 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 14:05:09 charge power: 10100W
Jan 12 14:05:09 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 14:05:09 charge currents: [15.1 15.1 15.2]A
Jan 12 14:05:09 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 14:05:09 detected phases: 3p [15.1 15.1 15.2]A
Jan 12 14:05:26 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 14:05:26 charge power: 10100W
Jan 12 14:05:27 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 14:05:27 charge currents: [15.1 15.1 15.2]A
Jan 12 14:05:27 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 14:05:27 detected phases: 3p [15.1 15.1 15.2]A
Jan 12 14:05:28 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 14:05:28 charger status: A
Jan 12 14:05:28 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 14:05:28 final charge energy: 13.8kWh
Jan 12 14:05:28 flowcontrol evcc[46040]: [lp-2 ] INFO 2022/01/12 14:05:28 stop charging <-
Jan 12 14:05:28 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 14:05:28 pv timer reset
Jan 12 14:05:28 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 14:05:28 pv action: inactive
Jan 12 14:05:28 flowcontrol evcc[46040]: [lp-2 ] INFO 2022/01/12 14:05:28 car disconnected
Jan 12 14:05:28 flowcontrol evcc[46040]: [lp-2 ] WARN 2022/01/12 14:05:28 invalid charge mode: 0
Jan 12 14:05:28 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 14:05:28 set min current: 6
Jan 12 14:05:28 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 14:05:28 set max current: 16
Jan 12 14:05:28 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 14:05:28 set min soc: 0
Jan 12 14:05:28 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 14:05:28 set target soc: 80
Jan 12 14:05:29 flowcontrol evcc[46040]: [lp-2 ] WARN 2022/01/12 14:05:29 charger out of sync: expected enabled, got disabled
Jan 12 14:05:29 flowcontrol evcc[46040]: [lp-2 ] ERROR 2022/01/12 14:05:29 charger: charging station refused to start transaction
Jan 12 14:05:30 flowcontrol evcc[46040]: [lp-2 ] DEBUG 2022/01/12 14:05:30 charger disable

Regards,

Sebastian

@andig
Copy link
Member

andig commented Jan 12, 2022

That's expected when the actual execution is async and slow. You may want to increase your interval.

@utsavanand2 could comment how long would be required for the charger.

@andig
Copy link
Member

andig commented Jan 15, 2022

Ping @utsavanand2

@utsavanand2
Copy link
Contributor

@andig @ExecuteGK As far as my experience, the status of the station doesn't take more than a second to update unless it doesn't update it at all and there's an issue.

@andig
Copy link
Member

andig commented Jan 15, 2022

@ExecuteGK

WARN 2022/01/12 14:05:28 invalid charge mode: 0

Woher kommt der charge mode "0"? Greifst Du über API auf Evcc zu?

@ExecuteGK
Copy link
Author

Nö. Das war noch das resetOnDisconnect Problem mit dem off anstelle "off"

Grüße

Sebastian

@andig
Copy link
Member

andig commented Jan 16, 2022

@utsavanand2 when the car is connected (start of the log) charger starts enabled right away without evcc enabling it. That causes the out of sync errors. Any idea why that happens?

@utsavanand2
Copy link
Contributor

@utsavanand2 when the car is connected (start of the log) charger starts enabled right away without evcc enabling it. That causes the out of sync errors. Any idea why that happens?

Okay this must be because we return Enabled() -> true when the connector is in 'Charging' or 'Preparing'(plugged in state).
I guess Enabled only means 'Charging' and doesn't mean that the status != 'Available'? In that case we just need to get rid of the second condition here

return res.Status == string(daheimladen.CHARGING) || res.Status == string(daheimladen.PREPARING), err

@andig
Copy link
Member

andig commented Jan 18, 2022

enabled really means that evcc has allowed the car to charge. It will only happen in B or C and is independent from the fact if the car actually takes the opportunity. I'm not sure what would be the best mapping for the box here?

@andig
Copy link
Member

andig commented Feb 2, 2022

No new insights, closing.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants